Lots of Ghost Calls

I am getting a lot of dropped calls. Agents pick up the phones and nobody is on the other side. I a have called customers right back and that have all said that they just hear silence. I am using trixbox with call queues and dynamic agents. I did update to the latest queue modules last night and that did not help the issue. This has been going on for about 3 weeks since I upgraded to the most recent version of freepbx. Below is the log file from the server. The Caller id was 5033311016. Called was answered on SIP-201 by Agent/403. Any info would be greatly appreciated.

–Greg

[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: Set
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/205-09893c60”, “OUTBOUND_GROUP=OUT_2”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: Set
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/205-09893c60”, “0?nomax”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: GotoIf
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk:8] GotoIf(“SIP/205-09893c60”, “0?chanfull”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: GotoIf
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/205-09893c60”, “0?skipoutcid”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: GotoIf
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk:10] Set(“SIP/205-09893c60”, “DIAL_TRUNK_OPTIONS=”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: Set
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/205-09893c60”, “outbound-callerid|2”) in new stack
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/205-09893c60”, “0|SetCallerPres|”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: ExecIf
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/205-09893c60”, “0|Set|REALCALLERIDNUM=205”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: ExecIf
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-outbound-callerid:3] GotoIf(“SIP/205-09893c60”, “1?normcid”) in new stack
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Goto (macro-outbound-callerid,s,6)
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: GotoIf
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-outbound-callerid:6] Set(“SIP/205-09893c60”, “USEROUTCID=”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: Set
[Nov 17 14:36:12] DEBUG[8697] func_db.c: DB: DEVICE/205/emergency_cid not found in database.
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-outbound-callerid:7] Set(“SIP/205-09893c60”, “EMERGENCYCID=”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: Set
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-outbound-callerid:8] Set(“SIP/205-09893c60”, “TRUNKOUTCID=”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: Set
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-outbound-callerid:9] GotoIf(“SIP/205-09893c60”, “1?trunkcid”) in new stack
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Goto (macro-outbound-callerid,s,12)
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: GotoIf
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-outbound-callerid:12] ExecIf(“SIP/205-09893c60”, “0|Set|CALLERID(all)=”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: ExecIf
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-outbound-callerid:13] GotoIf(“SIP/205-09893c60”, “1?exit”) in new stack
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Goto (macro-outbound-callerid,s,11)
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: GotoIf
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-outbound-callerid:11] MacroExit(“SIP/205-09893c60”, “”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: Macro
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk:12] ExecIf(“SIP/205-09893c60”, “0|AGI|fixlocalprefix”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: ExecIf
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/205-09893c60”, “OUTNUM=5032398598”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: Set
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/205-09893c60”, “custom=ZAP/g4”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: Set
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/205-09893c60”, “0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^)”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: ExecIf
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk:16] Macro(“SIP/205-09893c60”, “dialout-trunk-predial-hook|”) in new stack
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/205-09893c60”, “”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: Macro
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk:17] GotoIf(“SIP/205-09893c60”, “0?bypass|1”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: GotoIf
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/205-09893c60”, “0?customtrunk”) in new stack
[Nov 17 14:36:12] DEBUG[8697] app_macro.c: Executed application: GotoIf
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Executing [s@macro-dialout-trunk:19] Dial(“SIP/205-09893c60”, “ZAP/g4/5032398598|300|”) in new stack
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Requested transfer capability: 0x00 - SPEECH
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Called g4/5032398598
[Nov 17 14:36:12] VERBOSE[8699] logger.c: == Begin MixMonitor Recording SIP/205-09893c60
[Nov 17 14:36:12] DEBUG[2770] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 1
[Nov 17 14:36:12] VERBOSE[8697] logger.c: – Zap/1-1 is proceeding passing it to SIP/205-09893c60
[Nov 17 14:36:14] VERBOSE[8697] logger.c: – Zap/1-1 is ringing
[Nov 17 14:36:28] DEBUG[2770] chan_zap.c: Echo cancellation already on
[Nov 17 14:36:28] VERBOSE[8697] logger.c: – Zap/1-1 answered SIP/205-09893c60
[Nov 17 14:36:39] DEBUG[8697] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/1-1
[Nov 17 14:36:39] DEBUG[8697] chan_zap.c: Not yet hungup… Calling hangup once with icause, and clearing call
[Nov 17 14:36:39] DEBUG[8697] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/1-1
[Nov 17 14:36:39] VERBOSE[8697] logger.c: – Hungup ‘Zap/1-1’
[Nov 17 14:36:39] VERBOSE[8697] logger.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/205-09893c60’ in macro ‘dialout-trunk’
[Nov 17 14:36:39] VERBOSE[8697] logger.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/205-09893c60’
[Nov 17 14:36:39] VERBOSE[8697] logger.c: – Executing [h@macro-dialout-trunk:1] Macro(“SIP/205-09893c60”, “hangupcall|”) in new stack
[Nov 17 14:36:39] VERBOSE[8697] logger.c: – Executing [s@macro-hangupcall:1] ResetCDR(“SIP/205-09893c60”, “w”) in new stack
[Nov 17 14:36:39] DEBUG[8697] app_macro.c: Executed application: ResetCDR
[Nov 17 14:36:39] VERBOSE[8697] logger.c: – Executing [s@macro-hangupcall:2] NoCDR(“SIP/205-09893c60”, “”) in new stack
[Nov 17 14:36:39] DEBUG[8697] app_macro.c: Executed application: NoCDR
[Nov 17 14:36:39] VERBOSE[8697] logger.c: – Executing [s@macro-hangupcall:3] GotoIf(“SIP/205-09893c60”, “1?skiprg”) in new stack
[Nov 17 14:36:39] VERBOSE[8697] logger.c: – Goto (macro-hangupcall,s,6)
[Nov 17 14:36:39] DEBUG[8697] app_macro.c: Executed application: GotoIf

[Nov 17 14:36:39] VERBOSE[8697] logger.c: – Executing [s@macro-hangupcall:6] GotoIf(“SIP/205-09893c60”, “1?skipblkvm”) in new stack
[Nov 17 14:36:39] VERBOSE[8697] logger.c: – Goto (macro-hangupcall,s,9)
[Nov 17 14:36:39] DEBUG[8697] app_macro.c: Executed application: GotoIf
[Nov 17 14:36:39] VERBOSE[8697] logger.c: – Executing [s@macro-hangupcall:9] GotoIf(“SIP/205-09893c60”, “1?theend”) in new stack
[Nov 17 14:36:39] VERBOSE[8697] logger.c: – Goto (macro-hangupcall,s,11)
[Nov 17 14:36:39] DEBUG[8697] app_macro.c: Executed application: GotoIf
[Nov 17 14:36:39] VERBOSE[8697] logger.c: – Executing [s@macro-hangupcall:11] Hangup(“SIP/205-09893c60”, “”) in new stack
[Nov 17 14:36:39] VERBOSE[8697] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/205-09893c60’ in macro ‘hangupcall’
[Nov 17 14:36:39] VERBOSE[8697] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/205-09893c60’
[Nov 17 14:36:39] VERBOSE[8699] logger.c: == End MixMonitor Recording SIP/205-09893c60
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [5032220006@from-internal:1] Macro(“SIP/205-09893c60”, “user-callerid|SKIPTTL|”) in new stack
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-user-callerid:1] Set(“SIP/205-09893c60”, “AMPUSER=205”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/205-09893c60”, “0?report”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/205-09893c60”, “1|Set|REALCALLERIDNUM=205”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: ExecIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-user-callerid:4] Set(“SIP/205-09893c60”, “AMPUSER=205”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-user-callerid:5] Set(“SIP/205-09893c60”, “AMPUSERCIDNAME=CSR 205”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/205-09893c60”, “0?report”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-user-callerid:7] Set(“SIP/205-09893c60”, “AMPUSERCID=205”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-user-callerid:8] Set(“SIP/205-09893c60”, “CALLERID(all)=“CSR 205” <205>”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-user-callerid:9] Set(“SIP/205-09893c60”, “REALCALLERIDNUM=205”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-user-callerid:10] ExecIf(“SIP/205-09893c60”, “0|Set|CHANNEL(language)=”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: ExecIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-user-callerid:11] GotoIf(“SIP/205-09893c60”, “1?continue”) in new stack
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Goto (macro-user-callerid,s,20)
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-user-callerid:20] NoOp(“SIP/205-09893c60”, “Using CallerID “CSR 205” <205>”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Noop
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [5032220006@from-internal:2] Set(“SIP/205-09893c60”, “_NODEST=”) in new stack
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [5032220006@from-internal:3] Macro(“SIP/205-09893c60”, “record-enable|205|OUT|”) in new stack
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/205-09893c60”, “1?check”) in new stack
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Goto (macro-record-enable,s,4)
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-record-enable:4] AGI(“SIP/205-09893c60”, “recordingcheck|20081117-143832|1226961512.1086”) in new stack
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Nov 17 14:38:32] VERBOSE[8709] logger.c: recordingcheck|20081117-143832|1226961512.1086: Outbound recording enabled.
[Nov 17 14:38:32] VERBOSE[8709] logger.c: recordingcheck|20081117-143832|1226961512.1086: CALLFILENAME=OUT205-20081117-143832-1226961512.1086
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – AGI Script recordingcheck completed, returning 0
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: AGI
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-record-enable:999] MixMonitor(“SIP/205-09893c60”, “OUT205-20081117-143832-1226961512.1086.wav||”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: MixMonitor
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [5032220006@from-internal:4] Macro(“SIP/205-09893c60”, “dialout-trunk|2|5032220006||”) in new stack
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/205-09893c60”, “DIAL_TRUNK=2”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] DEBUG[8709] func_db.c: DB: AMPUSER/205/pinless not found in database.
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/205-09893c60”, “0?sub-pincheck|s|1”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: GosubIf
[Nov 17 14:38:32] DEBUG[8709] func_db.c: DB: AMPUSER/205/pinless not found in database.
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/205-09893c60”, “0?disabletrunk|1”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:4] Set(“SIP/205-09893c60”, “DIAL_NUMBER=5032220006”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/205-09893c60”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/205-09893c60”, “OUTBOUND_GROUP=OUT_2”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/205-09893c60”, “0?nomax”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:8] GotoIf(“SIP/205-09893c60”, “0?chanfull”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/205-09893c60”, “0?skipoutcid”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:10] Set(“SIP/205-09893c60”, “DIAL_TRUNK_OPTIONS=”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/205-09893c60”, “outbound-callerid|2”) in new stack
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/205-09893c60”, “0|SetCallerPres|”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: ExecIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/205-09893c60”, “0|Set|REALCALLERIDNUM=205”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: ExecIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-outbound-callerid:3] GotoIf(“SIP/205-09893c60”, “1?normcid”) in new stack
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Goto (macro-outbound-callerid,s,6)
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-outbound-callerid:6] Set(“SIP/205-09893c60”, “USEROUTCID=”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] DEBUG[8709] func_db.c: DB: DEVICE/205/emergency_cid not found in database.
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-outbound-callerid:7] Set(“SIP/205-09893c60”, “EMERGENCYCID=”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-outbound-callerid:8] Set(“SIP/205-09893c60”, “TRUNKOUTCID=”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-outbound-callerid:9] GotoIf(“SIP/205-09893c60”, “1?trunkcid”) in new stack
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Goto (macro-outbound-callerid,s,12)
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-outbound-callerid:12] ExecIf(“SIP/205-09893c60”, “0|Set|CALLERID(all)=”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: ExecIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-outbound-callerid:13] GotoIf(“SIP/205-09893c60”, “1?exit”) in new stack
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Goto (macro-outbound-callerid,s,11)
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-outbound-callerid:11] MacroExit(“SIP/205-09893c60”, “”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Macro
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:12] ExecIf(“SIP/205-09893c60”, “0|AGI|fixlocalprefix”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: ExecIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/205-09893c60”, “OUTNUM=5032220006”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/205-09893c60”, “custom=ZAP/g4”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Set
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/205-09893c60”, “0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^)”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: ExecIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:16] Macro(“SIP/205-09893c60”, “dialout-trunk-predial-hook|”) in new stack
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/205-09893c60”, “”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: Macro
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:17] GotoIf(“SIP/205-09893c60”, “0?bypass|1”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/205-09893c60”, “0?customtrunk”) in new stack
[Nov 17 14:38:32] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Executing [s@macro-dialout-trunk:19] Dial(“SIP/205-09893c60”, “ZAP/g4/5032220006|300|”) in new stack
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Requested transfer capability: 0x00 - SPEECH
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Called g4/5032220006
[Nov 17 14:38:32] VERBOSE[8711] logger.c: == Begin MixMonitor Recording SIP/205-09893c60
[Nov 17 14:38:32] DEBUG[2770] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 1
[Nov 17 14:38:32] VERBOSE[8709] logger.c: – Zap/1-1 is proceeding passing it to SIP/205-09893c60
[Nov 17 14:38:34] VERBOSE[8709] logger.c: – Zap/1-1 is ringing
[Nov 17 14:38:41] DEBUG[2770] chan_zap.c: Echo cancellation already on
[Nov 17 14:38:41] VERBOSE[8709] logger.c: – Zap/1-1 answered SIP/205-09893c60
[Nov 17 14:40:46] VERBOSE[2770] logger.c: – Accepting call from ‘5033311016’ to ‘5032390100’ on channel 0/2, span 1
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [5032390100@from-pstn:1] NoOp(“Zap/2-1”, “Catch-All DID Match - Found 5032390100 - You probably want a DID for this.”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [5032390100@from-pstn:2] Goto(“Zap/2-1”, “ext-did|s|1”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Goto (ext-did,s,1)
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@ext-did:1] Set(“Zap/2-1”, “__FROM_DID=s”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@ext-did:2] Gosub(“Zap/2-1”, “app-blacklist-check|s|1”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@app-blacklist-check:1] LookupBlacklist(“Zap/2-1”, “”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@app-blacklist-check:2] GotoIf(“Zap/2-1”, “0?blacklisted”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@app-blacklist-check:3] Return(“Zap/2-1”, “”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@ext-did:3] ExecIf(“Zap/2-1”, “0 |Set|CALLERID(name)=5033311016”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@ext-did:4] Set(“Zap/2-1”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@ext-did:5] SetCallerPres(“Zap/2-1”, “allowed_not_screened”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@ext-did:6] Goto(“Zap/2-1”, “timeconditions|11|1”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Goto (timeconditions,11,1)
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [11@timeconditions:1] GotoIfTime(“Zap/2-1”, “00:01-23:59||4|jul?from-did-direct|200|1") in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [11@timeconditions:2] Goto(“Zap/2-1”, “timeconditions|12|1”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Goto (timeconditions,12,1)
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [12@timeconditions:1] GotoIfTime(“Zap/2-1”, "08:45-22:15|mon|
|*?ivr-2|s|1”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Goto (ivr-2,s,1)
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@ivr-2:1] Set(“Zap/2-1”, “MSG=custom/NewJanHours08”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@ivr-2:2] Set(“Zap/2-1”, “LOOPCOUNT=0”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@ivr-2:3] Set(“Zap/2-1”, “__DIR-CONTEXT=default”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@ivr-2:4] Set(“Zap/2-1”, “_IVR_CONTEXT_ivr-2=”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@ivr-2:5] Set(“Zap/2-1”, “_IVR_CONTEXT=ivr-2”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@ivr-2:6] GotoIf(“Zap/2-1”, “0?begin”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@ivr-2:7] Answer(“Zap/2-1”, “”) in new stack
[Nov 17 14:40:46] VERBOSE[8718] logger.c: – Executing [s@ivr-2:8] Wait(“Zap/2-1”, “1”) in new stack
[Nov 17 14:40:47] VERBOSE[8718] logger.c: – Executing [s@ivr-2:9] Set(“Zap/2-1”, “TIMEOUT(digit)=3”) in new stack
[Nov 17 14:40:47] VERBOSE[8718] logger.c: – Digit timeout set to 3
[Nov 17 14:40:47] VERBOSE[8718] logger.c: – Executing [s@ivr-2:10] Set(“Zap/2-1”, “TIMEOUT(response)=10”) in new stack
[Nov 17 14:40:47] VERBOSE[8718] logger.c: – Response timeout set to 10
[Nov 17 14:40:47] VERBOSE[8718] logger.c: – Executing [s@ivr-2:11] Set(“Zap/2-1”, “__IVR_RETVM=”) in new stack
[Nov 17 14:40:47] VERBOSE[8718] logger.c: – Executing [s@ivr-2:12] ExecIf(“Zap/2-1”, “1|Background|custom/NewJanHours08”) in new stack
[Nov 17 14:40:47] VERBOSE[8718] logger.c: – <Zap/2-1> Playing ‘custom/NewJanHours08’ (language ‘en’)
[Nov 17 14:40:47] VERBOSE[2770] logger.c: – Channel 0/1, span 1 got hangup request, cause 16
[Nov 17 14:40:47] DEBUG[8709] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/1-1
[Nov 17 14:40:47] DEBUG[8709] chan_zap.c: Not yet hungup… Calling hangup once with icause, and clearing call
[Nov 17 14:40:47] DEBUG[8709] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/1-1
[Nov 17 14:40:47] VERBOSE[8709] logger.c: – Hungup ‘Zap/1-1’
[Nov 17 14:40:47] VERBOSE[8709] logger.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/205-09893c60’ in macro ‘dialout-trunk’
[Nov 17 14:40:47] VERBOSE[8709] logger.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/205-09893c60’
[Nov 17 14:40:47] VERBOSE[8709] logger.c: – Executing [h@macro-dialout-trunk:1] Macro(“SIP/205-09893c60”, “hangupcall|”) in new stack
[Nov 17 14:40:47] VERBOSE[8709] logger.c: – Executing [s@macro-hangupcall:1] ResetCDR(“SIP/205-09893c60”, “w”) in new stack
[Nov 17 14:40:47] DEBUG[8709] app_macro.c: Executed application: ResetCDR
[Nov 17 14:40:47] VERBOSE[8709] logger.c: – Executing [s@macro-hangupcall:2] NoCDR(“SIP/205-09893c60”, “”) in new stack
[Nov 17 14:40:47] DEBUG[8709] app_macro.c: Executed application: NoCDR
[Nov 17 14:40:47] VERBOSE[8709] logger.c: – Executing [s@macro-hangupcall:3] GotoIf(“SIP/205-09893c60”, “1?skiprg”) in new stack
[Nov 17 14:40:47] VERBOSE[8709] logger.c: – Goto (macro-hangupcall,s,6)
[Nov 17 14:40:47] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:40:47] VERBOSE[8709] logger.c: – Executing [s@macro-hangupcall:6] GotoIf(“SIP/205-09893c60”, “1?skipblkvm”) in new stack
[Nov 17 14:40:47] VERBOSE[8709] logger.c: – Goto (macro-hangupcall,s,9)
[Nov 17 14:40:47] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:40:47] VERBOSE[8709] logger.c: – Executing [s@macro-hangupcall:9] GotoIf(“SIP/205-09893c60”, “1?theend”) in new stack
[Nov 17 14:40:47] VERBOSE[8709] logger.c: – Goto (macro-hangupcall,s,11)
[Nov 17 14:40:47] DEBUG[8709] app_macro.c: Executed application: GotoIf
[Nov 17 14:40:47] VERBOSE[8709] logger.c: – Executing [s@macro-hangupcall:11] Hangup(“SIP/205-09893c60”, “”) in new stack
[Nov 17 14:40:47] VERBOSE[8709] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/205-09893c60’ in macro ‘hangupcall’
[Nov 17 14:40:47] VERBOSE[8709] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘SIP/205-09893c60’
[Nov 17 14:40:47] VERBOSE[8711] logger.c: == End MixMonitor Recording SIP/205-09893c60
[Nov 17 14:40:57] VERBOSE[8718] logger.c: == CDR updated on Zap/2-1
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [2@ivr-2:1] DBdel(“Zap/2-1”, “”) in new stack
[Nov 17 14:40:57] DEBUG[8718] app_db.c: Ignoring, no parameters
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [2@ivr-2:2] Set(“Zap/2-1”, “__NODEST=”) in new stack
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [2@ivr-2:3] Goto(“Zap/2-1”, “ext-queues|451|1”) in new stack
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Goto (ext-queues,451,1)
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [451@ext-queues:1] Macro(“Zap/2-1”, “user-callerid|”) in new stack
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [s@macro-user-callerid:1] Set(“Zap/2-1”, “AMPUSER=5033311016”) in new stack
[Nov 17 14:40:57] DEBUG[8718] app_macro.c: Executed application: Set
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“Zap/2-1”, “0?report”) in new stack
[Nov 17 14:40:57] DEBUG[8718] app_macro.c: Executed application: GotoIf
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“Zap/2-1”, “1|Set|REALCALLERIDNUM=5033311016”) in new stack
[Nov 17 14:40:57] DEBUG[8718] app_macro.c: Executed application: ExecIf
[Nov 17 14:40:57] DEBUG[8718] func_db.c: DB: DEVICE/5033311016/user not found in database.
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [s@macro-user-callerid:4] Set(“Zap/2-1”, “AMPUSER=”) in new stack
[Nov 17 14:40:57] DEBUG[8718] app_macro.c: Executed application: Set
[Nov 17 14:40:57] DEBUG[8718] func_db.c: DB: AMPUSER//cidname not found in database.
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [s@macro-user-callerid:5] Set(“Zap/2-1”, “AMPUSERCIDNAME=”) in new stack
[Nov 17 14:40:57] DEBUG[8718] app_macro.c: Executed application: Set
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“Zap/2-1”, “1?report”) in new stack
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Goto (macro-user-callerid,s,11)
[Nov 17 14:40:57] DEBUG[8718] app_macro.c: Executed application: GotoIf
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [s@macro-user-callerid:11] GotoIf(“Zap/2-1”, “0?continue”) in new stack
[Nov 17 14:40:57] DEBUG[8718] app_macro.c: Executed application: GotoIf
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [s@macro-user-callerid:12] Set(“Zap/2-1”, “__TTL=64”) in new stack
[Nov 17 14:40:57] DEBUG[8718] app_macro.c: Executed application: Set
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [s@macro-user-callerid:13] GotoIf(“Zap/2-1”, “1?continue”) in new stack
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Goto (macro-user-callerid,s,20)
[Nov 17 14:40:57] DEBUG[8718] app_macro.c: Executed application: GotoIf
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [s@macro-user-callerid:20] NoOp(“Zap/2-1”, "Using CallerID “STRAU " <5033311016>”) in new stack
[Nov 17 14:40:57] DEBUG[8718] app_macro.c: Executed application: Noop
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [451@ext-queues:2] Answer(“Zap/2-1”, “”) in new stack
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [451@ext-queues:3] Set(“Zap/2-1”, “__BLKVM_OVERRIDE=BLKVM/451/Zap/2-1”) in new stack
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [451@ext-queues:4] Set(“Zap/2-1”, “__BLKVM_BASE=451”) in new stack
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [451@ext-queues:5] Set(“Zap/2-1”, “DB(BLKVM/451/Zap/2-1)=TRUE”) in new stack
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [451@ext-queues:6] ExecIf(“Zap/2-1”, “1|Set|_DIAL_OPTIONS=trM(auto-blkvm)”) in new stack
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [451@ext-queues:7] Set(“Zap/2-1”, “__NODEST=451”) in new stack
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [451@ext-queues:8] Set(“Zap/2-1”, “MONITOR_FILENAME=/var/spool/asterisk/monitor/q451-20081117-144057-1226961646.1088”) in new stack
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – Executing [451@ext-queues:9] Playback(“Zap/2-1”, “custom/Forced-Record”) in new stack
[Nov 17 14:40:57] VERBOSE[8718] logger.c: – <Zap/2-1> Playing ‘custom/Forced-Record’ (language ‘en’)
[Nov 17 14:41:02] VERBOSE[8718] logger.c: – Executing [451@ext-queues:10] Set(“Zap/2-1”, “__MOHCLASS=default”) in new stack
[Nov 17 14:41:02] VERBOSE[8718] logger.c: – Executing [451@ext-queues:11] Set(“Zap/2-1”, “__CWIGNORE=TRUE”) in new stack
[Nov 17 14:41:02] VERBOSE[8718] logger.c: – Executing [451@ext-queues:12] Queue(“Zap/2-1”, “451|t||custom/CS-Whisper”) in new stack
[Nov 17 14:41:02] VERBOSE[8718] logger.c: – Started music on hold, class ‘default’, on Zap/2-1
[Nov 17 14:41:02] VERBOSE[8718] logger.c: – outgoing agentcall, to agent ‘402’, on ‘Local/205@from-internal-5f2e,1’
[Nov 17 14:41:02] VERBOSE[8718] logger.c: – outgoing agentcall, to agent ‘403’, on ‘Local/201@from-internal-96aa,1’
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [205@from-internal:1] Macro(“Local/205@from-internal-5f2e,2”, “exten-vm|205|205”) in new stack
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:1] Macro(“Local/205@from-internal-5f2e,2”, “user-callerid”) in new stack
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-user-callerid:1] Set(“Local/205@from-internal-5f2e,2”, “AMPUSER=5033311016”) in new stack
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: Set
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“Local/205@from-internal-5f2e,2”, “1?report”) in new stack
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Goto (macro-user-callerid,s,11)
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-user-callerid:11] GotoIf(“Local/205@from-internal-5f2e,2”, “0?continue”) in new stack
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: GotoIf

[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-user-callerid:12] Set(“Local/205@from-internal-5f2e,2”, “__TTL=63”) in new stack
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: Set
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-user-callerid:13] GotoIf(“Local/205@from-internal-5f2e,2”, “1?continue”) in new stack
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Goto (macro-user-callerid,s,20)
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-user-callerid:20] NoOp(“Local/205@from-internal-5f2e,2”, “Using CallerID “STRAU " <5033311016>”) in new stack
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: Noop
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: Macro
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:2] Set(“Local/205@from-internal-5f2e,2”, “RingGroupMethod=none”) in new stack
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: Set
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:3] Set(“Local/205@from-internal-5f2e,2”, “VMBOX=205”) in new stack
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: Set
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:4] Set(“Local/205@from-internal-5f2e,2”, “EXTTOCALL=205”) in new stack
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: Set
[Nov 17 14:41:02] DEBUG[8719] func_db.c: DB: CFU/205 not found in database.
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:5] Set(“Local/205@from-internal-5f2e,2”, “CFUEXT=”) in new stack
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: Set
[Nov 17 14:41:02] DEBUG[8719] func_db.c: DB: CFB/205 not found in database.
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:6] Set(“Local/205@from-internal-5f2e,2”, “CFBEXT=”) in new stack
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: Set
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:7] Set(“Local/205@from-internal-5f2e,2”, “RT=15”) in new stack
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: Set
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:8] Macro(“Local/205@from-internal-5f2e,2”, “record-enable|205|IN”) in new stack
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“Local/205@from-internal-5f2e,2”, “1?check”) in new stack
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Goto (macro-record-enable,s,4)
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-record-enable:4] AGI(“Local/205@from-internal-5f2e,2”, “recordingcheck|20081117-144102|1226961662.1090”) in new stack
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [201@from-internal:1] Macro(“Local/201@from-internal-96aa,2”, “exten-vm|novm|201”) in new stack
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-exten-vm:1] Macro(“Local/201@from-internal-96aa,2”, “user-callerid”) in new stack
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-user-callerid:1] Set(“Local/201@from-internal-96aa,2”, “AMPUSER=5033311016”) in new stack
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: Set
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“Local/201@from-internal-96aa,2”, “1?report”) in new stack
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Goto (macro-user-callerid,s,11)
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-user-callerid:11] GotoIf(“Local/201@from-internal-96aa,2”, “0?continue”) in new stack
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-user-callerid:12] Set(“Local/201@from-internal-96aa,2”, “__TTL=63”) in new stack
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: Set
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-user-callerid:13] GotoIf(“Local/201@from-internal-96aa,2”, “1?continue”) in new stack
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Goto (macro-user-callerid,s,20)
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-user-callerid:20] NoOp(“Local/201@from-internal-96aa,2”, “Using CallerID “STRAU " <5033311016>”) in new stack
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: Noop
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: Macro
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-exten-vm:2] Set(“Local/201@from-internal-96aa,2”, “RingGroupMethod=none”) in new stack
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: Set
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-exten-vm:3] Set(“Local/201@from-internal-96aa,2”, “VMBOX=novm”) in new stack
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: Set
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-exten-vm:4] Set(“Local/201@from-internal-96aa,2”, “EXTTOCALL=201”) in new stack
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: Set
[Nov 17 14:41:02] DEBUG[8720] func_db.c: DB: CFU/201 not found in database.
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-exten-vm:5] Set(“Local/201@from-internal-96aa,2”, “CFUEXT=”) in new stack
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: Set
[Nov 17 14:41:02] DEBUG[8720] func_db.c: DB: CFB/201 not found in database.
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-exten-vm:6] Set(“Local/201@from-internal-96aa,2”, “CFBEXT=”) in new stack
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: Set
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-exten-vm:7] Set(“Local/201@from-internal-96aa,2”, “RT=”””) in new stack
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: Set
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-exten-vm:8] Macro(“Local/201@from-internal-96aa,2”, “record-enable|201|IN”) in new stack
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“Local/201@from-internal-96aa,2”, “1?check”) in new stack
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Goto (macro-record-enable,s,4)
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-record-enable:4] AGI(“Local/201@from-internal-96aa,2”, “recordingcheck|20081117-144102|1226961662.1093”) in new stack
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Nov 17 14:41:02] VERBOSE[8720] logger.c: recordingcheck|20081117-144102|1226961662.1093: Inbound recording not enabled
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – AGI Script recordingcheck completed, returning 0
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: AGI
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-record-enable:5] MacroExit(“Local/201@from-internal-96aa,2”, “”) in new stack
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: Macro
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-exten-vm:9] Macro(“Local/201@from-internal-96aa,2”, “dial||tr|201”) in new stack
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-dial:1] GotoIf(“Local/201@from-internal-96aa,2”, “0?dial”) in new stack
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-dial:2] SetMusicOnHold(“Local/201@from-internal-96aa,2”, “default”) in new stack
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: SetMusicOnHold
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-dial:3] AGI(“Local/201@from-internal-96aa,2”, “dialparties.agi”) in new stack
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[Nov 17 14:41:02] VERBOSE[8720] logger.c: dialparties.agi: Starting New Dialparties.agi
[Nov 17 14:41:02] VERBOSE[8724] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Nov 17 14:41:02] VERBOSE[8724] logger.c: Found
[Nov 17 14:41:02] VERBOSE[8724] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Nov 17 14:41:02] VERBOSE[8724] logger.c: Found
[Nov 17 14:41:02] VERBOSE[8724] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Nov 17 14:41:02] VERBOSE[8724] logger.c: Found
[Nov 17 14:41:02] VERBOSE[8724] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Nov 17 14:41:02] VERBOSE[8720] logger.c: dialparties.agi: Caller ID name is ‘STRAU’ number is ‘5033311016’
[Nov 17 14:41:02] VERBOSE[8720] logger.c: dialparties.agi: Methodology of ring is ‘none’
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – dialparties.agi: Added extension 201 to extension map
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – dialparties.agi: Extension 201 cf is disabled
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – dialparties.agi: Extension 201 do not disturb is disabled
[Nov 17 14:41:02] VERBOSE[8720] logger.c: dialparties.agi: Extension 201 has ExtensionState: 0
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – dialparties.agi: Checking CW and CFB status for extension 201
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – dialparties.agi: dbset CALLTRACE/201 to 5033311016
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – dialparties.agi: Filtered ARG3: 201
[Nov 17 14:41:02] VERBOSE[8724] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – AGI Script dialparties.agi completed, returning 0
[Nov 17 14:41:02] DEBUG[8720] app_macro.c: Executed application: AGI
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Executing [s@macro-dial:7] Dial(“Local/201@from-internal-96aa,2”, “SIP/201||trM(auto-blkvm)”) in new stack
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – Called 201
[Nov 17 14:41:02] VERBOSE[8718] logger.c: – Agent/403 is ringing
[Nov 17 14:41:02] VERBOSE[8720] logger.c: – SIP/201-09893c60 is ringing
[Nov 17 14:41:02] VERBOSE[8719] logger.c: recordingcheck|20081117-144102|1226961662.1090: Inbound recording not enabled
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – AGI Script recordingcheck completed, returning 0
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: AGI
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-record-enable:5] MacroExit(“Local/205@from-internal-5f2e,2”, “”) in new stack
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: Macro
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:9] Macro(“Local/205@from-internal-5f2e,2”, “dial|15|tr|205”) in new stack
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-dial:1] GotoIf(“Local/205@from-internal-5f2e,2”, “0?dial”) in new stack
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-dial:2] SetMusicOnHold(“Local/205@from-internal-5f2e,2”, “default”) in new stack
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: SetMusicOnHold
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-dial:3] AGI(“Local/205@from-internal-5f2e,2”, “dialparties.agi”) in new stack
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[Nov 17 14:41:02] VERBOSE[8719] logger.c: dialparties.agi: Starting New Dialparties.agi
[Nov 17 14:41:02] VERBOSE[8726] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [Nov 17 14:41:02] VERBOSE[8726] logger.c: Found
[Nov 17 14:41:02] VERBOSE[8726] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [Nov 17 14:41:02] VERBOSE[8726] logger.c: Found
[Nov 17 14:41:02] VERBOSE[8726] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [Nov 17 14:41:02] VERBOSE[8726] logger.c: Found
[Nov 17 14:41:02] VERBOSE[8726] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[Nov 17 14:41:02] VERBOSE[8719] logger.c: dialparties.agi: Caller ID name is ‘STRAU’ number is ‘5033311016’
[Nov 17 14:41:02] VERBOSE[8719] logger.c: dialparties.agi: Methodology of ring is ‘none’
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – dialparties.agi: Added extension 205 to extension map
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – dialparties.agi: Extension 205 cf is disabled
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – dialparties.agi: Extension 205 do not disturb is disabled
[Nov 17 14:41:02] VERBOSE[8719] logger.c: dialparties.agi: Extension 205 has ExtensionState: 0
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – dialparties.agi: Checking CW and CFB status for extension 205
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – dialparties.agi: dbset CALLTRACE/205 to 5033311016
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – dialparties.agi: Filtered ARG3: 205
[Nov 17 14:41:02] VERBOSE[8726] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – AGI Script dialparties.agi completed, returning 0
[Nov 17 14:41:02] DEBUG[8719] app_macro.c: Executed application: AGI
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Executing [s@macro-dial:7] Dial(“Local/205@from-internal-5f2e,2”, “SIP/205|15|trM(auto-blkvm)”) in new stack
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – Called 205
[Nov 17 14:41:02] VERBOSE[8718] logger.c: – Agent/402 is ringing
[Nov 17 14:41:02] VERBOSE[8719] logger.c: – SIP/205-0988cf30 is ringing
[Nov 17 14:41:06] VERBOSE[2772] logger.c: – Got SIP response 486 “Busy Here” back from 192.168.168.121
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – SIP/205-0988cf30 is busy
[Nov 17 14:41:06] VERBOSE[8719] logger.c: == Everyone is busy/congested at this time (1:1/0/0)
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: Dial
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-dial:8] Set(“Local/205@from-internal-5f2e,2”, “DIALSTATUS=BUSY”) in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: Set
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-dial:9] GosubIf(“Local/205@from-internal-5f2e,2”, “0?BUSY|1”) in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: GosubIf
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: Macro
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:10] GotoIf(“Local/205@from-internal-5f2e,2”, “0?exit|return”) in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:11] Set(“Local/205@from-internal-5f2e,2”, “SV_DIALSTATUS=BUSY”) in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: Set
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:12] GosubIf(“Local/205@from-internal-5f2e,2”, “0?docfu|1”) in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: GosubIf
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:13] GosubIf(“Local/205@from-internal-5f2e,2”, “0?docfb|1”) in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: GosubIf
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:14] Set(“Local/205@from-internal-5f2e,2”, “DIALSTATUS=BUSY”) in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: Set
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:15] NoOp(“Local/205@from-internal-5f2e,2”, “Voicemail is 205”) in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: NoOp
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:16] GotoIf(“Local/205@from-internal-5f2e,2”, “0?s-BUSY|1”) in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:17] NoOp(“Local/205@from-internal-5f2e,2”, “Sending to Voicemail box 205”) in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: NoOp
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-exten-vm:18] Macro(“Local/205@from-internal-5f2e,2”, “vm|205|BUSY|”) in new stack
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-vm:1] Macro(“Local/205@from-internal-5f2e,2”, “user-callerid|SKIPTTL”) in new stack
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-user-callerid:1] Set(“Local/205@from-internal-5f2e,2”, “AMPUSER=5033311016”) in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: Set
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“Local/205@from-internal-5f2e,2”, “1?report”) in new stack
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Goto (macro-user-callerid,s,11)
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-user-callerid:11] GotoIf(“Local/205@from-internal-5f2e,2”, “1?continue”) in new stack
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Goto (macro-user-callerid,s,20)
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-user-callerid:20] NoOp(“Local/205@from-internal-5f2e,2”, “Using CallerID “STRAU " <5033311016>”) in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: Noop
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: Macro
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-vm:2] Set(“Local/205@from-internal-5f2e,2”, “VMGAIN=””") in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: Set
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-vm:3] GotoIf(“Local/205@from-internal-5f2e,2”, “0?vmx|1”) in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:06] WARNING[8719] func_db.c: DB requires an argument, DB(/)
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-vm:4] NoOp(“Local/205@from-internal-5f2e,2”, "CAME FROM: 451 - Blocking VM cause of key: ") in new stack
[Nov 17 14:41:06] DEBUG[8719] app_macro.c: Executed application: Noop
[Nov 17 14:41:06] VERBOSE[8719] logger.c: – Executing [s@macro-vm:5] Hangup(“Local/205@from-internal-5f2e,2”, “”) in new stack
[Nov 17 14:41:06] VERBOSE[8719] logger.c: == Spawn extension (macro-vm, s, 5) exited non-zero on ‘Local/205@from-internal-5f2e,2’ in macro ‘vm’
[Nov 17 14:41:06] VERBOSE[8719] logger.c: == Spawn extension (macro-vm, s, 5) exited non-zero on ‘Local/205@from-internal-5f2e,2’ in macro ‘exten-vm’
[Nov 17 14:41:06] VERBOSE[8719] logger.c: == Spawn extension (macro-vm, s, 5) exited non-zero on ‘Local/205@from-internal-5f2e,2’
[Nov 17 14:41:06] DEBUG[8718] app_queue.c: Dunno what to do with control type -1
[Nov 17 14:41:06] DEBUG[8718] chan_agent.c: Bridge on ‘Local/205@from-internal-5f2e,1’ being cleared (2)
[Nov 17 14:41:06] VERBOSE[8718] logger.c: – Nobody picked up in 4000 ms
[Nov 17 14:41:08] VERBOSE[8720] logger.c: – SIP/201-09893c60 answered Local/201@from-internal-96aa,2
[Nov 17 14:41:08] VERBOSE[8720] logger.c: – Executing [s@macro-auto-blkvm:1] Set(“SIP/201-09893c60”, “__MACRO_RESULT=”) in new stack
[Nov 17 14:41:08] DEBUG[8720] app_macro.c: Executed application: Set
[Nov 17 14:41:08] VERBOSE[8720] logger.c: – Executing [s@macro-auto-blkvm:2] DBdel(“SIP/201-09893c60”, “BLKVM/451/Zap/2-1”) in new stack
[Nov 17 14:41:08] VERBOSE[8720] logger.c: – DBdel: family=BLKVM, key=451/Zap/2-1
[Nov 17 14:41:08] DEBUG[8720] app_macro.c: Executed application: dbDel
[Nov 17 14:41:08] DEBUG[8720] app_dial.c: Macro exited with status 0
[Nov 17 14:41:08] DEBUG[8718] app_queue.c: Dunno what to do with control type -1
[Nov 17 14:41:08] VERBOSE[8718] logger.c: – Agent/403 answered Zap/2-1
[Nov 17 14:41:08] DEBUG[8718] chan_zap.c: Set option TONE VERIFY, mode: MUTECONF(1) on Zap/2-1
[Nov 17 14:41:08] VERBOSE[8718] logger.c: – <Agent/403> Playing ‘custom/CS-Whisper’ (language ‘en’)
[Nov 17 14:41:08] DEBUG[8718] chan_agent.c: Bridge on ‘SIP/201-09893c60’ being set to ‘Agent/403’ (3)
[Nov 17 14:41:08] VERBOSE[8720] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘Local/201@from-internal-96aa,2’ in macro ‘dial’
[Nov 17 14:41:08] VERBOSE[8720] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘Local/201@from-internal-96aa,2’ in macro ‘exten-vm’
[Nov 17 14:41:08] VERBOSE[8720] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘Local/201@from-internal-96aa,2’
[Nov 17 14:41:08] VERBOSE[8720] logger.c: – Executing [h@macro-dial:1] Macro(“Local/201@from-internal-96aa,2”, “hangupcall”) in new stack
[Nov 17 14:41:08] VERBOSE[8720] logger.c: – Executing [s@macro-hangupcall:1] ResetCDR(“Local/201@from-internal-96aa,2”, “w”) in new stack
[Nov 17 14:41:08] DEBUG[8720] app_macro.c: Executed application: ResetCDR
[Nov 17 14:41:08] VERBOSE[8720] logger.c: – Executing [s@macro-hangupcall:2] NoCDR(“Local/201@from-internal-96aa,2”, “”) in new stack
[Nov 17 14:41:08] DEBUG[8720] app_macro.c: Executed application: NoCDR
[Nov 17 14:41:08] VERBOSE[8720] logger.c: – Executing [s@macro-hangupcall:3] GotoIf(“Local/201@from-internal-96aa,2”, “1?skiprg”) in new stack
[Nov 17 14:41:08] VERBOSE[8720] logger.c: – Goto (macro-hangupcall,s,6)
[Nov 17 14:41:08] DEBUG[8720] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:08] VERBOSE[8720] logger.c: – Executing [s@macro-hangupcall:6] GotoIf(“Local/201@from-internal-96aa,2”, “1?skipblkvm”) in new stack
[Nov 17 14:41:08] VERBOSE[8720] logger.c: – Goto (macro-hangupcall,s,9)
[Nov 17 14:41:08] DEBUG[8720] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:08] VERBOSE[8720] logger.c: – Executing [s@macro-hangupcall:9] GotoIf(“Local/201@from-internal-96aa,2”, “1?theend”) in new stack
[Nov 17 14:41:08] VERBOSE[8720] logger.c: – Goto (macro-hangupcall,s,11)
[Nov 17 14:41:08] DEBUG[8720] app_macro.c: Executed application: GotoIf
[Nov 17 14:41:08] VERBOSE[8720] logger.c: – Executing [s@macro-hangupcall:11] Hangup(“Local/201@from-internal-96aa,2”, “”) in new stack
[Nov 17 14:41:08] VERBOSE[8720] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘Local/201@from-internal-96aa,2’ in macro ‘hangupcall’
[Nov 17 14:41:08] VERBOSE[8720] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on ‘Local/201@from-internal-96aa,2’
[Nov 17 14:41:10] VERBOSE[8718] logger.c: – Stopped music on hold on Zap/2-1
[Nov 17 14:41:10] VERBOSE[8727] logger.c: == Begin MixMonitor Recording Zap/2-1
[Nov 17 14:41:49] DEBUG[8718] chan_agent.c: Bridge on ‘SIP/201-09893c60’ being cleared (2)
[Nov 17 14:41:49] VERBOSE[8718] logger.c: == Spawn extension (ext-queues, 451, 12) exited non-zero on ‘Zap/2-1’
[Nov 17 14:41:49] DEBUG[8718] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/2-1
[Nov 17 14:41:49] DEBUG[8718] chan_zap.c: Not yet hungup… Calling hangup once with icause, and clearing call
[Nov 17 14:41:49] DEBUG[8718] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/2-1
[Nov 17 14:41:49] VERBOSE[8718] logger.c: – Hungup ‘Zap/2-1’
[Nov 17 14:41:49] VERBOSE[8727] logger.c: == End MixMonitor Recording Zap/2-1
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [5034971088@from-internal:1] Macro(“SIP/201-09893c60”, “user-callerid|SKIPTTL|”) in new stack
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [s@macro-user-callerid:1] Set(“SIP/201-09893c60”, “AMPUSER=201”) in new stack
[Nov 17 14:42:16] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/201-09893c60”, “0?report”) in new stack
[Nov 17 14:42:16] DEBUG[8732] app_macro.c: Executed application: GotoIf
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/201-09893c60”, “1|Set|REALCALLERIDNUM=201”) in new stack
[Nov 17 14:42:16] DEBUG[8732] app_macro.c: Executed application: ExecIf
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [s@macro-user-callerid:4] Set(“SIP/201-09893c60”, “AMPUSER=201”) in new stack
[Nov 17 14:42:16] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [s@macro-user-callerid:5] Set(“SIP/201-09893c60”, “AMPUSERCIDNAME=CSR 201”) in new stack
[Nov 17 14:42:16] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/201-09893c60”, “0?report”) in new stack
[Nov 17 14:42:16] DEBUG[8732] app_macro.c: Executed application: GotoIf
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [s@macro-user-callerid:7] Set(“SIP/201-09893c60”, “AMPUSERCID=201”) in new stack
[Nov 17 14:42:16] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [s@macro-user-callerid:8] Set(“SIP/201-09893c60”, “CALLERID(all)=“CSR 201” <201>”) in new stack
[Nov 17 14:42:16] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [s@macro-user-callerid:9] Set(“SIP/201-09893c60”, “REALCALLERIDNUM=201”) in new stack
[Nov 17 14:42:16] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [s@macro-user-callerid:10] ExecIf(“SIP/201-09893c60”, “0|Set|CHANNEL(language)=”) in new stack
[Nov 17 14:42:16] DEBUG[8732] app_macro.c: Executed application: ExecIf
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [s@macro-user-callerid:11] GotoIf(“SIP/201-09893c60”, “1?continue”) in new stack
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Goto (macro-user-callerid,s,20)
[Nov 17 14:42:16] DEBUG[8732] app_macro.c: Executed application: GotoIf
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [s@macro-user-callerid:20] NoOp(“SIP/201-09893c60”, “Using CallerID “CSR 201” <201>”) in new stack
[Nov 17 14:42:16] DEBUG[8732] app_macro.c: Executed application: Noop
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [5034971088@from-internal:2] Set(“SIP/201-09893c60”, “_NODEST=”) in new stack
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [5034971088@from-internal:3] Macro(“SIP/201-09893c60”, “record-enable|201|OUT|”) in new stack
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/201-09893c60”, “1?check”) in new stack
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Goto (macro-record-enable,s,4)
[Nov 17 14:42:16] DEBUG[8732] app_macro.c: Executed application: GotoIf
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Executing [s@macro-record-enable:4] AGI(“SIP/201-09893c60”, “recordingcheck|20081117-144216|1226961736.1097”) in new stack
[Nov 17 14:42:16] VERBOSE[8732] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Nov 17 14:42:17] VERBOSE[8732] logger.c: recordingcheck|20081117-144216|1226961736.1097: Outbound recording enabled.
[Nov 17 14:42:17] VERBOSE[8732] logger.c: recordingcheck|20081117-144216|1226961736.1097: CALLFILENAME=OUT201-20081117-144216-1226961736.1097
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – AGI Script recordingcheck completed, returning 0
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: AGI
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-record-enable:999] MixMonitor(“SIP/201-09893c60”, “OUT201-20081117-144216-1226961736.1097.wav||”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: MixMonitor
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [5034971088@from-internal:4] Macro(“SIP/201-09893c60”, “dialout-trunk|2|5034971088||”) in new stack
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/201-09893c60”, “DIAL_TRUNK=2”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:17] DEBUG[8732] func_db.c: DB: AMPUSER/201/pinless not found in database.
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/201-09893c60”, “0?sub-pincheck|s|1”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: GosubIf
[Nov 17 14:42:17] DEBUG[8732] func_db.c: DB: AMPUSER/201/pinless not found in database.
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/201-09893c60”, “0?disabletrunk|1”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: GotoIf
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:4] Set(“SIP/201-09893c60”, “DIAL_NUMBER=5034971088”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/201-09893c60”, “DIAL_TRUNK_OPTIONS=tr”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/201-09893c60”, “OUTBOUND_GROUP=OUT_2”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/201-09893c60”, “0?nomax”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: GotoIf
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:8] GotoIf(“SIP/201-09893c60”, “0?chanfull”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: GotoIf
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/201-09893c60”, “0?skipoutcid”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: GotoIf
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:10] Set(“SIP/201-09893c60”, “DIAL_TRUNK_OPTIONS=”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/201-09893c60”, “outbound-callerid|2”) in new stack
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/201-09893c60”, “0|SetCallerPres|”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: ExecIf
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/201-09893c60”, “0|Set|REALCALLERIDNUM=201”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: ExecIf
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-outbound-callerid:3] GotoIf(“SIP/201-09893c60”, “1?normcid”) in new stack
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Goto (macro-outbound-callerid,s,6)
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: GotoIf
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-outbound-callerid:6] Set(“SIP/201-09893c60”, “USEROUTCID=”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:17] DEBUG[8732] func_db.c: DB: DEVICE/201/emergency_cid not found in database.
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-outbound-callerid:7] Set(“SIP/201-09893c60”, “EMERGENCYCID=”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-outbound-callerid:8] Set(“SIP/201-09893c60”, “TRUNKOUTCID=”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-outbound-callerid:9] GotoIf(“SIP/201-09893c60”, “1?trunkcid”) in new stack
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Goto (macro-outbound-callerid,s,12)
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: GotoIf
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-outbound-callerid:12] ExecIf(“SIP/201-09893c60”, “0|Set|CALLERID(all)=”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: ExecIf
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-outbound-callerid:13] GotoIf(“SIP/201-09893c60”, “1?exit”) in new stack
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Goto (macro-outbound-callerid,s,11)
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: GotoIf
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-outbound-callerid:11] MacroExit(“SIP/201-09893c60”, “”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: Macro
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:12] ExecIf(“SIP/201-09893c60”, “0|AGI|fixlocalprefix”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: ExecIf
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/201-09893c60”, “OUTNUM=5034971088”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/201-09893c60”, “custom=ZAP/g4”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: Set
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/201-09893c60”, “0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^)”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: ExecIf
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:16] Macro(“SIP/201-09893c60”, “dialout-trunk-predial-hook|”) in new stack
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/201-09893c60”, “”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: Macro
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:17] GotoIf(“SIP/201-09893c60”, “0?bypass|1”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: GotoIf
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/201-09893c60”, “0?customtrunk”) in new stack
[Nov 17 14:42:17] DEBUG[8732] app_macro.c: Executed application: GotoIf
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Executing [s@macro-dialout-trunk:19] Dial(“SIP/201-09893c60”, “ZAP/g4/5034971088|300|”) in new stack
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Requested transfer capability: 0x00 - SPEECH
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Called g4/5034971088
[Nov 17 14:42:17] VERBOSE[8734] logger.c: == Begin MixMonitor Recording SIP/201-09893c60
[Nov 17 14:42:17] DEBUG[2770] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 1
[Nov 17 14:42:17] VERBOSE[8732] logger.c: – Zap/1-1 is proceeding passing it to SIP/201-09893c60
[Nov 17 14:42:18] VERBOSE[8732] logger.c: – Zap/1-1 is ringing
[Nov 17 14:42:28] DEBUG[2770] chan_zap.c: Echo cancellation already on
[Nov 17 14:42:28] VERBOSE[8732] logger.c: – Zap/1-1 answered SIP/201-09893c60