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 [[email protected]:1] Macro(“SIP/1602-00010262”, “user-callerid|SKIPTTL|”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:2] NoOp(“SIP/1602-00010262”, “Calling Out Route: Out”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [[email protected]:3] Set(“SIP/1602-00010262”, “MOHCLASS=default”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [[email protected]: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 [[email protected]:5] Macro(“SIP/1602-00010262”, “record-enable|1602|OUT|”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:16] ExecIf(“SIP/1602-00010262”, “1|MacroExit|”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [[email protected]:6] Macro(“SIP/1602-00010262”, “dialout-trunk|1|911|”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:11] Macro(“SIP/1602-00010262”, “outbound-callerid|1”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:16] Macro(“SIP/1602-00010262”, “dialout-trunk-predial-hook|”) in new stack
[2011-09-02 10:18:47] VERBOSE[5523] logger.c: – Executing [[email protected]k: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [*[email protected]:3] Macro(“SIP/2111-00010261”, “user-callerid|”) in new stack
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [*[email protected]:4] Macro(“SIP/2111-00010261”, “get-vmcontext|2111”) in new stack
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [*[email protected]:5] MailboxExists(“SIP/2111-00010261”, “[email protected]”) in new stack
[2011-09-02 10:18:48] VERBOSE[5522] logger.c: – Executing [*[email protected]: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 [*[email protected]:106] VoiceMailMain(“SIP/2111-00010261”, “[email protected]”) 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 [[email protected]:1] Macro(“SIP/2109-0001025e”, “hangupcall”) in new stack
[2011-09-02 10:18:50] VERBOSE[5455] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:13] WaitExten(“DAHDI/2-1”, “|”) in new stack
[2011-09-02 10:18:50] VERBOSE[5539] logger.c: – Executing [*[email protected]:1] Answer(“SIP/2107-00010263”, “”) in new stack
[2011-09-02 10:18:50] VERBOSE[5539] logger.c: – Executing [*[email protected]: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 [*[email protected]:3] Macro(“SIP/2107-00010263”, “user-callerid|”) in new stack
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [*[email protected]:4] Macro(“SIP/2107-00010263”, “get-vmcontext|2107”) in new stack
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [*[email protected]:5] MailboxExists(“SIP/2107-00010263”, “[email protected]”) in new stack
[2011-09-02 10:18:51] VERBOSE[5539] logger.c: – Executing [*[email protected]: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 [*[email protected]:106] VoiceMailMain(“SIP/2107-00010263”, “[email protected]”) 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 [[email protected]:1] NoOp(“DAHDI/2-1”, "Deleting: ") in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [[email protected]:2] Set(“DAHDI/2-1”, “__NODEST=”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [[email protected]: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 [[email protected]:1] Macro(“DAHDI/2-1”, “exten-vm|2110|2110”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [[email protected]:1] Macro(“DAHDI/2-1”, “user-callerid|”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:8] Macro(“DAHDI/2-1”, “record-enable|2110|IN”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:9] Macro(“DAHDI/2-1”, “dial|20|tTrw|2110”) in new stack
[2011-09-02 10:18:53] VERBOSE[5452] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:1] NoOp(“DAHDI/5-1”, "Deleting: ") in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [[email protected]:2] Set(“DAHDI/5-1”, “__NODEST=”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [[email protected]: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 [[email protected]:1] Set(“DAHDI/5-1”, “MSG=custom/DOPersonnel”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [[email protected]:2] Set(“DAHDI/5-1”, “LOOPCOUNT=0”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [[email protected]:3] Set(“DAHDI/5-1”, “__DIR-CONTEXT=”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [[email protected]: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 [[email protected]:5] Set(“DAHDI/5-1”, “_IVR_CONTEXT=ivr-14”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:11] Set(“DAHDI/5-1”, “__IVR_RETVM=”) in new stack
[2011-09-02 10:18:55] VERBOSE[5471] logger.c: – Executing [[email protected]: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 [[email protected]:1] Macro(“SIP/4101-00010265”, “user-callerid|SKIPTTL|”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:2] NoOp(“SIP/4101-00010265”, “Calling Out Route: Out”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [[email protected]:3] Set(“SIP/4101-00010265”, “MOHCLASS=default”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [[email protected]:4] Set(“SIP/4101-00010265”, “_NODEST=”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [[email protected]:5] Macro(“SIP/4101-00010265”, “record-enable|4101|OUT|”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:16] ExecIf(“SIP/4101-00010265”, “1|MacroExit|”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [[email protected]:6] Macro(“SIP/4101-00010265”, “dialout-trunk|1|7606252302|”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:11] Macro(“SIP/4101-00010265”, “outbound-callerid|1”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:16] Macro(“SIP/4101-00010265”, “dialout-trunk-predial-hook|”) in new stack
[2011-09-02 10:18:56] VERBOSE[5546] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:1] Macro(“SIP/3102-00010266”, “user-callerid|SKIPTTL|”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:2] NoOp(“SIP/3102-00010266”, “Calling Out Route: Out”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [[email protected]:3] Set(“SIP/3102-00010266”, “MOHCLASS=default”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [[email protected]:4] Set(“SIP/3102-00010266”, “_NODEST=”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [[email protected]:5] Macro(“SIP/3102-00010266”, “record-enable|3102|OUT|”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:16] ExecIf(“SIP/3102-00010266”, “1|MacroExit|”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [[email protected]:6] Macro(“SIP/3102-00010266”, “dialout-trunk|1|17602188330|”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:11] Macro(“SIP/3102-00010266”, “outbound-callerid|1”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:16] Macro(“SIP/3102-00010266”, “dialout-trunk-predial-hook|”) in new stack
[2011-09-02 10:18:59] VERBOSE[5547] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:1] NoOp(“DAHDI/5-1”, "Deleting: ") in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [[email protected]:2] Set(“DAHDI/5-1”, “__NODEST=”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [[email protected]: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 [[email protected]:1] Macro(“DAHDI/5-1”, “exten-vm|1232|1232”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [[email protected]:1] Macro(“DAHDI/5-1”, “user-callerid|”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:8] Macro(“DAHDI/5-1”, “record-enable|1232|IN”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]:9] Macro(“DAHDI/5-1”, “dial|20|tTrw|1232”) in new stack
[2011-09-02 10:19:03] VERBOSE[5471] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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/[email protected]’ (thanks to SIP/1232-00010267)
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [[email protected]:1] Macro(“Local/[email protected],2”, “exten-vm|1221|1221”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [[email protected]:1] Macro(“Local/[email protected],2”, “user-callerid|”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [[email protected]:1] Set(“Local/[email protected],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 [[email protected]:2] GotoIf(“Local/[email protected],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 [[email protected]:10] GotoIf(“Local/[email protected],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 [[email protected]:11] Set(“Local/[email protected],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 [[email protected]:12] GotoIf(“Local/[email protected],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 [[email protected]:19] Set(“Local/[email protected],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 [[email protected]:20] Set(“Local/[email protected],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 [[email protected]:21] NoOp(“Local/[email protected],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 [[email protected]:2] Set(“Local/[email protected],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 [[email protected]:3] Set(“Local/[email protected],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 [[email protected]:4] Set(“Local/[email protected],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 [[email protected]:5] Set(“Local/[email protected],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 [[email protected]:6] Set(“Local/[email protected],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 [[email protected]:7] Set(“Local/[email protected],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 [[email protected]:8] Macro(“Local/[email protected],2”, “record-enable|1221|IN”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [[email protected]:1] GotoIf(“Local/[email protected],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 [[email protected]:4] ExecIf(“Local/[email protected],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 [[email protected]:5] GotoIf(“Local/[email protected],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 [[email protected]:15] GotoIf(“Local/[email protected],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 [[email protected]:20] ExecIf(“Local/[email protected],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 [[email protected]:9] Macro(“Local/[email protected],2”, “dial|20|tTrw|1221”) in new stack
[2011-09-02 10:19:03] VERBOSE[5557] logger.c: – Executing [[email protected]:1] GotoIf(“Local/[email protected],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 [[email protected]:3] AGI(“Local/[email protected],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 [[email protected]:7] Dial(“Local/[email protected],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/[email protected],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 [[email protected]:1] Macro(“SIP/1602-00010262”, “hangupcall|”) in new stack
[2011-09-02 10:19:04] VERBOSE[5523] logger.c: – Executing [[email protected]: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 [[email protected]: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 [[email protected]: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 [[email protected]: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).