[Mar 31 12:44:17] -- Executing [2216950e1@incoming:1] Goto("SIP/sipgate-gmbh-e0-00000006", "83,510") in new stack [Mar 31 12:44:17] -- Goto (incoming,83,510) [Mar 31 12:44:17] -- Executing [83@incoming:510] Macro("SIP/sipgate-gmbh-e0-00000006", "CallExt2Int,SIP/snomvs831&IAX2/vsauer,V1:,,volker@volker-sauer.de") in new stack [Mar 31 12:44:17] -- Executing [s@macro-CallExt2Int:1] AGI("SIP/sipgate-gmbh-e0-00000006", "telefonbuch_reverselookup.php,01796901475") in new stack [Mar 31 12:44:17] -- Launched AGI Script /opt/asterisk/var/lib/asterisk/agi-bin/telefonbuch_reverselookup.php [Mar 31 12:44:18] ERROR[7261]: utils.c:1170 ast_carefulwrite: write() returned error: Broken pipe [Mar 31 12:44:18] -- AGI Script telefonbuch_reverselookup.php completed, returning 0 [Mar 31 12:44:18] -- Executing [s@macro-CallExt2Int:2] Set("SIP/sipgate-gmbh-e0-00000006", "PICKUPMARK=83") in new stack [Mar 31 12:44:18] -- Executing [s@macro-CallExt2Int:3] NoOp("SIP/sipgate-gmbh-e0-00000006", "83") in new stack [Mar 31 12:44:18] -- Executing [s@macro-CallExt2Int:4] Set("SIP/sipgate-gmbh-e0-00000006", "VOLUME(TX)=") in new stack [Mar 31 12:44:18] -- Executing [s@macro-CallExt2Int:5] Set("SIP/sipgate-gmbh-e0-00000006", "VOLUME(TX)=") in new stack [Mar 31 12:44:18] -- Executing [s@macro-CallExt2Int:6] Set("SIP/sipgate-gmbh-e0-00000006", "CALLERID(name)=V1:Sauer,Volker(cell)") in new stack [Mar 31 12:44:18] -- Executing [s@macro-CallExt2Int:7] JabberSend("SIP/sipgate-gmbh-e0-00000006", "asterisk,volker@volker-sauer.de,Sie wurden angerufen von "V1:Sauer,Volker(cell)" <01796901475> um Sat Mar 31 12:44:18 2012") in new stack [Mar 31 12:44:18] -- Executing [s@macro-CallExt2Int:8] Dial("SIP/sipgate-gmbh-e0-00000006", "SIP/snomvs831&IAX2/vsauer,,kKtTwW") in new stack [Mar 31 12:44:18] == Using SIP RTP CoS mark 5 [Mar 31 12:44:18] -- Called SIP/snomvs831 [Mar 31 12:44:18] == Extension Changed 83[incoming] new state Ringing for Notify User snomhmk [Mar 31 12:44:18] WARNING[7261]: app_dial.c:2218 dial_exec_full: Unable to create channel of type 'IAX2' (cause 20 - Unknown) [Mar 31 12:44:18] -- Got SIP response 302 "Moved Temporarily" back from 192.168.0.14:5060 [Mar 31 12:44:18] -- Now forwarding SIP/sipgate-gmbh-e0-00000006 to 'Local/85@doLocalCallsPrivat' (thanks to SIP/snomvs831-00000007) [Mar 31 12:44:18] NOTICE[7261]: app_dial.c:883 do_forward: Not accepting call completion offers from call-forward recipient Local/85@doLocalCallsPrivat-2130;1 [Mar 31 12:44:18] -- Executing [85@doLocalCallsPrivat:1] NoOp("Local/85@doLocalCallsPrivat-2130;2", "Local/85@d") in new stack [Mar 31 12:44:18] -- Executing [85@doLocalCallsPrivat:2] Set("Local/85@doLocalCallsPrivat-2130;2", "VOLUME(TX)=") in new stack [Mar 31 12:44:18] -- Executing [85@doLocalCallsPrivat:3] Goto("Local/85@doLocalCallsPrivat-2130;2", "doLocalCallsGeneric,85,1") in new stack [Mar 31 12:44:18] -- Goto (doLocalCallsGeneric,85,1) [Mar 31 12:44:18] NOTICE[7264]: ast_expr2.y:760 compose_func_args: argbuf allocated 12 bytes; [Mar 31 12:44:18] NOTICE[7264]: ast_expr2.y:779 compose_func_args: argbuf uses 11 bytes; [Mar 31 12:44:18] == Extension Changed 83[incoming] new state Idle for Notify User snomhmk [Mar 31 12:44:18] -- Executing [85@doLocalCallsGeneric:1] Set("Local/85@doLocalCallsPrivat-2130;2", "CALLERID(num)=01796901475") in new stack [Mar 31 12:44:18] -- Executing [85@doLocalCallsGeneric:2] Goto("Local/85@doLocalCallsPrivat-2130;2", "incoming,85,100") in new stack [Mar 31 12:44:18] -- Goto (incoming,85,100) [Mar 31 12:44:18] -- Executing [85@incoming:100] Macro("Local/85@doLocalCallsPrivat-2130;2", "CallInt2Int,SIP/snomm9-2") in new stack [Mar 31 12:44:18] -- Executing [s@macro-CallInt2Int:1] Set("Local/85@doLocalCallsPrivat-2130;2", "PICKUPMARK=85") in new stack [Mar 31 12:44:18] -- Executing [s@macro-CallInt2Int:2] NoOp("Local/85@doLocalCallsPrivat-2130;2", "85") in new stack [Mar 31 12:44:18] -- Executing [s@macro-CallInt2Int:3] Set("Local/85@doLocalCallsPrivat-2130;2", "VOLUME(TX)=") in new stack [Mar 31 12:44:18] -- Executing [s@macro-CallInt2Int:4] Set("Local/85@doLocalCallsPrivat-2130;2", "VOLUME(TX)=-4") in new stack [Mar 31 12:44:18] -- Executing [s@macro-CallInt2Int:5] Dial("Local/85@doLocalCallsPrivat-2130;2", "SIP/snomm9-2,,kKwWtTj") in new stack [Mar 31 12:44:18] == Using SIP RTP CoS mark 5 [Mar 31 12:44:18] == Extension Changed 85[incoming] new state Ringing for Notify User snomvs [Mar 31 12:44:18] == Extension Changed 85[incoming] new state Ringing for Notify User snomhmk [Mar 31 12:44:18] -- Called SIP/snomm9-2 [Mar 31 12:44:18] -- SIP/snomm9-2-00000008 is ringing [Mar 31 12:44:18] -- Local/85@doLocalCallsPrivat-2130;1 is ringing [Mar 31 12:44:24] -- SIP/snomm9-2-00000008 answered Local/85@doLocalCallsPrivat-2130;2 [Mar 31 12:44:24] == Extension Changed 85[incoming] new state InUse for Notify User snomvs [Mar 31 12:44:24] == Extension Changed 85[incoming] new state InUse for Notify User snomhmk [Mar 31 12:44:24] -- Local/85@doLocalCallsPrivat-2130;1 answered SIP/sipgate-gmbh-e0-00000006 [Mar 31 12:44:24] == Spawn extension (macro-CallInt2Int, s, 5) exited non-zero on 'Local/85@doLocalCallsPrivat-2130;2' in macro 'CallInt2Int' [Mar 31 12:44:24] == Spawn extension (incoming, 85, 100) exited non-zero on 'Local/85@doLocalCallsPrivat-2130;2' [Mar 31 12:44:24] ERROR[7261]: lock.c:280 __ast_pthread_mutex_lock: audiohook.c line 842 (audio_audiohook_write_list): Error obtaining mutex: Invalid argument [Mar 31 12:44:24] ERROR[7261]: lock.c:407 __ast_pthread_mutex_unlock: audiohook.c line 861 (audio_audiohook_write_list): mutex '&(audiohook)->lock' freed more times than we've locked! [Mar 31 12:44:24] ERROR[7261]: lock.c:438 __ast_pthread_mutex_unlock: audiohook.c line 861 (audio_audiohook_write_list): Error releasing mutex: Invalid argument [Message repeated ~ 100 times] [Asterisk stopped processing (sip) calls] *CLI> core show locks ======================================================================= === Currently Held Locks ============================================== ======================================================================= === === (): (times locked) === === Thread ID: 0xaefffb70 (pbx_thread started at [ 5512] pbx.c ast_pbx_start()) === ---> Lock #0 (channel.c): MUTEX 4852 ast_write chan 0x875a3d8 (1) /opt/asterisk/sbin/asterisk(ast_bt_get_addresses+0x1a) [0x812c8aa] /opt/asterisk/sbin/asterisk(__ast_pthread_mutex_trylock+0x77) [0x8129fc7] /opt/asterisk/sbin/asterisk(ast_write+0x37) [0x80bd017] /opt/asterisk/sbin/asterisk() [0x80c47a2] /opt/asterisk/sbin/asterisk(ast_channel_bridge+0x6d6) [0x80c54a6] /opt/asterisk/sbin/asterisk(ast_bridge_call+0x341) [0x80fa2e1] /opt/asterisk/lib/asterisk/modules/app_dial.so(+0xc05d) [0xb67a105d] /opt/asterisk/lib/asterisk/modules/app_dial.so(+0xda1d) [0xb67a2a1d] /opt/asterisk/sbin/asterisk(pbx_exec+0x10b) [0x8154bdb] /opt/asterisk/sbin/asterisk() [0x816305b] /opt/asterisk/lib/asterisk/modules/app_macro.so(+0x248b) [0xb675c48b] /opt/asterisk/sbin/asterisk(pbx_exec+0x10b) [0x8154bdb] /opt/asterisk/sbin/asterisk() [0x816305b] /opt/asterisk/sbin/asterisk() [0x81697ed] /opt/asterisk/sbin/asterisk() [0x816b1de] /opt/asterisk/sbin/asterisk() [0x81af8ce] /lib/i686/cmov/libpthread.so.0(+0x5955) [0xb751c955] /lib/i686/cmov/libc.so.6(clone+0x5e) [0xb769058e] === ------------------------------------------------------------------- === =======================================================================