Problems when calling 911

When we call 911 we can hear the 911 operator but they cannot hear us. All other calls work just fine.

If we hit buttons while in call with them they can hear the DTMF tones.
Call report shows call placed but shows No Answer.

We are using 2 PRI lines.
Asterisk Version 1.4.42

[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [911@from-internal:1] Macro(“SIP/1602-00010262”, “user-callerid|SKIPTTL|”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-user-callerid:1] Set(“SIP/1602-00010262”, “AMPUSER=1602”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/1602-00010262”, “0?report”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/1602-00010262”, “1|Set|REALCALLERIDNUM=1602”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-user-callerid:4] Set(“SIP/1602-00010262”, “AMPUSER=1602”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-user-callerid:5] Set(“SIP/1602-00010262”, "AMPUSERCIDNAME=Steve) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/1602-00010262”, “0?report”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-user-callerid:7] Set(“SIP/1602-00010262”, “AMPUSERCID=1602”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-user-callerid:8] Set(“SIP/1602-00010262”, “CALLERID(all)=“Steve” <1602>”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-user-callerid:9] ExecIf(“SIP/1602-00010262”, “0|Set|CHANNEL(language)=”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/1602-00010262”, “1?continue”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Goto (macro-user-callerid,s,19)
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-user-callerid:19] Set(“SIP/1602-00010262”, “CALLERID(number)=1602”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-user-callerid:20] Set(“SIP/1602-00010262”, “CALLERID(name)=Steve”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-user-callerid:21] NoOp(“SIP/1602-00010262”, “Using CallerID “Steve” <1602>”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Noop
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [911@from-internal:2] NoOp(“SIP/1602-00010262”, “Calling Out Route: Out”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [911@from-internal:3] Set(“SIP/1602-00010262”, “MOHCLASS=default”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [911@from-internal:4] Set(“SIP/1602-00010262”, “_NODEST=”) in new stack
[2011-09-02 10:18:47] VERBOSE[7111] logger.c: Extension Changed 1602[ext-local] new state InUse for Notify User 1604
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [911@from-internal:5] Macro(“SIP/1602-00010262”, “record-enable|1602|OUT|”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/1602-00010262”, “1?check”) in new stack
[2011-09-02 10:18:47] VERBOSE[7111] logger.c: Extension Changed 1602[ext-local] new state InUse for Notify User 1603
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Goto (macro-record-enable,s,4)
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-record-enable:4] ExecIf(“SIP/1602-00010262”, “0|MacroExit|”) in new stack
[2011-09-02 10:18:47] VERBOSE[7111] logger.c: Extension Changed 1602[ext-local] new state InUse for Notify User 1602
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-record-enable:5] GotoIf(“SIP/1602-00010262”, “0?Group:OUT”) in new stack
[2011-09-02 10:18:47] VERBOSE[7111] logger.c: Extension Changed 1602[ext-local] new state InUse for Notify User 1601
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Goto (macro-record-enable,s,15)
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-record-enable:15] GotoIf(“SIP/1602-00010262”, “0?IN”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-record-enable:16] ExecIf(“SIP/1602-00010262”, “1|MacroExit|”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [911@from-internal:6] Macro(“SIP/1602-00010262”, “dialout-trunk|1|911|”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/1602-00010262”, “DIAL_TRUNK=1”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] DEBUG[5523] func_db.c: DB: AMPUSER/1602/pinless not found in database.
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/1602-00010262”, “0?sub-pincheck|s|1”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GosubIf
[2011-09-02 10:18:47] DEBUG[5523] func_db.c: DB: AMPUSER/1602/pinless not found in database.
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/1602-00010262”, “0?disabletrunk|1”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:4] Set(“SIP/1602-00010262”, “DIAL_NUMBER=911”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/1602-00010262”, “DIAL_TRUNK_OPTIONS=tTrw”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/1602-00010262”, “OUTBOUND_GROUP=OUT_1”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/1602-00010262”, “0?nomax”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:8] GotoIf(“SIP/1602-00010262”, “0?chanfull”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/1602-00010262”, “0?skipoutcid”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:10] Set(“SIP/1602-00010262”, “DIAL_TRUNK_OPTIONS=TW”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/1602-00010262”, “outbound-callerid|1”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/1602-00010262”, “0|SetCallerPres|”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/1602-00010262”, “0|Set|REALCALLERIDNUM=1602”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-outbound-callerid:3] GotoIf(“SIP/1602-00010262”, “1?normcid”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Goto (macro-outbound-callerid,s,6)
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-outbound-callerid:6] Set(“SIP/1602-00010262”, “USEROUTCID=Technology <7609223242>”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] DEBUG[5523] func_db.c: DB: DEVICE/1602/emergency_cid not found in database.
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-outbound-callerid:7] Set(“SIP/1602-00010262”, “EMERGENCYCID=”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-outbound-callerid:8] Set(“SIP/1602-00010262”, “TRUNKOUTCID=”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-outbound-callerid:9] GotoIf(“SIP/1602-00010262”, “1?trunkcid”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Goto (macro-outbound-callerid,s,12)
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-outbound-callerid:12] ExecIf(“SIP/1602-00010262”, “0|Set|CALLERID(all)=”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-outbound-callerid:13] ExecIf(“SIP/1602-00010262”, “1|Set|CALLERID(all)=Technology <7609223242>”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Last app: Set|CALLERID(all)=Technology <7609223242>
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-outbound-callerid:14] ExecIf(“SIP/1602-00010262”, “0|Set|CALLERID(all)=”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/1602-00010262”, “0|SetCallerPres|prohib_passed_screen”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Macro
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:12] GosubIf(“SIP/1602-00010262”, “0?sub-flp-1|s|1”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GosubIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/1602-00010262”, “OUTNUM=911”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/1602-00010262”, “custom=DAHDI/g0”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Set
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/1602-00010262”, “0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^default)TW”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:16] Macro(“SIP/1602-00010262”, “dialout-trunk-predial-hook|”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/1602-00010262”, “”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: Macro
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:17] GotoIf(“SIP/1602-00010262”, “0?bypass|1”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/1602-00010262”, “0?customtrunk”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [s@macro-dialout-trunk:19] Dial(“SIP/1602-00010262”, “DAHDI/g0/911|300|TW”) in new stack
[2011-09-02 10:18:47] DEBUG[5523] dsp.c: dsp busy pattern set to 0,0
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Requested transfer capability: 0x00 - SPEECH
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Called g0/911
[2011-09-02 10:18:47] DEBUG[7136] chan_dahdi.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 1
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – DAHDI/1-1 is proceeding passing it to SIP/1602-00010262
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [*97@from-internal:3] Macro(“SIP/2111-00010261”, “user-callerid|”) in new stack
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:1] Set(“SIP/2111-00010261”, “AMPUSER=2111”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: Set
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/2111-00010261”, “0?report”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/2111-00010261”, “1|Set|REALCALLERIDNUM=2111”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:4] Set(“SIP/2111-00010261”, “AMPUSER=2111”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: Set
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:5] Set(“SIP/2111-00010261”, “AMPUSERCIDNAME=Kim Bayles”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: Set
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/2111-00010261”, “0?report”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:7] Set(“SIP/2111-00010261”, “AMPUSERCID=2111”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: Set
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:8] Set(“SIP/2111-00010261”, “CALLERID(all)=“Kim Bayles” <2111>”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: Set
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:9] ExecIf(“SIP/2111-00010261”, “0|Set|CHANNEL(language)=”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/2111-00010261”, “0?continue”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:11] Set(“SIP/2111-00010261”, “__TTL=64”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: Set
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/2111-00010261”, “1?continue”) in new stack
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Goto (macro-user-callerid,s,19)
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:19] Set(“SIP/2111-00010261”, “CALLERID(number)=2111”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: Set
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:20] Set(“SIP/2111-00010261”, “CALLERID(name)=Kim Bayles”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: Set
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-user-callerid:21] NoOp(“SIP/2111-00010261”, “Using CallerID “Kim Bayles” <2111>”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: Noop
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [*97@from-internal:4] Macro(“SIP/2111-00010261”, “get-vmcontext|2111”) in new stack
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-get-vmcontext:1] Set(“SIP/2111-00010261”, “VMCONTEXT=default”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: Set
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-get-vmcontext:2] GotoIf(“SIP/2111-00010261”, “0?200:300”) in new stack
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Goto (macro-get-vmcontext,s,300)
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [s@macro-get-vmcontext:300] NoOp(“SIP/2111-00010261”, “”) in new stack
[2011-09-02 10:18:48] DEBUG[5522] app_macro.c: Executed application: NoOp
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [*97@from-internal:5] MailboxExists(“SIP/2111-00010261”, “2111@default”) in new stack
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [*97@from-internal:6] GotoIf(“SIP/2111-00010261”, “1?mbexist”) in new stack
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Goto (from-internal,*97,106)
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [*97@from-internal:106] VoiceMailMain(“SIP/2111-00010261”, “2111@default”) in new stack
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – <SIP/2111-00010261> Playing ‘vm-password’ (language ‘en’)
[2011-09-02 10:18:48] VERBOSE[5530] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [2011-09-02 10:18:48] VERBOSE[5530] logger.c: Found
[2011-09-02 10:18:48] VERBOSE[5530] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [2011-09-02 10:18:48] VERBOSE[5530] logger.c: Found
[2011-09-02 10:18:48] VERBOSE[5530] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [2011-09-02 10:18:48] VERBOSE[5530] logger.c: Found
[2011-09-02 10:18:48] VERBOSE[5530] logger.c: == Manager ‘aastra-xml’ logged on from 127.0.0.1
[2011-09-02 10:18:48] VERBOSE[5530] logger.c: == Manager ‘aastra-xml’ logged off from 127.0.0.1
[2011-09-02 10:18:49] VERBOSE[7136] logger.c: – PROGRESS with cause code 127 received
[2011-09-02 10:18:49] DEBUG[7136] chan_dahdi.c: Queuing frame from PRI_EVENT_PROGRESS on channel 0/1 span 1
[2011-09-02 10:18:49] VERBOSE[5523] logger.c: – DAHDI/1-1 is making progress passing it to SIP/1602-00010262
[2011-09-02 10:18:49] NOTICE[7111] chan_sip.c: Registration from ‘“409” sip:[email protected]:5060’ failed for ‘10.64.56.112’ - No matching peer found
[2011-09-02 10:18:49] NOTICE[7111] chan_sip.c: Registration from ‘“409” sip:[email protected]:5060’ failed for ‘10.64.56.112’ - No matching peer found
[2011-09-02 10:18:49] VERBOSE[5531] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [2011-09-02 10:18:49] VERBOSE[5531] logger.c: Found
[2011-09-02 10:18:49] VERBOSE[5531] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [2011-09-02 10:18:49] VERBOSE[5531] logger.c: Found
[2011-09-02 10:18:49] VERBOSE[5531] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [2011-09-02 10:18:49] VERBOSE[5531] logger.c: Found
[2011-09-02 10:18:49] VERBOSE[5531] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[2011-09-02 10:18:49] VERBOSE[5531] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[2011-09-02 10:18:49] VERBOSE[5533] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [2011-09-02 10:18:49] VERBOSE[5533] logger.c: Found
[2011-09-02 10:18:49] VERBOSE[5533] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [2011-09-02 10:18:49] VERBOSE[5533] logger.c: Found
[2011-09-02 10:18:49] VERBOSE[5533] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [2011-09-02 10:18:49] VERBOSE[5533] logger.c: Found
[2011-09-02 10:18:49] VERBOSE[5533] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[2011-09-02 10:18:50] VERBOSE[5533] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[2011-09-02 10:18:50] VERBOSE[5455] logger.c: – Executing [h@macro-dial:1] Macro(“SIP/2109-0001025e”, “hangupcall”) in new stack
[2011-09-02 10:18:50] VERBOSE[5455] logger.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/2109-0001025e”, “1?skiprg”) in new stack
[2011-09-02 10:18:50] VERBOSE[5455] logger.c: – Goto (macro-hangupcall,s,4)
[2011-09-02 10:18:50] DEBUG[5455] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:50] VERBOSE[5455] logger.c: – Executing [s@macro-hangupcall:4] GotoIf(“SIP/2109-0001025e”, “1?skipblkvm”) in new stack
[2011-09-02 10:18:50] VERBOSE[5455] logger.c: – Goto (macro-hangupcall,s,7)
[2011-09-02 10:18:50] DEBUG[5455] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:50] VERBOSE[5455] logger.c: – Executing [s@macro-hangupcall:7] GotoIf(“SIP/2109-0001025e”, “1?theend”) in new stack
[2011-09-02 10:18:50] VERBOSE[5455] logger.c: – Goto (macro-hangupcall,s,9)
[2011-09-02 10:18:50] DEBUG[5455] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:50] VERBOSE[5455] logger.c: – Executing [s@macro-hangupcall:9] Hangup(“SIP/2109-0001025e”, “”) in new stack
[2011-09-02 10:18:50] VERBOSE[5455] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/2109-0001025e’ in macro ‘hangupcall’
[2011-09-02 10:18:50] VERBOSE[5455] logger.c: == Spawn h extension (macro-dial, h, 1) exited non-zero on ‘SIP/2109-0001025e’
[2011-09-02 10:18:50] VERBOSE[5455] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on ‘SIP/2109-0001025e’ in macro ‘dial’
[2011-09-02 10:18:50] VERBOSE[5455] logger.c: == Spawn extension (macro-exten-vm, s, 9) exited non-zero on ‘SIP/2109-0001025e’ in macro ‘exten-vm’
[2011-09-02 10:18:50] VERBOSE[5455] logger.c: == Spawn extension (from-internal, 2016, 1) exited non-zero on ‘SIP/2109-0001025e’
[2011-09-02 10:18:50] VERBOSE[7111] logger.c: Extension Changed 2109[ext-local] new state Idle for Notify User 2109
[2011-09-02 10:18:50] VERBOSE[7111] logger.c: Extension Changed 2109[ext-local] new state Idle for Notify User 2115
[2011-09-02 10:18:50] VERBOSE[7111] logger.c: Extension Changed 2109[ext-local] new state Idle for Notify User 2105
[2011-09-02 10:18:50] VERBOSE[7111] logger.c: Extension Changed 2109[ext-local] new state Idle for Notify User 2117
[2011-09-02 10:18:50] VERBOSE[7111] logger.c: Extension Changed 2109[ext-local] new state Idle for Notify User 2103
[2011-09-02 10:18:50] VERBOSE[7111] logger.c: Extension Changed 2109[ext-local] new state Idle for Notify User 1507
[2011-09-02 10:18:50] VERBOSE[7111] logger.c: Extension Changed 2109[ext-local] new state Idle for Notify User 2106
[2011-09-02 10:18:50] VERBOSE[7111] logger.c: Extension Changed 2109[ext-local] new state Idle for Notify User 2102
[2011-09-02 10:18:50] VERBOSE[7111] logger.c: Extension Changed 2109[ext-local] new state Idle for Notify User 2104
[2011-09-02 10:18:50] VERBOSE[7111] logger.c: Extension Changed 2109[ext-local] new state Idle for Notify User 2107
[2011-09-02 10:18:50] VERBOSE[7111] logger.c: Extension Changed 2109[ext-local] new state Idle for Notify User 2108
[2011-09-02 10:18:50] VERBOSE[5538] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [2011-09-02 10:18:50] VERBOSE[5538] logger.c: Found
[2011-09-02 10:18:50] VERBOSE[5538] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [2011-09-02 10:18:50] VERBOSE[5538] logger.c: Found
[2011-09-02 10:18:50] VERBOSE[5538] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [2011-09-02 10:18:50] VERBOSE[5538] logger.c: Found
[2011-09-02 10:18:50] VERBOSE[5538] logger.c: == Manager ‘aastra-xml’ logged on from 127.0.0.1
[2011-09-02 10:18:50] VERBOSE[5538] logger.c: == Manager ‘aastra-xml’ logged off from 127.0.0.1
[2011-09-02 10:18:50] VERBOSE[5452] logger.c: – Executing [s@ivr-2:13] WaitExten(“DAHDI/2-1”, “|”) in new stack
[2011-09-02 10:18:50] VERBOSE[5539] logger.c: – Executing [*97@from-internal:1] Answer(“SIP/2107-00010263”, “”) in new stack
[2011-09-02 10:18:50] VERBOSE[5539] logger.c: – Executing [*97@from-internal:2] Wait(“SIP/2107-00010263”, “1”) in new stack
[2011-09-02 10:18:51] VERBOSE[5459] logger.c: – DAHDI/4-1 answered SIP/2105-00010260
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [*97@from-internal:3] Macro(“SIP/2107-00010263”, “user-callerid|”) in new stack
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:1] Set(“SIP/2107-00010263”, “AMPUSER=2107”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: Set
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/2107-00010263”, “0?report”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/2107-00010263”, “1|Set|REALCALLERIDNUM=2107”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:4] Set(“SIP/2107-00010263”, “AMPUSER=2107”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: Set
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:5] Set(“SIP/2107-00010263”, “AMPUSERCIDNAME=Mary Trejo”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: Set
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/2107-00010263”, “0?report”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:7] Set(“SIP/2107-00010263”, “AMPUSERCID=2107”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: Set
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:8] Set(“SIP/2107-00010263”, “CALLERID(all)=“Mary Trejo” <2107>”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: Set
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:9] ExecIf(“SIP/2107-00010263”, “0|Set|CHANNEL(language)=”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/2107-00010263”, “0?continue”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:11] Set(“SIP/2107-00010263”, “__TTL=64”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: Set
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/2107-00010263”, “1?continue”) in new stack
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Goto (macro-user-callerid,s,19)
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:19] Set(“SIP/2107-00010263”, “CALLERID(number)=2107”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: Set
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:20] Set(“SIP/2107-00010263”, “CALLERID(name)=Mary Trejo”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: Set
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-user-callerid:21] NoOp(“SIP/2107-00010263”, “Using CallerID “Mary Trejo” <2107>”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: Noop
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [*97@from-internal:4] Macro(“SIP/2107-00010263”, “get-vmcontext|2107”) in new stack
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-get-vmcontext:1] Set(“SIP/2107-00010263”, “VMCONTEXT=default”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: Set
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-get-vmcontext:2] GotoIf(“SIP/2107-00010263”, “0?200:300”) in new stack
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Goto (macro-get-vmcontext,s,300)
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [s@macro-get-vmcontext:300] NoOp(“SIP/2107-00010263”, “”) in new stack
[2011-09-02 10:18:51] DEBUG[5539] app_macro.c: Executed application: NoOp
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [*97@from-internal:5] MailboxExists(“SIP/2107-00010263”, “2107@default”) in new stack
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [*97@from-internal:6] GotoIf(“SIP/2107-00010263”, “1?mbexist”) in new stack
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Goto (from-internal,*97,106)
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [*97@from-internal:106] VoiceMailMain(“SIP/2107-00010263”, “2107@default”) in new stack
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – <SIP/2107-00010263> Playing ‘vm-password’ (language ‘en’)
[2011-09-02 10:18:52] VERBOSE[5522] logger.c: – <SIP/2111-00010261> Playing ‘vm-youhave’ (language ‘en’)
[2011-09-02 10:18:52] VERBOSE[5540] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [2011-09-02 10:18:52] VERBOSE[5540] logger.c: Found
[2011-09-02 10:18:52] VERBOSE[5540] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [2011-09-02 10:18:52] VERBOSE[5540] logger.c: Found
[2011-09-02 10:18:52] VERBOSE[5540] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [2011-09-02 10:18:52] VERBOSE[5540] logger.c: Found
[2011-09-02 10:18:52] VERBOSE[5540] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[2011-09-02 10:18:52] VERBOSE[5540] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[2011-09-02 10:18:53] VERBOSE[5542] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [2011-09-02 10:18:53] VERBOSE[5542] logger.c: Found
[2011-09-02 10:18:53] VERBOSE[5542] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [2011-09-02 10:18:53] VERBOSE[5542] logger.c: Found
[2011-09-02 10:18:53] VERBOSE[5542] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [2011-09-02 10:18:53] VERBOSE[5542] logger.c: Found
[2011-09-02 10:18:53] VERBOSE[5542] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[2011-09-02 10:18:53] VERBOSE[5522] logger.c: – <SIP/2111-00010261> Playing ‘digits/2’ (language ‘en’)
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: == CDR updated on DAHDI/2-1
[2011-09-02 10:18:53] WARNING[5452] func_db.c: DB_DELETE requires an argument, DB_DELETE(/)
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [4@ivr-2:1] NoOp(“DAHDI/2-1”, "Deleting: ") in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [4@ivr-2:2] Set(“DAHDI/2-1”, “__NODEST=”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [4@ivr-2:3] Goto(“DAHDI/2-1”, “from-did-direct|2110|1”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Goto (from-did-direct,2110,1)
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [2110@from-did-direct:1] Macro(“DAHDI/2-1”, “exten-vm|2110|2110”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-exten-vm:1] Macro(“DAHDI/2-1”, “user-callerid|”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-user-callerid:1] Set(“DAHDI/2-1”, “AMPUSER=9287822758”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Set
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“DAHDI/2-1”, “0?report”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“DAHDI/2-1”, “1|Set|REALCALLERIDNUM=9287822758”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:53] DEBUG[5452] func_db.c: DB: DEVICE/9287822758/user not found in database.
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-user-callerid:4] Set(“DAHDI/2-1”, “AMPUSER=”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Set
[2011-09-02 10:18:53] DEBUG[5452] func_db.c: DB: AMPUSER//cidname not found in database.
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-user-callerid:5] Set(“DAHDI/2-1”, “AMPUSERCIDNAME=”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Set
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“DAHDI/2-1”, “1?report”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Goto (macro-user-callerid,s,10)
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“DAHDI/2-1”, “0?continue”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-user-callerid:11] Set(“DAHDI/2-1”, “__TTL=64”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Set
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-user-callerid:12] GotoIf(“DAHDI/2-1”, “1?continue”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Goto (macro-user-callerid,s,19)
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-user-callerid:19] Set(“DAHDI/2-1”, “CALLERID(number)=9287822758”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Set
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-user-callerid:20] Set(“DAHDI/2-1”, “CALLERID(name)=YUMA PRIVATE IN”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Set
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-user-callerid:21] NoOp(“DAHDI/2-1”, “Using CallerID “YUMA PRIVATE IN” <9287822758>”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Noop
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Macro
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-exten-vm:2] Set(“DAHDI/2-1”, “RingGroupMethod=none”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Set
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-exten-vm:3] Set(“DAHDI/2-1”, “VMBOX=2110”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Set
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-exten-vm:4] Set(“DAHDI/2-1”, “__EXTTOCALL=2110”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Set
[2011-09-02 10:18:53] DEBUG[5452] func_db.c: DB: CFU/2110 not found in database.
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-exten-vm:5] Set(“DAHDI/2-1”, “CFUEXT=”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Set
[2011-09-02 10:18:53] DEBUG[5452] func_db.c: DB: CFB/2110 not found in database.
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-exten-vm:6] Set(“DAHDI/2-1”, “CFBEXT=”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Set
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-exten-vm:7] Set(“DAHDI/2-1”, “RT=20”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Set
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-exten-vm:8] Macro(“DAHDI/2-1”, “record-enable|2110|IN”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“DAHDI/2-1”, “1?check”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Goto (macro-record-enable,s,4)
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-record-enable:4] ExecIf(“DAHDI/2-1”, “0|MacroExit|”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-record-enable:5] GotoIf(“DAHDI/2-1”, “0?Group:OUT”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Goto (macro-record-enable,s,15)
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-record-enable:15] GotoIf(“DAHDI/2-1”, “1?IN”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Goto (macro-record-enable,s,20)
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-record-enable:20] ExecIf(“DAHDI/2-1”, “1|MacroExit|”) in new stack
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: Macro
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-exten-vm:9] Macro(“DAHDI/2-1”, “dial|20|tTrw|2110”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-dial:1] GotoIf(“DAHDI/2-1”, “1?dial”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Goto (macro-dial,s,3)
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-dial:3] AGI(“DAHDI/2-1”, “dialparties.agi”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: dialparties.agi: Starting New Dialparties.agi
[2011-09-02 10:18:53] VERBOSE[5545] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [2011-09-02 10:18:53] VERBOSE[5545] logger.c: Found
[2011-09-02 10:18:53] VERBOSE[5545] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [2011-09-02 10:18:53] VERBOSE[5545] logger.c: Found
[2011-09-02 10:18:53] VERBOSE[5545] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [2011-09-02 10:18:53] VERBOSE[5545] logger.c: Found
[2011-09-02 10:18:53] VERBOSE[5545] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: dialparties.agi: Caller ID name is ‘YUMA PRIVATE IN’ number is ‘9287822758’
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: dialparties.agi: Methodology of ring is ‘none’
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – dialparties.agi: Added extension 2110 to extension map
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – dialparties.agi: Extension 2110 cf is disabled
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – dialparties.agi: Extension 2110 do not disturb is disabled
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: dialparties.agi: ExtensionState: 0
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – dialparties.agi: dbset CALLTRACE/2110 to 9287822758
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – dialparties.agi: Filtered ARG3: 2110
[2011-09-02 10:18:53] VERBOSE[5545] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – AGI Script dialparties.agi completed, returning 0
[2011-09-02 10:18:53] DEBUG[5452] app_macro.c: Executed application: AGI
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [s@macro-dial:7] Dial(“DAHDI/2-1”, “SIP/2110|20|tTrw”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Called 2110
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 2109
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 2114
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 2115
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 2105
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 2117
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 2103
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 1507
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 2106
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 2102
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 2104
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 2112
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 2110
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 2107
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 2111
[2011-09-02 10:18:53] VERBOSE[7111] logger.c: Extension Changed 2110[ext-local] new state Ringing for Notify User 2108
[2011-09-02 10:18:53] VERBOSE[5542] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – SIP/2110-00010264 is ringing
[2011-09-02 10:18:53] VERBOSE[5522] logger.c: – <SIP/2111-00010261> Playing ‘vm-INBOX’ (language ‘en’)
[2011-09-02 10:18:54] VERBOSE[5522] logger.c: – <SIP/2111-00010261> Playing ‘vm-and’ (language ‘en’)
[2011-09-02 10:18:54] VERBOSE[5539] logger.c: – Incorrect password ‘000’ for user ‘2107’ (context = default)
[2011-09-02 10:18:54] VERBOSE[5539] logger.c: – <SIP/2107-00010263> Playing ‘vm-incorrect’ (language ‘en’)
[2011-09-02 10:18:55] VERBOSE[5522] logger.c: – <SIP/2111-00010261> Playing ‘digits/6’ (language ‘en’)
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: == CDR updated on DAHDI/5-1
[2011-09-02 10:18:55] WARNING[5471] func_db.c: DB_DELETE requires an argument, DB_DELETE(/)
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [1@ivr-6:1] NoOp(“DAHDI/5-1”, "Deleting: ") in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [1@ivr-6:2] Set(“DAHDI/5-1”, “__NODEST=”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [1@ivr-6:3] Goto(“DAHDI/5-1”, “ivr-14|s|1”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Goto (ivr-14,s,1)
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [s@ivr-14:1] Set(“DAHDI/5-1”, “MSG=custom/DOPersonnel”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [s@ivr-14:2] Set(“DAHDI/5-1”, “LOOPCOUNT=0”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [s@ivr-14:3] Set(“DAHDI/5-1”, “__DIR-CONTEXT=”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [s@ivr-14:4] Set(“DAHDI/5-1”, “_IVR_CONTEXT_ivr-14=ivr-6”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [s@ivr-14:5] Set(“DAHDI/5-1”, “_IVR_CONTEXT=ivr-14”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [s@ivr-14:6] GotoIf(“DAHDI/5-1”, “1?begin”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Goto (ivr-14,s,9)
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [s@ivr-14:9] Set(“DAHDI/5-1”, “TIMEOUT(digit)=3”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Digit timeout set to 3
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [s@ivr-14:10] Set(“DAHDI/5-1”, “TIMEOUT(response)=5”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Response timeout set to 5
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [s@ivr-14:11] Set(“DAHDI/5-1”, “__IVR_RETVM=”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [s@ivr-14:12] ExecIf(“DAHDI/5-1”, “1|Background|custom/DOPersonnel”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – <DAHDI/5-1> Playing ‘custom/DOPersonnel’ (language ‘en’)
[2011-09-02 10:18:55] VERBOSE[5522] logger.c: – <SIP/2111-00010261> Playing ‘vm-Old’ (language ‘en’)
[2011-09-02 10:18:56] VERBOSE[5522] logger.c: – <SIP/2111-00010261> Playing ‘vm-messages’ (language ‘en’)
[2011-09-02 10:18:56] VERBOSE[5539] logger.c: – <SIP/2107-00010263> Playing ‘vm-password’ (language ‘en’)
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [7606252302@from-internal:1] Macro(“SIP/4101-00010265”, “user-callerid|SKIPTTL|”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-user-callerid:1] Set(“SIP/4101-00010265”, “AMPUSER=4101”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/4101-00010265”, “0?report”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/4101-00010265”, “1|Set|REALCALLERIDNUM=4101”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-user-callerid:4] Set(“SIP/4101-00010265”, “AMPUSER=4101”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-user-callerid:5] Set(“SIP/4101-00010265”, “AMPUSERCIDNAME=Carole Fibrow”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/4101-00010265”, “0?report”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-user-callerid:7] Set(“SIP/4101-00010265”, “AMPUSERCID=4101”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-user-callerid:8] Set(“SIP/4101-00010265”, “CALLERID(all)=“Carole Fibrow” <4101>”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-user-callerid:9] ExecIf(“SIP/4101-00010265”, “0|Set|CHANNEL(language)=”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/4101-00010265”, “1?continue”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Goto (macro-user-callerid,s,19)
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-user-callerid:19] Set(“SIP/4101-00010265”, “CALLERID(number)=4101”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-user-callerid:20] Set(“SIP/4101-00010265”, “CALLERID(name)=Carole Fibrow”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-user-callerid:21] NoOp(“SIP/4101-00010265”, “Using CallerID “Carole Fibrow” <4101>”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Noop
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [7606252302@from-internal:2] NoOp(“SIP/4101-00010265”, “Calling Out Route: Out”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [7606252302@from-internal:3] Set(“SIP/4101-00010265”, “MOHCLASS=default”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [7606252302@from-internal:4] Set(“SIP/4101-00010265”, “_NODEST=”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [7606252302@from-internal:5] Macro(“SIP/4101-00010265”, “record-enable|4101|OUT|”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/4101-00010265”, “1?check”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Goto (macro-record-enable,s,4)
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-record-enable:4] ExecIf(“SIP/4101-00010265”, “0|MacroExit|”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-record-enable:5] GotoIf(“SIP/4101-00010265”, “0?Group:OUT”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Goto (macro-record-enable,s,15)
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-record-enable:15] GotoIf(“SIP/4101-00010265”, “0?IN”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-record-enable:16] ExecIf(“SIP/4101-00010265”, “1|MacroExit|”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [7606252302@from-internal:6] Macro(“SIP/4101-00010265”, “dialout-trunk|1|7606252302|”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/4101-00010265”, “DIAL_TRUNK=1”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] DEBUG[5546] func_db.c: DB: AMPUSER/4101/pinless not found in database.
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/4101-00010265”, “0?sub-pincheck|s|1”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: GosubIf
[2011-09-02 10:18:56] DEBUG[5546] func_db.c: DB: AMPUSER/4101/pinless not found in database.
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/4101-00010265”, “0?disabletrunk|1”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:4] Set(“SIP/4101-00010265”, “DIAL_NUMBER=7606252302”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/4101-00010265”, “DIAL_TRUNK_OPTIONS=tTrw”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/4101-00010265”, “OUTBOUND_GROUP=OUT_1”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/4101-00010265”, “0?nomax”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:8] GotoIf(“SIP/4101-00010265”, “0?chanfull”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/4101-00010265”, “0?skipoutcid”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:10] Set(“SIP/4101-00010265”, “DIAL_TRUNK_OPTIONS=TW”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/4101-00010265”, “outbound-callerid|1”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/4101-00010265”, “0|SetCallerPres|”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/4101-00010265”, “0|Set|REALCALLERIDNUM=4101”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-outbound-callerid:3] GotoIf(“SIP/4101-00010265”, “1?normcid”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Goto (macro-outbound-callerid,s,6)
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-outbound-callerid:6] Set(“SIP/4101-00010265”, “USEROUTCID=Margaret White <7609225159>”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] DEBUG[5546] func_db.c: DB: DEVICE/4101/emergency_cid not found in database.
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-outbound-callerid:7] Set(“SIP/4101-00010265”, “EMERGENCYCID=”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-outbound-callerid:8] Set(“SIP/4101-00010265”, “TRUNKOUTCID=”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-outbound-callerid:9] GotoIf(“SIP/4101-00010265”, “1?trunkcid”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Goto (macro-outbound-callerid,s,12)
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-outbound-callerid:12] ExecIf(“SIP/4101-00010265”, “0|Set|CALLERID(all)=”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-outbound-callerid:13] ExecIf(“SIP/4101-00010265”, “1|Set|CALLERID(all)=Margaret White <7609225159>”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Last app: Set|CALLERID(all)=Margaret White <7609225159>
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-outbound-callerid:14] ExecIf(“SIP/4101-00010265”, “0|Set|CALLERID(all)=”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/4101-00010265”, “0|SetCallerPres|prohib_passed_screen”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Macro
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:12] GosubIf(“SIP/4101-00010265”, “0?sub-flp-1|s|1”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: GosubIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/4101-00010265”, “OUTNUM=7606252302”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/4101-00010265”, “custom=DAHDI/g0”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Set
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/4101-00010265”, “0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^default)TW”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:16] Macro(“SIP/4101-00010265”, “dialout-trunk-predial-hook|”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/4101-00010265”, “”) in new stack
[2011-09-02 10:18:56] DEBUG[5546] app_macro.c: Executed application: Macro
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:17] GotoIf(“SIP/4101-00010265”, “0?bypass|1”) in new stack
[2011-09-02 10:18:57] DEBUG[5546] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:57] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/4101-00010265”, “0?customtrunk”) in new stack
[2011-09-02 10:18:57] VERBOSE[7111] logger.c: Extension Changed 4101[ext-local] new state InUse for Notify User 4105
[2011-09-02 10:18:57] DEBUG[5546] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:57] VERBOSE[5546] logger.c: – Executing [s@macro-dialout-trunk:19] Dial(“SIP/4101-00010265”, “DAHDI/g0/7606252302|300|TW”) in new stack
[2011-09-02 10:18:57] VERBOSE[7111] logger.c: Extension Changed 4101[ext-local] new state InUse for Notify User 4111
[2011-09-02 10:18:57] DEBUG[5546] dsp.c: dsp busy pattern set to 0,0
[2011-09-02 10:18:57] VERBOSE[5546] logger.c: – Requested transfer capability: 0x00 - SPEECH
[2011-09-02 10:18:57] VERBOSE[5546] logger.c: – Called g0/7606252302
[2011-09-02 10:18:57] VERBOSE[7111] logger.c: Extension Changed 4101[ext-local] new state InUse for Notify User 4102
[2011-09-02 10:18:57] VERBOSE[7111] logger.c: Extension Changed 4101[ext-local] new state InUse for Notify User 4117
[2011-09-02 10:18:57] VERBOSE[7111] logger.c: Extension Changed 4101[ext-local] new state InUse for Notify User 4112
[2011-09-02 10:18:57] VERBOSE[7111] logger.c: Extension Changed 4101[ext-local] new state InUse for Notify User 4113
[2011-09-02 10:18:57] VERBOSE[7111] logger.c: Extension Changed 4101[ext-local] new state InUse for Notify User 4101
[2011-09-02 10:18:57] VERBOSE[7111] logger.c: Extension Changed 4101[ext-local] new state InUse for Notify User 4115
[2011-09-02 10:18:57] DEBUG[7136] chan_dahdi.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/3 span 1
[2011-09-02 10:18:57] VERBOSE[5546] logger.c: – DAHDI/3-1 is proceeding passing it to SIP/4101-00010265
[2011-09-02 10:18:57] VERBOSE[5522] logger.c: – <SIP/2111-00010261> Playing ‘vm-onefor’ (language ‘en’)
[2011-09-02 10:18:57] VERBOSE[5522] logger.c: – <SIP/2111-00010261> Playing ‘vm-first’ (language ‘en’)
[2011-09-02 10:18:58] VERBOSE[5522] logger.c: – <SIP/2111-00010261> Playing ‘vm-message’ (language ‘en’)
[2011-09-02 10:18:59] VERBOSE[5546] logger.c: – DAHDI/3-1 is ringing
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [17602188330@from-internal:1] Macro(“SIP/3102-00010266”, “user-callerid|SKIPTTL|”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-user-callerid:1] Set(“SIP/3102-00010266”, “AMPUSER=3102”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/3102-00010266”, “0?report”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/3102-00010266”, “1|Set|REALCALLERIDNUM=3102”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-user-callerid:4] Set(“SIP/3102-00010266”, “AMPUSER=3102”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-user-callerid:5] Set(“SIP/3102-00010266”, “AMPUSERCIDNAME=Lisa Schlehuber”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/3102-00010266”, “0?report”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-user-callerid:7] Set(“SIP/3102-00010266”, “AMPUSERCID=3102”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-user-callerid:8] Set(“SIP/3102-00010266”, “CALLERID(all)=“Lisa Schlehuber” <3102>”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-user-callerid:9] ExecIf(“SIP/3102-00010266”, “0|Set|CHANNEL(language)=”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/3102-00010266”, “1?continue”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Goto (macro-user-callerid,s,19)
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-user-callerid:19] Set(“SIP/3102-00010266”, “CALLERID(number)=3102”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-user-callerid:20] Set(“SIP/3102-00010266”, “CALLERID(name)=Lisa Schlehuber”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-user-callerid:21] NoOp(“SIP/3102-00010266”, “Using CallerID “Lisa Schlehuber” <3102>”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Noop
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [17602188330@from-internal:2] NoOp(“SIP/3102-00010266”, “Calling Out Route: Out”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [17602188330@from-internal:3] Set(“SIP/3102-00010266”, “MOHCLASS=default”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [17602188330@from-internal:4] Set(“SIP/3102-00010266”, “_NODEST=”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [17602188330@from-internal:5] Macro(“SIP/3102-00010266”, “record-enable|3102|OUT|”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/3102-00010266”, “1?check”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Goto (macro-record-enable,s,4)
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-record-enable:4] ExecIf(“SIP/3102-00010266”, “0|MacroExit|”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-record-enable:5] GotoIf(“SIP/3102-00010266”, “0?Group:OUT”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Goto (macro-record-enable,s,15)
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-record-enable:15] GotoIf(“SIP/3102-00010266”, “0?IN”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-record-enable:16] ExecIf(“SIP/3102-00010266”, “1|MacroExit|”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [17602188330@from-internal:6] Macro(“SIP/3102-00010266”, “dialout-trunk|1|17602188330|”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/3102-00010266”, “DIAL_TRUNK=1”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] DEBUG[5547] func_db.c: DB: AMPUSER/3102/pinless not found in database.
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/3102-00010266”, “0?sub-pincheck|s|1”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GosubIf
[2011-09-02 10:18:59] DEBUG[5547] func_db.c: DB: AMPUSER/3102/pinless not found in database.
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/3102-00010266”, “0?disabletrunk|1”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:4] Set(“SIP/3102-00010266”, “DIAL_NUMBER=17602188330”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/3102-00010266”, “DIAL_TRUNK_OPTIONS=tTrw”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/3102-00010266”, “OUTBOUND_GROUP=OUT_1”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/3102-00010266”, “0?nomax”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:8] GotoIf(“SIP/3102-00010266”, “0?chanfull”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/3102-00010266”, “0?skipoutcid”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:10] Set(“SIP/3102-00010266”, “DIAL_TRUNK_OPTIONS=TW”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/3102-00010266”, “outbound-callerid|1”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/3102-00010266”, “0|SetCallerPres|”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/3102-00010266”, “0|Set|REALCALLERIDNUM=3102”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-outbound-callerid:3] GotoIf(“SIP/3102-00010266”, “1?normcid”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Goto (macro-outbound-callerid,s,6)
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-outbound-callerid:6] Set(“SIP/3102-00010266”, “USEROUTCID=Blythe Middle School <7609221300>”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] DEBUG[5547] func_db.c: DB: DEVICE/3102/emergency_cid not found in database.
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-outbound-callerid:7] Set(“SIP/3102-00010266”, “EMERGENCYCID=”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-outbound-callerid:8] Set(“SIP/3102-00010266”, “TRUNKOUTCID=”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-outbound-callerid:9] GotoIf(“SIP/3102-00010266”, “1?trunkcid”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Goto (macro-outbound-callerid,s,12)
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-outbound-callerid:12] ExecIf(“SIP/3102-00010266”, “0|Set|CALLERID(all)=”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-outbound-callerid:13] ExecIf(“SIP/3102-00010266”, “1|Set|CALLERID(all)=Blythe Middle School <7609221300>”) in new stack
[2011-09-02 10:18:59] VERBOSE[7111] logger.c: Extension Changed 3102[ext-local] new state InUse for Notify User 3103
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Last app: Set|CALLERID(all)=Blythe Middle School <7609221300>
[2011-09-02 10:18:59] VERBOSE[7111] logger.c: Extension Changed 3102[ext-local] new state InUse for Notify User 3101
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-outbound-callerid:14] ExecIf(“SIP/3102-00010266”, “0|Set|CALLERID(all)=”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/3102-00010266”, “0|SetCallerPres|prohib_passed_screen”) in new stack
[2011-09-02 10:18:59] VERBOSE[7111] logger.c: Extension Changed 3102[ext-local] new state InUse for Notify User 3102
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Macro
[2011-09-02 10:18:59] VERBOSE[7111] logger.c: Extension Changed 3102[ext-local] new state InUse for Notify User 3106
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:12] GosubIf(“SIP/3102-00010266”, “0?sub-flp-1|s|1”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GosubIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/3102-00010266”, “OUTNUM=17602188330”) in new stack
[2011-09-02 10:18:59] VERBOSE[7111] logger.c: Extension Changed 3102[ext-local] new state InUse for Notify User 3115
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/3102-00010266”, “custom=DAHDI/g0”) in new stack
[2011-09-02 10:18:59] VERBOSE[7111] logger.c: Extension Changed 3102[ext-local] new state InUse for Notify User 3105
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Set
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/3102-00010266”, “0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^default)TW”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: ExecIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:16] Macro(“SIP/3102-00010266”, “dialout-trunk-predial-hook|”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/3102-00010266”, “”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: Macro
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:17] GotoIf(“SIP/3102-00010266”, “0?bypass|1”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/3102-00010266”, “0?customtrunk”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] app_macro.c: Executed application: GotoIf
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [s@macro-dialout-trunk:19] Dial(“SIP/3102-00010266”, “DAHDI/g0/17602188330|300|TW”) in new stack
[2011-09-02 10:18:59] DEBUG[5547] dsp.c: dsp busy pattern set to 0,0
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Requested transfer capability: 0x00 - SPEECH
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Called g0/17602188330
[2011-09-02 10:18:59] VERBOSE[5522] logger.c: == Parsing ‘/var/spool/asterisk/voicemail/default/2111/INBOX/msg0000.txt’: [2011-09-02 10:18:59] VERBOSE[5522] logger.c: Found
[2011-09-02 10:18:59] VERBOSE[5522] logger.c: – <SIP/2111-00010261> Playing ‘/var/spool/asterisk/voicemail/default/2111/INBOX/msg0000’ (language ‘en’)
[2011-09-02 10:18:59] DEBUG[7136] chan_dahdi.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/6 span 1
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – DAHDI/6-1 is proceeding passing it to SIP/3102-00010266
[2011-09-02 10:18:59] VERBOSE[5554] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [2011-09-02 10:18:59] VERBOSE[5554] logger.c: Found
[2011-09-02 10:18:59] VERBOSE[5554] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [2011-09-02 10:18:59] VERBOSE[5554] logger.c: Found
[2011-09-02 10:18:59] VERBOSE[5554] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [2011-09-02 10:18:59] VERBOSE[5554] logger.c: Found
[2011-09-02 10:18:59] VERBOSE[5554] logger.c: == Manager ‘aastra-xml’ logged on from 127.0.0.1
[2011-09-02 10:18:59] VERBOSE[5554] logger.c: == Manager ‘aastra-xml’ logged off from 127.0.0.1
[2011-09-02 10:18:59] VERBOSE[5539] logger.c: – <SIP/2107-00010263> Playing ‘vm-youhave’ (language ‘en’)
[2011-09-02 10:19:00] VERBOSE[5539] logger.c: – <SIP/2107-00010263> Playing ‘digits/4’ (language ‘en’)
[2011-09-02 10:19:01] VERBOSE[5539] logger.c: – <SIP/2107-00010263> Playing ‘vm-INBOX’ (language ‘en’)
[2011-09-02 10:19:01] VERBOSE[5547] logger.c: – DAHDI/6-1 is ringing
[2011-09-02 10:19:02] VERBOSE[5539] logger.c: – <SIP/2107-00010263> Playing ‘vm-first’ (language ‘en’)
[2011-09-02 10:19:02] VERBOSE[5539] logger.c: – <SIP/2107-00010263> Playing ‘vm-message’ (language ‘en’)
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: == CDR updated on DAHDI/5-1
[2011-09-02 10:19:03] WARNING[5471] func_db.c: DB_DELETE requires an argument, DB_DELETE(/)
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [2@ivr-14:1] NoOp(“DAHDI/5-1”, "Deleting: ") in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [2@ivr-14:2] Set(“DAHDI/5-1”, “__NODEST=”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [2@ivr-14:3] Goto(“DAHDI/5-1”, “from-did-direct|1232|1”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Goto (from-did-direct,1232,1)
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [1232@from-did-direct:1] Macro(“DAHDI/5-1”, “exten-vm|1232|1232”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-exten-vm:1] Macro(“DAHDI/5-1”, “user-callerid|”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-user-callerid:1] Set(“DAHDI/5-1”, “AMPUSER=8175425050”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“DAHDI/5-1”, “0?report”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“DAHDI/5-1”, “1|Set|REALCALLERIDNUM=8175425050”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: ExecIf
[2011-09-02 10:19:03] DEBUG[5471] func_db.c: DB: DEVICE/8175425050/user not found in database.
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-user-callerid:4] Set(“DAHDI/5-1”, “AMPUSER=”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] DEBUG[5471] func_db.c: DB: AMPUSER//cidname not found in database.
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-user-callerid:5] Set(“DAHDI/5-1”, “AMPUSERCIDNAME=”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“DAHDI/5-1”, “1?report”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Goto (macro-user-callerid,s,10)
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“DAHDI/5-1”, “0?continue”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-user-callerid:11] Set(“DAHDI/5-1”, “__TTL=64”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-user-callerid:12] GotoIf(“DAHDI/5-1”, “1?continue”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Goto (macro-user-callerid,s,19)
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-user-callerid:19] Set(“DAHDI/5-1”, “CALLERID(number)=8175425050”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-user-callerid:20] Set(“DAHDI/5-1”, “CALLERID(name)=TEXAS”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-user-callerid:21] NoOp(“DAHDI/5-1”, “Using CallerID “TEXAS” <8175425050>”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Noop
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Macro
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-exten-vm:2] Set(“DAHDI/5-1”, “RingGroupMethod=none”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-exten-vm:3] Set(“DAHDI/5-1”, “VMBOX=1232”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-exten-vm:4] Set(“DAHDI/5-1”, “__EXTTOCALL=1232”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] DEBUG[5471] func_db.c: DB: CFU/1232 not found in database.
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-exten-vm:5] Set(“DAHDI/5-1”, “CFUEXT=”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] DEBUG[5471] func_db.c: DB: CFB/1232 not found in database.
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-exten-vm:6] Set(“DAHDI/5-1”, “CFBEXT=”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-exten-vm:7] Set(“DAHDI/5-1”, “RT=20”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-exten-vm:8] Macro(“DAHDI/5-1”, “record-enable|1232|IN”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“DAHDI/5-1”, “1?check”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Goto (macro-record-enable,s,4)
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-record-enable:4] ExecIf(“DAHDI/5-1”, “0|MacroExit|”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: ExecIf
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-record-enable:5] GotoIf(“DAHDI/5-1”, “0?Group:OUT”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Goto (macro-record-enable,s,15)
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-record-enable:15] GotoIf(“DAHDI/5-1”, “1?IN”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Goto (macro-record-enable,s,20)
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-record-enable:20] ExecIf(“DAHDI/5-1”, “1|MacroExit|”) in new stack
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: Macro
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-exten-vm:9] Macro(“DAHDI/5-1”, “dial|20|tTrw|1232”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-dial:1] GotoIf(“DAHDI/5-1”, “1?dial”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Goto (macro-dial,s,3)
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-dial:3] AGI(“DAHDI/5-1”, “dialparties.agi”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: dialparties.agi: Starting New Dialparties.agi
[2011-09-02 10:19:03] VERBOSE[5556] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [2011-09-02 10:19:03] VERBOSE[5556] logger.c: Found
[2011-09-02 10:19:03] VERBOSE[5556] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [2011-09-02 10:19:03] VERBOSE[5556] logger.c: Found
[2011-09-02 10:19:03] VERBOSE[5556] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [2011-09-02 10:19:03] VERBOSE[5556] logger.c: Found
[2011-09-02 10:19:03] VERBOSE[5556] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: dialparties.agi: Caller ID name is ‘TEXAS’ number is ‘8175425050’
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: dialparties.agi: Methodology of ring is ‘none’
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – dialparties.agi: Added extension 1232 to extension map
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – dialparties.agi: Extension 1232 cf is disabled
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – dialparties.agi: Extension 1232 do not disturb is disabled
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: dialparties.agi: ExtensionState: 0
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – dialparties.agi: dbset CALLTRACE/1232 to 8175425050
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – dialparties.agi: Filtered ARG3: 1232
[2011-09-02 10:19:03] VERBOSE[5556] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – AGI Script dialparties.agi completed, returning 0
[2011-09-02 10:19:03] DEBUG[5471] app_macro.c: Executed application: AGI
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [s@macro-dial:7] Dial(“DAHDI/5-1”, “SIP/1232|20|tTrw”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Called 1232
[2011-09-02 10:19:03] VERBOSE[7111] logger.c: Extension Changed 1232[ext-local] new state Ringing for Notify User 1221
[2011-09-02 10:19:03] VERBOSE[7111] logger.c: Extension Changed 1232[ext-local] new state Ringing for Notify User 1247
[2011-09-02 10:19:03] VERBOSE[7111] logger.c: Extension Changed 1232[ext-local] new state Ringing for Notify User 1233
[2011-09-02 10:19:03] VERBOSE[7111] logger.c: Extension Changed 1232[ext-local] new state Ringing for Notify User 1224
[2011-09-02 10:19:03] VERBOSE[7111] logger.c: – Got SIP response 302 “Moved Temporarily” back from 10.64.1.168
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Now forwarding DAHDI/5-1 to ‘Local/1221@from-internal’ (thanks to SIP/1232-00010267)
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [1221@from-internal:1] Macro(“Local/1221@from-internal-5c47,2”, “exten-vm|1221|1221”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-exten-vm:1] Macro(“Local/1221@from-internal-5c47,2”, “user-callerid|”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-user-callerid:1] Set(“Local/1221@from-internal-5c47,2”, “AMPUSER=8175425050”) in new stack
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“Local/1221@from-internal-5c47,2”, “1?report”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Goto (macro-user-callerid,s,10)
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-user-callerid:10] GotoIf(“Local/1221@from-internal-5c47,2”, “0?continue”) in new stack
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-user-callerid:11] Set(“Local/1221@from-internal-5c47,2”, “__TTL=63”) in new stack
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-user-callerid:12] GotoIf(“Local/1221@from-internal-5c47,2”, “1?continue”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Goto (macro-user-callerid,s,19)
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-user-callerid:19] Set(“Local/1221@from-internal-5c47,2”, “CALLERID(number)=8175425050”) in new stack
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-user-callerid:20] Set(“Local/1221@from-internal-5c47,2”, “CALLERID(name)=TEXAS”) in new stack
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-user-callerid:21] NoOp(“Local/1221@from-internal-5c47,2”, “Using CallerID “TEXAS” <8175425050>”) in new stack
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: Noop
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: Macro
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-exten-vm:2] Set(“Local/1221@from-internal-5c47,2”, “RingGroupMethod=none”) in new stack
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-exten-vm:3] Set(“Local/1221@from-internal-5c47,2”, “VMBOX=1221”) in new stack
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-exten-vm:4] Set(“Local/1221@from-internal-5c47,2”, “__EXTTOCALL=1221”) in new stack
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] DEBUG[5557] func_db.c: DB: CFU/1221 not found in database.
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-exten-vm:5] Set(“Local/1221@from-internal-5c47,2”, “CFUEXT=”) in new stack
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] DEBUG[5557] func_db.c: DB: CFB/1221 not found in database.
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-exten-vm:6] Set(“Local/1221@from-internal-5c47,2”, “CFBEXT=”) in new stack
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-exten-vm:7] Set(“Local/1221@from-internal-5c47,2”, “RT=20”) in new stack
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: Set
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-exten-vm:8] Macro(“Local/1221@from-internal-5c47,2”, “record-enable|1221|IN”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“Local/1221@from-internal-5c47,2”, “1?check”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Goto (macro-record-enable,s,4)
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-record-enable:4] ExecIf(“Local/1221@from-internal-5c47,2”, “0|MacroExit|”) in new stack
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: ExecIf
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-record-enable:5] GotoIf(“Local/1221@from-internal-5c47,2”, “0?Group:OUT”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Goto (macro-record-enable,s,15)
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-record-enable:15] GotoIf(“Local/1221@from-internal-5c47,2”, “1?IN”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Goto (macro-record-enable,s,20)
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-record-enable:20] ExecIf(“Local/1221@from-internal-5c47,2”, “1|MacroExit|”) in new stack
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: Macro
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-exten-vm:9] Macro(“Local/1221@from-internal-5c47,2”, “dial|20|tTrw|1221”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-dial:1] GotoIf(“Local/1221@from-internal-5c47,2”, “1?dial”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Goto (macro-dial,s,3)
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-dial:3] AGI(“Local/1221@from-internal-5c47,2”, “dialparties.agi”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2011-09-02 10:19:03] VERBOSE[7111] logger.c: Extension Changed 1232[ext-local] new state Idle for Notify User 1221
[2011-09-02 10:19:03] VERBOSE[7111] logger.c: Extension Changed 1232[ext-local] new state Idle for Notify User 1247
[2011-09-02 10:19:03] VERBOSE[7111] logger.c: Extension Changed 1232[ext-local] new state Idle for Notify User 1233
[2011-09-02 10:19:03] VERBOSE[7111] logger.c: Extension Changed 1232[ext-local] new state Idle for Notify User 1224
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: dialparties.agi: Starting New Dialparties.agi
[2011-09-02 10:19:03] VERBOSE[5559] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [2011-09-02 10:19:03] VERBOSE[5559] logger.c: Found
[2011-09-02 10:19:03] VERBOSE[5559] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [2011-09-02 10:19:03] VERBOSE[5559] logger.c: Found
[2011-09-02 10:19:03] VERBOSE[5559] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [2011-09-02 10:19:03] VERBOSE[5559] logger.c: Found
[2011-09-02 10:19:03] VERBOSE[5559] logger.c: == Manager ‘admin’ logged on from 127.0.0.1
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: dialparties.agi: Caller ID name is ‘TEXAS’ number is ‘8175425050’
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: dialparties.agi: Methodology of ring is ‘none’
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – dialparties.agi: Added extension 1221 to extension map
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – dialparties.agi: Extension 1221 cf is disabled
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – dialparties.agi: Extension 1221 do not disturb is disabled
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: dialparties.agi: ExtensionState: 0
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – dialparties.agi: dbset CALLTRACE/1221 to 8175425050
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – dialparties.agi: Filtered ARG3: 1221
[2011-09-02 10:19:03] VERBOSE[5559] logger.c: == Manager ‘admin’ logged off from 127.0.0.1
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – AGI Script dialparties.agi completed, returning 0
[2011-09-02 10:19:03] DEBUG[5557] app_macro.c: Executed application: AGI
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [s@macro-dial:7] Dial(“Local/1221@from-internal-5c47,2”, “SIP/1221|20|tTrw”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Called 1221
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Local/1221@from-internal-5c47,1 is ringing
[2011-09-02 10:19:03] VERBOSE[7111] logger.c: Extension Changed 1221[ext-local] new state Ringing for Notify User 1247
[2011-09-02 10:19:03] VERBOSE[7111] logger.c: Extension Changed 1221[ext-local] new state Ringing for Notify User 1233
[2011-09-02 10:19:03] VERBOSE[7111] logger.c: Extension Changed 1221[ext-local] new state Ringing for Notify User 1232
[2011-09-02 10:19:03] VERBOSE[5539] logger.c: == Parsing ‘/var/spool/asterisk/voicemail/default/2107/INBOX/msg0000.txt’: [2011-09-02 10:19:03] VERBOSE[5539] logger.c: Found
[2011-09-02 10:19:03] VERBOSE[5539] logger.c: – <SIP/2107-00010263> Playing ‘/var/spool/asterisk/voicemail/default/2107/INBOX/msg0000’ (language ‘en’)
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – SIP/1221-00010268 is ringing
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – SIP/1221-00010268 is ringing
[2011-09-02 10:19:04] DEBUG[5523] chan_dahdi.c: Set option AUDIO MODE, value: ON(1) on DAHDI/1-1
[2011-09-02 10:19:04] DEBUG[5523] chan_dahdi.c: Not yet hungup… Calling hangup once with icause, and clearing call
[2011-09-02 10:19:04] DEBUG[5523] chan_dahdi.c: Set option AUDIO MODE, value: OFF(0) on DAHDI/1-1
[2011-09-02 10:19:04] VERBOSE[5523] logger.c: – Hungup ‘DAHDI/1-1’
[2011-09-02 10:19:04] VERBOSE[5523] logger.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on ‘SIP/1602-00010262’ in macro ‘dialout-trunk’
[2011-09-02 10:19:04] VERBOSE[5523] logger.c: == Spawn extension (from-internal, 911, 6) exited non-zero on ‘SIP/1602-00010262’
[2011-09-02 10:19:04] VERBOSE[5523] logger.c: – Executing [h@macro-dialout-trunk:1] Macro(“SIP/1602-00010262”, “hangupcall|”) in new stack
[2011-09-02 10:19:04] VERBOSE[5523] logger.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/1602-00010262”, “1?skiprg”) in new stack
[2011-09-02 10:19:04] VERBOSE[5523] logger.c: – Goto (macro-hangupcall,s,4)
[2011-09-02 10:19:04] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:04] VERBOSE[5523] logger.c: – Executing [s@macro-hangupcall:4] GotoIf(“SIP/1602-00010262”, “1?skipblkvm”) in new stack
[2011-09-02 10:19:04] VERBOSE[5523] logger.c: – Goto (macro-hangupcall,s,7)
[2011-09-02 10:19:04] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:04] VERBOSE[5523] logger.c: – Executing [s@macro-hangupcall:7] GotoIf(“SIP/1602-00010262”, “1?theend”) in new stack
[2011-09-02 10:19:04] VERBOSE[5523] logger.c: – Goto (macro-hangupcall,s,9)
[2011-09-02 10:19:04] DEBUG[5523] app_macro.c: Executed application: GotoIf
[2011-09-02 10:19:04] VERBOSE[5523] logger.c: – Executing [s@macro-hangupcall:9] Hangup(“SIP/1602-00010262”, “”) in new stack
[2011-09-02 10:19:04] VERBOSE[5523] logger.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/1602-00010262’ in macro ‘hangupcall’
[2011-09-02 10:19:04] VERBOSE[5523] logger.c: == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on ‘SIP/1602-00010262’
[2011-09-02 10:19:04] VERBOSE[7111] logger.c: Extension Changed 1602[ext-local] new state Idle for Notify User 1604
[2011-09-02 10:19:04] VERBOSE[7111] logger.c: Extension Changed 1602[ext-local] new state Idle for Notify User 1603
[2011-09-02 10:19:04] VERBOSE[7111] logger.c: Extension Changed 1602[ext-local] new state Idle for Notify User 1602
[2011-09-02 10:19:04] VERBOSE[7111] logger.c: Extension Changed 1602[ext-local] new state Idle for Notify User 1601

I suspect that this is an issue with your PRI provider and not with FreePBX or Asterisk. You can rule that out for sure by making 911 calls part of your standard outbound route instead of part of an emergency route. You might also try another provider, including a VOIP provider (Callcentric, VOIP.ms, Vitelity, Broadvoice, Flowroute, etc).