[Feb 7 13:44:48] VERBOSE[8590] logger.c: -- Incoming call: Got SIP response 500 "Internal Server Error" back from 192.168.30.200 [Feb 7 13:44:48] VERBOSE[8774] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:44:48] VERBOSE[8774] logger.c: Found [Feb 7 13:44:48] VERBOSE[8775] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:44:48] VERBOSE[8775] logger.c: Found [Feb 7 13:44:54] VERBOSE[8787] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:44:54] VERBOSE[8787] logger.c: Found [Feb 7 13:44:54] VERBOSE[8590] logger.c: -- Incoming call: Got SIP response 500 "Internal Server Error" back from 192.168.30.200 [Feb 7 13:44:59] VERBOSE[8590] logger.c: -- Incoming call: Got SIP response 500 "Internal Server Error" back from 192.168.30.200 [Feb 7 13:44:59] VERBOSE[8808] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:44:59] VERBOSE[8808] logger.c: Found [Feb 7 13:45:03] VERBOSE[9045] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:45:03] VERBOSE[9045] logger.c: Found [Feb 7 13:45:05] VERBOSE[9068] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:45:05] VERBOSE[9068] logger.c: Found [Feb 7 13:45:06] DEBUG[8616] iax2-provision.c: Unable to create provisioning packet for 'si-00036400013b' [Feb 7 13:45:06] VERBOSE[8590] logger.c: -- Incoming call: Got SIP response 500 "Internal Server Error" back from 192.168.30.200 [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Executing [6000@default-5900-incoming:1] GotoIf("SIP/5900-0884b6a8", "0?3") in new stack [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Executing [6000@default-5900-incoming:2] Set("SIP/5900-0884b6a8", "GROUP(OUTGOING)=5900") in new stack [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Executing [6000@default-5900-incoming:3] Set("SIP/5900-0884b6a8", "OUTBOUND_GROUP_ONCE=6000@INCOMING") in new stack [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Executing [6000@default-5900-incoming:4] Set("SIP/5900-0884b6a8", "GROUPCOUNT=0") in new stack [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Executing [6000@default-5900-incoming:5] Set("SIP/5900-0884b6a8", "GROUPCOUNT2=0") in new stack [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Executing [6000@default-5900-incoming:6] Set("SIP/5900-0884b6a8", "DB(default/wrapup/6000/lastcall)=1202409906.0") in new stack [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Executing [6000@default-5900-incoming:7] Macro("SIP/5900-0884b6a8", "default-dial|SIP/6000|6000|default|20|en|6000@default|wWkKM(all-tapi^1202409906.0)||default||Local/0@default-local|Local/s@default-aa-servicemainmenubutton1englishsubmenu") in new stack [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Executing [s@macro-default-dial:1] NoOp("SIP/5900-0884b6a8", ""CALL TO LOCAL EXTENSION FROM 5900()"") in new stack [Feb 7 13:45:06] DEBUG[9069] app_macro.c: Executed application: NoOp [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Executing [s@macro-default-dial:2] UserEvent("SIP/5900-0884b6a8", "TAPI|TAPIEVENT: LINE_NEWCALL default") in new stack [Feb 7 13:45:06] DEBUG[9069] app_macro.c: Executed application: UserEvent [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Executing [s@macro-default-dial:3] UserEvent("SIP/5900-0884b6a8", "TAPI|TAPIEVENT: LINE_CALLSTATE LINECALLSTATE_OFFERING") in new stack [Feb 7 13:45:06] DEBUG[9069] app_macro.c: Executed application: UserEvent [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Executing [s@macro-default-dial:4] UserEvent("SIP/5900-0884b6a8", "TAPI|TAPIEVENT: SET CALLERID ") in new stack [Feb 7 13:45:06] DEBUG[9069] app_macro.c: Executed application: UserEvent [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Executing [s@macro-default-dial:5] UserEvent("SIP/5900-0884b6a8", "TAPI|TAPIEVENT: LINE_CALLINFO LINECALLINFOSTATE_CALLERID") in new stack [Feb 7 13:45:06] DEBUG[9069] app_macro.c: Executed application: UserEvent [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Executing [s@macro-default-dial:6] AGI("SIP/5900-0884b6a8", "/var/www/asterisk/telephony/scripts/agi/dial.php") in new stack [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Launched AGI Script /var/www/asterisk/telephony/scripts/agi/dial.php [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- AGI Script Executing Application: (SetMusicOnHold) Options: (default) [Feb 7 13:45:06] VERBOSE[9071] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:45:06] VERBOSE[9071] logger.c: Found [Feb 7 13:45:06] VERBOSE[9069] logger.c: /var/www/asterisk/telephony/scripts/agi/dial.php: Extension State for '6000' is '0'. [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- AGI Script Executing Application: (NoOp) Options: (STATUS:) [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- /var/www/asterisk/telephony/scripts/agi/dial.php: Doing the action dial with params : 6000 [Feb 7 13:45:06] VERBOSE[9069] logger.c: /var/www/asterisk/telephony/scripts/agi/dial.php: Dial string is SIP/6000|20|wWkKM(all-tapi^1202409906.0)|. [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- AGI Script Executing Application: (Dial) Options: (SIP/6000|20|wWkKM(all-tapi^1202409906.0)|) [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- Called 6000 [Feb 7 13:45:06] VERBOSE[9069] logger.c: -- SIP/6000-0884e1c8 is ringing [Feb 7 13:45:07] VERBOSE[9069] logger.c: -- SIP/6000-0884e1c8 is ringing [Feb 7 13:45:07] VERBOSE[9069] logger.c: -- SIP/6000-0884e1c8 answered SIP/5900-0884b6a8 [Feb 7 13:45:07] VERBOSE[9069] logger.c: -- Executing [s@macro-all-tapi:1] UserEvent("SIP/6000-0884e1c8", "TAPI|TAPIEVENT [~1202409906.0] LINE_CALLSTATE LINECALLSTATE_CONNECTED") in new stack [Feb 7 13:45:07] DEBUG[9069] app_macro.c: Executed application: UserEvent [Feb 7 13:45:07] DEBUG[9069] app_dial.c: Macro exited with status 0 [Feb 7 13:45:07] VERBOSE[9069] logger.c: -- Packet2Packet bridging SIP/5900-0884b6a8 and SIP/6000-0884e1c8 [Feb 7 13:45:08] DTMF[9069] channel.c: DTMF begin '*' received on SIP/6000-0884e1c8 [Feb 7 13:45:08] DTMF[9069] channel.c: DTMF begin passthrough '*' on SIP/6000-0884e1c8 [Feb 7 13:45:08] VERBOSE[9069] logger.c: -- Packet2Packet bridging SIP/5900-0884b6a8 and SIP/6000-0884e1c8 [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF end '*' received on SIP/6000-0884e1c8, duration 120 ms [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF end accepted with begin '*' on SIP/6000-0884e1c8 [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF end passthrough '*' on SIP/6000-0884e1c8 [Feb 7 13:45:09] VERBOSE[9069] logger.c: -- Packet2Packet bridging SIP/5900-0884b6a8 and SIP/6000-0884e1c8 [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF begin '9' received on SIP/6000-0884e1c8 [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF begin passthrough '9' on SIP/6000-0884e1c8 [Feb 7 13:45:09] VERBOSE[9069] logger.c: -- Packet2Packet bridging SIP/5900-0884b6a8 and SIP/6000-0884e1c8 [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF end '9' received on SIP/6000-0884e1c8, duration 100 ms [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF end accepted with begin '9' on SIP/6000-0884e1c8 [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF end passthrough '9' on SIP/6000-0884e1c8 [Feb 7 13:45:09] VERBOSE[9069] logger.c: -- Packet2Packet bridging SIP/5900-0884b6a8 and SIP/6000-0884e1c8 [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF begin '9' received on SIP/6000-0884e1c8 [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF begin passthrough '9' on SIP/6000-0884e1c8 [Feb 7 13:45:09] VERBOSE[9069] logger.c: -- Packet2Packet bridging SIP/5900-0884b6a8 and SIP/6000-0884e1c8 [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF end '9' received on SIP/6000-0884e1c8, duration 120 ms [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF end accepted with begin '9' on SIP/6000-0884e1c8 [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF end passthrough '9' on SIP/6000-0884e1c8 [Feb 7 13:45:09] VERBOSE[9069] logger.c: -- Packet2Packet bridging SIP/5900-0884b6a8 and SIP/6000-0884e1c8 [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF begin '9' received on SIP/6000-0884e1c8 [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF begin passthrough '9' on SIP/6000-0884e1c8 [Feb 7 13:45:09] VERBOSE[9069] logger.c: -- Packet2Packet bridging SIP/5900-0884b6a8 and SIP/6000-0884e1c8 [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF end '9' received on SIP/6000-0884e1c8, duration 120 ms [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF end accepted with begin '9' on SIP/6000-0884e1c8 [Feb 7 13:45:09] DTMF[9069] channel.c: DTMF end passthrough '9' on SIP/6000-0884e1c8 [Feb 7 13:45:10] VERBOSE[9080] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:45:10] VERBOSE[9080] logger.c: Found [Feb 7 13:45:11] VERBOSE[8590] logger.c: -- Incoming call: Got SIP response 500 "Internal Server Error" back from 192.168.30.200 [Feb 7 13:45:12] VERBOSE[9069] logger.c: -- AGI Script /var/www/asterisk/telephony/scripts/agi/dial.php completed, returning 0 [Feb 7 13:45:12] DEBUG[9069] app_macro.c: Executed application: AGI [Feb 7 13:45:12] VERBOSE[9069] logger.c: -- Executing [6000@default-5900-incoming:8] GotoIf("SIP/5900-0884b6a8", "1?9:10") in new stack [Feb 7 13:45:12] VERBOSE[9069] logger.c: -- Goto (default-5900-incoming,6000,9) [Feb 7 13:45:12] VERBOSE[9069] logger.c: -- Executing [6000@default-5900-incoming:9] Hangup("SIP/5900-0884b6a8", "") in new stack [Feb 7 13:45:12] VERBOSE[9069] logger.c: == Spawn extension (default-5900-incoming, 6000, 9) exited non-zero on 'SIP/5900-0884b6a8' [Feb 7 13:45:12] VERBOSE[9069] logger.c: -- Executing [h@default-5900-incoming:1] Goto("SIP/5900-0884b6a8", "all-hangup|s|1") in new stack [Feb 7 13:45:12] VERBOSE[9069] logger.c: -- Goto (all-hangup,s,1) [Feb 7 13:45:12] VERBOSE[9069] logger.c: -- Executing [s@all-hangup:1] GotoIf("SIP/5900-0884b6a8", "0?all-faxnotify|s|1:2") in new stack [Feb 7 13:45:12] VERBOSE[9069] logger.c: -- Goto (all-hangup,s,2) [Feb 7 13:45:12] VERBOSE[9069] logger.c: -- Executing [s@all-hangup:2] ResetCDR("SIP/5900-0884b6a8", "w") in new stack [Feb 7 13:45:12] VERBOSE[9069] logger.c: -- Executing [s@all-hangup:3] NoCDR("SIP/5900-0884b6a8", "") in new stack [Feb 7 13:45:12] VERBOSE[9069] logger.c: -- Executing [s@all-hangup:4] System("SIP/5900-0884b6a8", "/var/www/asterisk/telephony/scripts/billing/cdr.sh 1202409906.0") in new stack [Feb 7 13:45:12] DEBUG[9069] res_monitor.c: monitor executing ( nice -n 19 sox -m "/var/spool/asterisk/monitor/auto-1202409909-1202409906.0-in.wav" "/var/spool/asterisk/monitor/auto-1202409909-1202409906.0-out.wav" "/var/spool/asterisk/monitor/auto-1202409909-1202409906.0.wav" && rm -f "/var/spool/asterisk/monitor/auto-1202409909-1202409906.0-"* ) & [Feb 7 13:45:16] VERBOSE[9099] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:45:16] VERBOSE[9099] logger.c: Found [Feb 7 13:45:17] VERBOSE[8590] logger.c: -- Incoming call: Got SIP response 500 "Internal Server Error" back from 192.168.30.200 [Feb 7 13:45:20] NOTICE[8613] chan_iax2.c: Restricting registration for peer 'iaxmodem0' to 60 seconds (requested 300) [Feb 7 13:45:21] VERBOSE[9107] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:45:21] VERBOSE[9107] logger.c: Found [Feb 7 13:45:21] VERBOSE[9108] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:45:21] VERBOSE[9108] logger.c: Found [Feb 7 13:45:22] VERBOSE[8590] logger.c: -- Incoming call: Got SIP response 500 "Internal Server Error" back from 192.168.30.200