[Feb 7 13:34:15] VERBOSE[3823] logger.c: Asterisk Event Logger restarted [Feb 7 13:34:15] VERBOSE[3823] logger.c: Asterisk Queue Logger restarted [Feb 7 13:34:16] VERBOSE[4002] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:34:16] VERBOSE[4002] logger.c: Found [Feb 7 13:34:16] VERBOSE[4003] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:34:16] VERBOSE[4003] logger.c: Found [Feb 7 13:34:19] NOTICE[25123] chan_iax2.c: Restricting registration for peer 'iaxmodem0' to 60 seconds (requested 300) [Feb 7 13:34:20] VERBOSE[25137] logger.c: -- Accepting call from '9057122221' to '6000' on channel 0/23, span 1 [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Executing [6000@zap-incoming:1] Answer("Zap/23-1", "") in new stack [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Executing [6000@zap-incoming:2] Set("Zap/23-1", "CHANNEL(musicclass)=wavfolder") in new stack [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Executing [6000@zap-incoming:3] NoOp("Zap/23-1", ""INCOMING CALL FROM CALLER ID: 9057122221 (BCM502221)"") in new stack [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Executing [6000@zap-incoming:4] Set("Zap/23-1", "__INCOMING_DNIS=6000") in new stack [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Executing [6000@zap-incoming:5] Set("Zap/23-1", "CDR(userfield)=6000") in new stack [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Executing [6000@zap-incoming:6] Goto("Zap/23-1", "10") in new stack [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Goto (zap-incoming,6000,10) [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Executing [6000@zap-incoming:10] Set("Zap/23-1", "__INCOMINGLINE=1") in new stack [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Executing [6000@zap-incoming:11] GotoIf("Zap/23-1", "0?12:13") in new stack [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Goto (zap-incoming,6000,13) [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Executing [6000@zap-incoming:13] Set("Zap/23-1", "CHANNEL(language)=en") in new stack [Feb 7 13:34:20] DEBUG[4016] func_db.c: DB: default/ringservice/line/1/dest not found in database. [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Executing [6000@zap-incoming:14] Set("Zap/23-1", "RING_DEST=") in new stack [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Executing [6000@zap-incoming:15] GotoIf("Zap/23-1", "1?18") in new stack [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Goto (zap-incoming,6000,18) [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Executing [6000@zap-incoming:18] Dial("Zap/23-1", "Local/6000@default-local|") in new stack [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Called 6000@default-local [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Executing [6000@default-local:1] GotoIf("Local/6000@default-local-80cc,2", "0?3") in new stack [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Executing [6000@default-local:2] Set("Local/6000@default-local-80cc,2", "GROUP(OUTGOING)=9057122221") in new stack [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Executing [6000@default-local:3] Set("Local/6000@default-local-80cc,2", "OUTBOUND_GROUP_ONCE=6000@INCOMING") in new stack [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Executing [6000@default-local:4] Set("Local/6000@default-local-80cc,2", "GROUPCOUNT=0") in new stack [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Executing [6000@default-local:5] Set("Local/6000@default-local-80cc,2", "GROUPCOUNT2=0") in new stack [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Executing [6000@default-local:6] Set("Local/6000@default-local-80cc,2", "DB(default/wrapup/6000/lastcall)=1202409260.76") in new stack [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Executing [6000@default-local:7] Macro("Local/6000@default-local-80cc,2", "default-dial|SIP/6000|6000|default|20|en|6000@default|wWkKM(all-tapi^1202409260.76)||default||Local/0@default-local|Local/s@default-aa-servicemainmenubutton1englishsubmenu") in new stack [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Executing [s@macro-default-dial:1] NoOp("Local/6000@default-local-80cc,2", ""CALL TO LOCAL EXTENSION FROM 9057122221(BCM502221)"") in new stack [Feb 7 13:34:20] DEBUG[4017] app_macro.c: Executed application: NoOp [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Executing [s@macro-default-dial:2] UserEvent("Local/6000@default-local-80cc,2", "TAPI|TAPIEVENT: LINE_NEWCALL default") in new stack [Feb 7 13:34:20] DEBUG[4017] app_macro.c: Executed application: UserEvent [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Executing [s@macro-default-dial:3] UserEvent("Local/6000@default-local-80cc,2", "TAPI|TAPIEVENT: LINE_CALLSTATE LINECALLSTATE_OFFERING") in new stack [Feb 7 13:34:20] DEBUG[4017] app_macro.c: Executed application: UserEvent [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Executing [s@macro-default-dial:4] UserEvent("Local/6000@default-local-80cc,2", "TAPI|TAPIEVENT: SET CALLERID ") in new stack [Feb 7 13:34:20] DEBUG[4017] app_macro.c: Executed application: UserEvent [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Executing [s@macro-default-dial:5] UserEvent("Local/6000@default-local-80cc,2", "TAPI|TAPIEVENT: LINE_CALLINFO LINECALLINFOSTATE_CALLERID") in new stack [Feb 7 13:34:20] DEBUG[4017] app_macro.c: Executed application: UserEvent [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Executing [s@macro-default-dial:6] AGI("Local/6000@default-local-80cc,2", "/var/www/asterisk/telephony/scripts/agi/dial.php") in new stack [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Launched AGI Script /var/www/asterisk/telephony/scripts/agi/dial.php [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- AGI Script Executing Application: (SetMusicOnHold) Options: (default) [Feb 7 13:34:20] VERBOSE[4019] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:34:20] VERBOSE[4019] logger.c: Found [Feb 7 13:34:20] VERBOSE[4017] logger.c: /var/www/asterisk/telephony/scripts/agi/dial.php: Extension State for '6000' is '0'. [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- AGI Script Executing Application: (NoOp) Options: (STATUS:) [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- /var/www/asterisk/telephony/scripts/agi/dial.php: Doing the action dial with params : 6000 [Feb 7 13:34:20] VERBOSE[4017] logger.c: /var/www/asterisk/telephony/scripts/agi/dial.php: Dial string is SIP/6000|20|wWkKM(all-tapi^1202409260.76)|. [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- AGI Script Executing Application: (Dial) Options: (SIP/6000|20|wWkKM(all-tapi^1202409260.76)|) [Feb 7 13:34:20] VERBOSE[25093] logger.c: Extension Changed 6000[default-local] new state Ringing for Notify User 6001 [Feb 7 13:34:20] VERBOSE[25093] logger.c: Extension Changed 6000[default-local] new state Ringing for Notify User 6003 [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- Called 6000 [Feb 7 13:34:20] VERBOSE[25093] logger.c: Extension Changed 6000[default-local] new state Ringing for Notify User 6000 [Feb 7 13:34:20] VERBOSE[25093] logger.c: Extension Changed 6000[default-local] new state Ringing for Notify User 6002 [Feb 7 13:34:20] VERBOSE[4017] logger.c: -- SIP/6000-09ebc400 is ringing [Feb 7 13:34:20] VERBOSE[4016] logger.c: -- Local/6000@default-local-80cc,1 is ringing [Feb 7 13:34:21] VERBOSE[4017] logger.c: -- SIP/6000-09ebc400 is ringing [Feb 7 13:34:21] VERBOSE[4017] logger.c: -- SIP/6000-09ebc400 answered Local/6000@default-local-80cc,2 [Feb 7 13:34:21] VERBOSE[25093] logger.c: Extension Changed 6000[default-local] new state InUse for Notify User 6001 [Feb 7 13:34:21] VERBOSE[4017] logger.c: -- Executing [s@macro-all-tapi:1] UserEvent("SIP/6000-09ebc400", "TAPI|TAPIEVENT [~1202409260.76] LINE_CALLSTATE LINECALLSTATE_CONNECTED") in new stack [Feb 7 13:34:21] DEBUG[4017] app_macro.c: Executed application: UserEvent [Feb 7 13:34:21] DEBUG[4017] app_dial.c: Macro exited with status 0 [Feb 7 13:34:21] VERBOSE[4016] logger.c: -- Local/6000@default-local-80cc,1 stopped sounds [Feb 7 13:34:21] VERBOSE[25093] logger.c: Extension Changed 6000[default-local] new state InUse for Notify User 6003 [Feb 7 13:34:21] VERBOSE[4016] logger.c: -- Local/6000@default-local-80cc,1 answered Zap/23-1 [Feb 7 13:34:21] VERBOSE[25093] logger.c: Extension Changed 6000[default-local] new state InUse for Notify User 6000 [Feb 7 13:34:21] VERBOSE[25093] logger.c: Extension Changed 6000[default-local] new state InUse for Notify User 6002 [Feb 7 13:34:21] VERBOSE[4022] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:34:21] VERBOSE[4022] logger.c: Found [Feb 7 13:34:21] DEBUG[4017] res_agi.c: Local/6000@default-local-80cc,2 hungup [Feb 7 13:34:21] VERBOSE[4017] logger.c: == Spawn extension (macro-default-dial, s, 6) exited non-zero on 'Local/6000@default-local-80cc,2' in macro 'default-dial' [Feb 7 13:34:21] VERBOSE[4017] logger.c: == Spawn extension (macro-default-dial, s, 6) exited non-zero on 'Local/6000@default-local-80cc,2' [Feb 7 13:34:21] VERBOSE[4017] logger.c: -- Executing [h@macro-default-dial:1] ResetCDR("Local/6000@default-local-80cc,2", "w") in new stack [Feb 7 13:34:21] VERBOSE[4017] logger.c: -- Executing [h@macro-default-dial:2] NoCDR("Local/6000@default-local-80cc,2", "") in new stack [Feb 7 13:34:21] VERBOSE[4017] logger.c: -- Executing [h@macro-default-dial:3] UserEvent("Local/6000@default-local-80cc,2", "TAPI|TAPIEVENT: LINE_CALLSTATE LINECALLSTATE_IDLE") in new stack [Feb 7 13:34:21] VERBOSE[4017] logger.c: -- Executing [h@macro-default-dial:4] System("Local/6000@default-local-80cc,2", "/var/www/asterisk/telephony/scripts/billing/cdr.sh 1202409260.76") in new stack [Feb 7 13:34:22] DTMF[4016] channel.c: DTMF begin '*' received on SIP/6000-09ebc400 [Feb 7 13:34:22] DTMF[4016] channel.c: DTMF begin passthrough '*' on SIP/6000-09ebc400 [Feb 7 13:34:22] DEBUG[4016] chan_zap.c: Started VLDTMF digit '*' [Feb 7 13:34:22] DTMF[4016] channel.c: DTMF end '*' received on SIP/6000-09ebc400, duration 140 ms [Feb 7 13:34:22] DTMF[4016] channel.c: DTMF end accepted with begin '*' on SIP/6000-09ebc400 [Feb 7 13:34:22] DTMF[4016] channel.c: DTMF end passthrough '*' on SIP/6000-09ebc400 [Feb 7 13:34:22] DEBUG[4016] chan_zap.c: Ending VLDTMF digit '*' [Feb 7 13:34:22] DTMF[4016] channel.c: DTMF begin '9' received on SIP/6000-09ebc400 [Feb 7 13:34:22] DTMF[4016] channel.c: DTMF begin passthrough '9' on SIP/6000-09ebc400 [Feb 7 13:34:22] DEBUG[4016] chan_zap.c: Started VLDTMF digit '9' [Feb 7 13:34:23] DTMF[4016] channel.c: DTMF end '9' received on SIP/6000-09ebc400, duration 120 ms [Feb 7 13:34:23] DTMF[4016] channel.c: DTMF end accepted with begin '9' on SIP/6000-09ebc400 [Feb 7 13:34:23] DTMF[4016] channel.c: DTMF end passthrough '9' on SIP/6000-09ebc400 [Feb 7 13:34:23] DEBUG[4016] chan_zap.c: Ending VLDTMF digit '9' [Feb 7 13:34:23] DTMF[4016] channel.c: DTMF begin '9' received on SIP/6000-09ebc400 [Feb 7 13:34:23] DTMF[4016] channel.c: DTMF begin passthrough '9' on SIP/6000-09ebc400 [Feb 7 13:34:23] DEBUG[4016] chan_zap.c: Started VLDTMF digit '9' [Feb 7 13:34:23] DTMF[4016] channel.c: DTMF end '9' received on SIP/6000-09ebc400, duration 120 ms [Feb 7 13:34:23] DTMF[4016] channel.c: DTMF end accepted with begin '9' on SIP/6000-09ebc400 [Feb 7 13:34:23] DTMF[4016] channel.c: DTMF end passthrough '9' on SIP/6000-09ebc400 [Feb 7 13:34:23] DEBUG[4016] chan_zap.c: Ending VLDTMF digit '9' [Feb 7 13:34:23] DTMF[4016] channel.c: DTMF begin '9' received on SIP/6000-09ebc400 [Feb 7 13:34:23] DTMF[4016] channel.c: DTMF begin passthrough '9' on SIP/6000-09ebc400 [Feb 7 13:34:23] DEBUG[4016] chan_zap.c: Started VLDTMF digit '9' [Feb 7 13:34:23] DTMF[4016] channel.c: DTMF end '9' received on SIP/6000-09ebc400, duration 120 ms [Feb 7 13:34:23] DTMF[4016] channel.c: DTMF end accepted with begin '9' on SIP/6000-09ebc400 [Feb 7 13:34:23] DTMF[4016] channel.c: DTMF end passthrough '9' on SIP/6000-09ebc400 [Feb 7 13:34:23] DEBUG[4016] chan_zap.c: Ending VLDTMF digit '9' [Feb 7 13:34:25] VERBOSE[4016] logger.c: == Spawn extension (zap-incoming, 6000, 18) exited non-zero on 'Zap/23-1' [Feb 7 13:34:25] VERBOSE[4016] logger.c: -- Executing [h@zap-incoming:1] Goto("Zap/23-1", "all-hangup|s|1") in new stack [Feb 7 13:34:25] VERBOSE[4016] logger.c: -- Goto (all-hangup,s,1) [Feb 7 13:34:25] VERBOSE[4016] logger.c: -- Executing [s@all-hangup:1] GotoIf("Zap/23-1", "0?all-faxnotify|s|1:2") in new stack [Feb 7 13:34:25] VERBOSE[4016] logger.c: -- Goto (all-hangup,s,2) [Feb 7 13:34:25] VERBOSE[4016] logger.c: -- Executing [s@all-hangup:2] ResetCDR("Zap/23-1", "w") in new stack [Feb 7 13:34:25] VERBOSE[25093] logger.c: Extension Changed 6000[default-local] new state Idle for Notify User 6001 [Feb 7 13:34:25] VERBOSE[25093] logger.c: Extension Changed 6000[default-local] new state Idle for Notify User 6003 [Feb 7 13:34:25] VERBOSE[25093] logger.c: Extension Changed 6000[default-local] new state Idle for Notify User 6000 [Feb 7 13:34:25] VERBOSE[25093] logger.c: Extension Changed 6000[default-local] new state Idle for Notify User 6002 [Feb 7 13:34:25] VERBOSE[4016] logger.c: -- Executing [s@all-hangup:3] NoCDR("Zap/23-1", "") in new stack [Feb 7 13:34:25] VERBOSE[4016] logger.c: -- Executing [s@all-hangup:4] System("Zap/23-1", "/var/www/asterisk/telephony/scripts/billing/cdr.sh 1202409260.74") in new stack [Feb 7 13:34:25] DEBUG[4016] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/23-1 [Feb 7 13:34:25] DEBUG[4016] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call [Feb 7 13:34:25] DEBUG[4016] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/23-1 [Feb 7 13:34:25] VERBOSE[4016] logger.c: -- Hungup 'Zap/23-1' [Feb 7 13:34:27] VERBOSE[4049] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:34:27] VERBOSE[4049] logger.c: Found [Feb 7 13:34:32] VERBOSE[4059] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:34:32] VERBOSE[4059] logger.c: Found [Feb 7 13:34:38] VERBOSE[4068] logger.c: == Parsing '/etc/asterisk/manager.conf': [Feb 7 13:34:38] VERBOSE[4068] logger.c: Found