Forwarding to extarnal, dial tone and disconnect

PBX Firmware : 1.88.210.57-1
PBX Service Pack: 1.0.0.0

When I call from the outside world directly to an extension which is forwarded to an external phone I keep hearing the dial tone, while the external phone is picked up and can hear me already. A few seconds after pick up, it disconnects and in the CDR appearing two rows with ‘no answer’

When I call from an internal phone to the extension with active forward everything works fine.

Please provide a call trace of a working call
Please provide a call trace of an abnormal call.

Thanks,

How do I trace a call? This is what I see in the full log (var/log/asterisk)

Working call, from internal device to another internal device with forwarding to external number:

[2014-05-28 07:17:25] NOTICE[3445] chan_sip.c: Sending fake auth rejection for device 1<sip:[email protected]>;tag=5692afe8
[2014-05-28 07:17:25] NOTICE[3445] chan_sip.c: Sending fake auth rejection for device 1<sip:[email protected]>;tag=5692afe8

Abnormal call, form external device to internal (IVR, direct dial extension):

[2014-05-28 07:16:56] NOTICE[3445] chan_sip.c: – Re-registration for [email protected]
[2014-05-28 07:16:56] NOTICE[3445] chan_sip.c: – Re-registration for [email protected]
[2014-05-28 07:16:56] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s)
[2014-05-28 07:16:56] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s)
[2014-05-28 07:17:25] NOTICE[3445] chan_sip.c: Sending fake auth rejection for device 1<sip:[email protected]>;tag=5692afe8
[2014-05-28 07:17:25] NOTICE[3445] chan_sip.c: Sending fake auth rejection for device 1<sip:[email protected]>;tag=5692afe8
[2014-05-28 07:17:30] WARNING[31744] mp3/interface.c: Junk at the beginning of frame 49443303
[2014-05-28 07:17:30] WARNING[31744] mp3/interface.c: Junk at the beginning of frame 49443303
[2014-05-28 07:17:32] NOTICE[31744] app_dial.c: Not accepting call completion offers from call-forward recipient Local/[email protected];1
[2014-05-28 07:17:32] NOTICE[31744] app_dial.c: Not accepting call completion offers from call-forward recipient Local/[email protected];1

Anyone?

Ok, I increased the verbose level to 6. Hopefully this makes it more clear.

[2014-05-28 08:25:59] VERBOSE[6433] pbx.c: -- Executing [[email protected]:11] ExecIf("SIP/Trunk-Out_999999-000001db", "1?Background(custom/Welcome)") in new stack [2014-05-28 08:25:59] VERBOSE[6433] pbx.c: -- Executing [[email protected]:11] ExecIf("SIP/Trunk-Out_999999-000001db", "1?Background(custom/Welcome)") in new stack [2014-05-28 08:25:59] WARNING[6433] mp3/interface.c: Junk at the beginning of frame 49443303 [2014-05-28 08:25:59] WARNING[6433] mp3/interface.c: Junk at the beginning of frame 49443303 [2014-05-28 08:25:59] VERBOSE[6433] file.c: -- Playing 'custom/Welcome.slin' (language 'en') [2014-05-28 08:25:59] VERBOSE[6433] file.c: -- Playing 'custom/Welcome.slin' (language 'en') [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: == CDR updated on SIP/Trunk-Out_999999-000001db [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: == CDR updated on SIP/Trunk-Out_999999-000001db [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Macro("SIP/Trunk-Out_999999-000001db", "blkvm-clr,") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Macro("SIP/Trunk-Out_999999-000001db", "blkvm-clr,") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Set("SIP/Trunk-Out_999999-000001db", "SHARED(BLKVM,)=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Set("SIP/Trunk-Out_999999-000001db", "SHARED(BLKVM,)=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Set("SIP/Trunk-Out_999999-000001db", "GOSUB_RETVAL=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Set("SIP/Trunk-Out_999999-000001db", "GOSUB_RETVAL=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] MacroExit("SIP/Trunk-Out_999999-000001db", "") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] MacroExit("SIP/Trunk-Out_999999-000001db", "") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Set("SIP/Trunk-Out_999999-000001db", "__NODEST=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Set("SIP/Trunk-Out_999999-000001db", "__NODEST=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] Goto("SIP/Trunk-Out_999999-000001db", "from-did-direct,20,1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] Goto("SIP/Trunk-Out_999999-000001db", "from-did-direct,20,1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (from-did-direct,20,1) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (from-did-direct,20,1) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Set("SIP/Trunk-Out_999999-000001db", "__RINGTIMER=15") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Set("SIP/Trunk-Out_999999-000001db", "__RINGTIMER=15") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Macro("SIP/Trunk-Out_999999-000001db", "exten-vm,novm,20,1,1,1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Macro("SIP/Trunk-Out_999999-000001db", "exten-vm,novm,20,1,1,1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Macro("SIP/Trunk-Out_999999-000001db", "user-callerid,") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Macro("SIP/Trunk-Out_999999-000001db", "user-callerid,") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Set("SIP/Trunk-Out_999999-000001db", "TOUCH_MONITOR=1401258353.521") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Set("SIP/Trunk-Out_999999-000001db", "TOUCH_MONITOR=1401258353.521") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Set("SIP/Trunk-Out_999999-000001db", "AMPUSER=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Set("SIP/Trunk-Out_999999-000001db", "AMPUSER=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] GotoIf("SIP/Trunk-Out_999999-000001db", "0?report") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] GotoIf("SIP/Trunk-Out_999999-000001db", "0?report") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:4] ExecIf("SIP/Trunk-Out_999999-000001db", "1?Set(REALCALLERIDNUM=0612345678)") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:4] ExecIf("SIP/Trunk-Out_999999-000001db", "1?Set(REALCALLERIDNUM=0612345678)") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:5] Set("SIP/Trunk-Out_999999-000001db", "AMPUSER=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:5] Set("SIP/Trunk-Out_999999-000001db", "AMPUSER=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:6] GotoIf("SIP/Trunk-Out_999999-000001db", "0?limit") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:6] GotoIf("SIP/Trunk-Out_999999-000001db", "0?limit") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:7] Set("SIP/Trunk-Out_999999-000001db", "AMPUSERCIDNAME=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:7] Set("SIP/Trunk-Out_999999-000001db", "AMPUSERCIDNAME=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:8] GotoIf("SIP/Trunk-Out_999999-000001db", "1?report") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:8] GotoIf("SIP/Trunk-Out_999999-000001db", "1?report") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (macro-user-callerid,s,16) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (macro-user-callerid,s,16) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:16] GotoIf("SIP/Trunk-Out_999999-000001db", "0?continue") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:16] GotoIf("SIP/Trunk-Out_999999-000001db", "0?continue") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:17] Set("SIP/Trunk-Out_999999-000001db", "__TTL=64") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:17] Set("SIP/Trunk-Out_999999-000001db", "__TTL=64") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:18] GotoIf("SIP/Trunk-Out_999999-000001db", "1?continue") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:18] GotoIf("SIP/Trunk-Out_999999-000001db", "1?continue") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (macro-user-callerid,s,29) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (macro-user-callerid,s,29) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:29] Set("SIP/Trunk-Out_999999-000001db", "CALLERID(number)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:29] Set("SIP/Trunk-Out_999999-000001db", "CALLERID(number)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:30] Set("SIP/Trunk-Out_999999-000001db", "CALLERID(name)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:30] Set("SIP/Trunk-Out_999999-000001db", "CALLERID(name)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:31] Set("SIP/Trunk-Out_999999-000001db", "CDR(cnum)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:31] Set("SIP/Trunk-Out_999999-000001db", "CDR(cnum)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:32] Set("SIP/Trunk-Out_999999-000001db", "CDR(cnam)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:32] Set("SIP/Trunk-Out_999999-000001db", "CDR(cnam)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:33] Set("SIP/Trunk-Out_999999-000001db", "CHANNEL(language)=en") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:33] Set("SIP/Trunk-Out_999999-000001db", "CHANNEL(language)=en") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Set("SIP/Trunk-Out_999999-000001db", "RingGroupMethod=none") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Set("SIP/Trunk-Out_999999-000001db", "RingGroupMethod=none") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] Set("SIP/Trunk-Out_999999-000001db", "__EXTTOCALL=20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] Set("SIP/Trunk-Out_999999-000001db", "__EXTTOCALL=20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:4] Set("SIP/Trunk-Out_999999-000001db", "__PICKUPMARK=20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:4] Set("SIP/Trunk-Out_999999-000001db", "__PICKUPMARK=20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:5] Set("SIP/Trunk-Out_999999-000001db", "RT=15") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:5] Set("SIP/Trunk-Out_999999-000001db", "RT=15") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:6] Gosub("SIP/Trunk-Out_999999-000001db", "sub-record-check,s,1(exten,20,)") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:6] Gosub("SIP/Trunk-Out_999999-000001db", "sub-record-check,s,1(exten,20,)") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Set("SIP/Trunk-Out_999999-000001db", "REC_POLICY_MODE_SAVE=always") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Set("SIP/Trunk-Out_999999-000001db", "REC_POLICY_MODE_SAVE=always") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] GotoIf("SIP/Trunk-Out_999999-000001db", "1?check") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] GotoIf("SIP/Trunk-Out_999999-000001db", "1?check") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (sub-record-check,s,7) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (sub-record-check,s,7) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:7] Set("SIP/Trunk-Out_999999-000001db", "__MON_FMT=wav") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:7] Set("SIP/Trunk-Out_999999-000001db", "__MON_FMT=wav") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:8] GotoIf("SIP/Trunk-Out_999999-000001db", "0?next") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:8] GotoIf("SIP/Trunk-Out_999999-000001db", "0?next") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:9] Set("SIP/Trunk-Out_999999-000001db", "CDR(recordingfile)=force-31174999999-unknown-20140528-082557-1401258353.521.wav") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:9] Set("SIP/Trunk-Out_999999-000001db", "CDR(recordingfile)=force-31174999999-unknown-20140528-082557-1401258353.521.wav") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:10] Return("SIP/Trunk-Out_999999-000001db", "") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:10] Return("SIP/Trunk-Out_999999-000001db", "") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:7] GotoIf("SIP/Trunk-Out_999999-000001db", "1?macrodial") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:7] GotoIf("SIP/Trunk-Out_999999-000001db", "1?macrodial") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (macro-exten-vm,s,13) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (macro-exten-vm,s,13) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:13] GosubIf("SIP/Trunk-Out_999999-000001db", "0?clrheader,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:13] GosubIf("SIP/Trunk-Out_999999-000001db", "0?clrheader,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:14] Macro("SIP/Trunk-Out_999999-000001db", "dial-one,15,tr,20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:14] Macro("SIP/Trunk-Out_999999-000001db", "dial-one,15,tr,20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Set("SIP/Trunk-Out_999999-000001db", "DEXTEN=20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Set("SIP/Trunk-Out_999999-000001db", "DEXTEN=20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Set("SIP/Trunk-Out_999999-000001db", "DIALSTATUS_CW=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Set("SIP/Trunk-Out_999999-000001db", "DIALSTATUS_CW=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] GosubIf("SIP/Trunk-Out_999999-000001db", "0?screen,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] GosubIf("SIP/Trunk-Out_999999-000001db", "0?screen,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:4] GosubIf("SIP/Trunk-Out_999999-000001db", "0?cf,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:4] GosubIf("SIP/Trunk-Out_999999-000001db", "0?cf,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:5] GotoIf("SIP/Trunk-Out_999999-000001db", "1?skip1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:5] GotoIf("SIP/Trunk-Out_999999-000001db", "1?skip1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (macro-dial-one,s,8) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (macro-dial-one,s,8) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:8] GotoIf("SIP/Trunk-Out_999999-000001db", "0?nodial") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:8] GotoIf("SIP/Trunk-Out_999999-000001db", "0?nodial") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/Trunk-Out_999999-000001db", "0?continue") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/Trunk-Out_999999-000001db", "0?continue") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:10] Set("SIP/Trunk-Out_999999-000001db", "EXTHASCW=ENABLED") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:10] Set("SIP/Trunk-Out_999999-000001db", "EXTHASCW=ENABLED") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:11] GotoIf("SIP/Trunk-Out_999999-000001db", "0?next1:cwinusebusy") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:11] GotoIf("SIP/Trunk-Out_999999-000001db", "0?next1:cwinusebusy") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (macro-dial-one,s,23) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (macro-dial-one,s,23) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:23] GotoIf("SIP/Trunk-Out_999999-000001db", "1?next3:continue") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:23] GotoIf("SIP/Trunk-Out_999999-000001db", "1?next3:continue") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (macro-dial-one,s,24) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (macro-dial-one,s,24) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:24] ExecIf("SIP/Trunk-Out_999999-000001db", "0?Set(DIALSTATUS_CW=BUSY)") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:24] ExecIf("SIP/Trunk-Out_999999-000001db", "0?Set(DIALSTATUS_CW=BUSY)") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:25] GotoIf("SIP/Trunk-Out_999999-000001db", "0?nodial") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:25] GotoIf("SIP/Trunk-Out_999999-000001db", "0?nodial") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:26] GosubIf("SIP/Trunk-Out_999999-000001db", "1?dstring,1():dlocal,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:26] GosubIf("SIP/Trunk-Out_999999-000001db", "1?dstring,1():dlocal,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Set("SIP/Trunk-Out_999999-000001db", "DSTRING=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Set("SIP/Trunk-Out_999999-000001db", "DSTRING=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Set("SIP/Trunk-Out_999999-000001db", "DEVICES=20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Set("SIP/Trunk-Out_999999-000001db", "DEVICES=20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/Trunk-Out_999999-000001db", "0?Return()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/Trunk-Out_999999-000001db", "0?Return()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:4] ExecIf("SIP/Trunk-Out_999999-000001db", "0?Set(DEVICES=0)") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:4] ExecIf("SIP/Trunk-Out_999999-000001db", "0?Set(DEVICES=0)") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:5] Set("SIP/Trunk-Out_999999-000001db", "LOOPCNT=1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:5] Set("SIP/Trunk-Out_999999-000001db", "LOOPCNT=1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:6] Set("SIP/Trunk-Out_999999-000001db", "ITER=1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:6] Set("SIP/Trunk-Out_999999-000001db", "ITER=1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:7] Set("SIP/Trunk-Out_999999-000001db", "THISDIAL=SIP/20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:7] Set("SIP/Trunk-Out_999999-000001db", "THISDIAL=SIP/20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:8] GosubIf("SIP/Trunk-Out_999999-000001db", "1?zap2dahdi,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:8] GosubIf("SIP/Trunk-Out_999999-000001db", "1?zap2dahdi,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/Trunk-Out_999999-000001db", "0?Return()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/Trunk-Out_999999-000001db", "0?Return()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Set("SIP/Trunk-Out_999999-000001db", "NEWDIAL=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Set("SIP/Trunk-Out_999999-000001db", "NEWDIAL=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] Set("SIP/Trunk-Out_999999-000001db", "LOOPCNT2=1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] Set("SIP/Trunk-Out_999999-000001db", "LOOPCNT2=1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:4] Set("SIP/Trunk-Out_999999-000001db", "ITER2=1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:4] Set("SIP/Trunk-Out_999999-000001db", "ITER2=1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:5] Set("SIP/Trunk-Out_999999-000001db", "THISPART2=SIP/20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:5] Set("SIP/Trunk-Out_999999-000001db", "THISPART2=SIP/20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:6] ExecIf("SIP/Trunk-Out_999999-000001db", "0?Set(THISPART2=DAHDI/20)") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:6] ExecIf("SIP/Trunk-Out_999999-000001db", "0?Set(THISPART2=DAHDI/20)") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]macro-dial-one:7] Set("SIP/Trunk-Out_999999-000001db", "NEWDIAL=SIP/20&") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:7] Set("SIP/Trunk-Out_999999-000001db", "NEWDIAL=SIP/20&") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:8] Set("SIP/Trunk-Out_999999-000001db", "ITER2=2") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:8] Set("SIP/Trunk-Out_999999-000001db", "ITER2=2") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/Trunk-Out_999999-000001db", "0?begin2") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/Trunk-Out_999999-000001db", "0?begin2") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:10] Set("SIP/Trunk-Out_999999-000001db", "THISDIAL=SIP/20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:10] Set("SIP/Trunk-Out_999999-000001db", "THISDIAL=SIP/20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:11] Return("SIP/Trunk-Out_999999-000001db", "") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:11] Return("SIP/Trunk-Out_999999-000001db", "") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:9] Set("SIP/Trunk-Out_999999-000001db", "DSTRING=SIP/20&") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:9] Set("SIP/Trunk-Out_999999-000001db", "DSTRING=SIP/20&") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:10] Set("SIP/Trunk-Out_999999-000001db", "ITER=2") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:10] Set("SIP/Trunk-Out_999999-000001db", "ITER=2") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:11] GotoIf("SIP/Trunk-Out_999999-000001db", "0?begin") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:11] GotoIf("SIP/Trunk-Out_999999-000001db", "0?begin") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:12] Set("SIP/Trunk-Out_999999-000001db", "DSTRING=SIP/20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:12] Set("SIP/Trunk-Out_999999-000001db", "DSTRING=SIP/20") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:13] Return("SIP/Trunk-Out_999999-000001db", "") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:13] Return("SIP/Trunk-Out_999999-000001db", "") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:27] GotoIf("SIP/Trunk-Out_999999-000001db", "0?nodial") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:27] GotoIf("SIP/Trunk-Out_999999-000001db", "0?nodial") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:28] GotoIf("SIP/Trunk-Out_999999-000001db", "0?skiptrace") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:28] GotoIf("SIP/Trunk-Out_999999-000001db", "0?skiptrace") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:29] GosubIf("SIP/Trunk-Out_999999-000001db", "1?ctset,1():ctclear,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:29] GosubIf("SIP/Trunk-Out_999999-000001db", "1?ctset,1():ctclear,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Set("SIP/Trunk-Out_999999-000001db", "DB(CALLTRACE/20)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] Set("SIP/Trunk-Out_999999-000001db", "DB(CALLTRACE/20)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Return("SIP/Trunk-Out_999999-000001db", "") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Return("SIP/Trunk-Out_999999-000001db", "") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:30] Set("SIP/Trunk-Out_999999-000001db", "D_OPTIONS=tr") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:30] Set("SIP/Trunk-Out_999999-000001db", "D_OPTIONS=tr") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:31] ExecIf("SIP/Trunk-Out_999999-000001db", "1?SIPAddHeader(Alert-Info: n=Classic-1\;w=3\;c=1)") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:31] ExecIf("SIP/Trunk-Out_999999-000001db", "1?SIPAddHeader(Alert-Info: n=Classic-1\;w=3\;c=1)") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:32] ExecIf("SIP/Trunk-Out_999999-000001db", "0?SIPAddHeader()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:32] ExecIf("SIP/Trunk-Out_999999-000001db", "0?SIPAddHeader()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:33] ExecIf("SIP/Trunk-Out_999999-000001db", "1?Set(CHANNEL(musicclass)=none)") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:33] ExecIf("SIP/Trunk-Out_999999-000001db", "1?Set(CHANNEL(musicclass)=none)") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:34] GosubIf("SIP/Trunk-Out_999999-000001db", "0?qwait,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:34] GosubIf("SIP/Trunk-Out_999999-000001db", "0?qwait,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:35] Set("SIP/Trunk-Out_999999-000001db", "__CWIGNORE=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:35] Set("SIP/Trunk-Out_999999-000001db", "__CWIGNORE=") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:36] Set("SIP/Trunk-Out_999999-000001db", "__KEEPCID=TRUE") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:36] Set("SIP/Trunk-Out_999999-000001db", "__KEEPCID=TRUE") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:37] GotoIf("SIP/Trunk-Out_999999-000001db", "0?usegoto,1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:37] GotoIf("SIP/Trunk-Out_999999-000001db", "0?usegoto,1") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:38] GotoIf("SIP/Trunk-Out_999999-000001db", "1?godial") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:38] GotoIf("SIP/Trunk-Out_999999-000001db", "1?godial") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (macro-dial-one,s,42) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Goto (macro-dial-one,s,42) [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:42] Dial("SIP/Trunk-Out_999999-000001db", "SIP/20,15,tr") in new stack [2014-05-28 08:26:01] VERBOSE[6433] pbx.c: -- Executing [[email protected]:42] Dial("SIP/Trunk-Out_999999-000001db", "SIP/20,15,tr") in new stack [2014-05-28 08:26:01] VERBOSE[6433] netsock.c: == Using UDPTL TOS bits 184 [2014-05-28 08:26:01] VERBOSE[6433] netsock.c: == Using UDPTL TOS bits 184 [2014-05-28 08:26:01] VERBOSE[6433] netsock.c: == Using UDPTL CoS mark 5 [2014-05-28 08:26:01] VERBOSE[6433] netsock.c: == Using UDPTL CoS mark 5 [2014-05-28 08:26:01] VERBOSE[6433] netsock2.c: == Using SIP RTP TOS bits 184 [2014-05-28 08:26:01] VERBOSE[6433] netsock2.c: == Using SIP RTP TOS bits 184 [2014-05-28 08:26:01] VERBOSE[6433] netsock2.c: == Using SIP RTP CoS mark 5 [2014-05-28 08:26:01] VERBOSE[6433] netsock2.c: == Using SIP RTP CoS mark 5 [2014-05-28 08:26:01] VERBOSE[6433] app_dial.c: -- Called SIP/20 [2014-05-28 08:26:01] VERBOSE[6433] app_dial.c: -- Called SIP/20 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 17 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 17 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 27 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 27 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 12 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 12 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 11 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 11 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 32 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 32 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 18 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 18 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 31 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 31 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 19 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 19 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 26 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 26 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 15 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 15 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 22 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 22 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 29 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 29 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 21 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 21 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 20 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Ringing for Notify User 20 [2014-05-28 08:26:01] VERBOSE[3445] chan_sip.c: -- Got SIP response 302 "Moved Temporarily" back from 10.1.100.65:5060 [2014-05-28 08:26:01] VERBOSE[3445] chan_sip.c: -- Got SIP response 302 "Moved Temporarily" back from 10.1.100.65:5060 [2014-05-28 08:26:01] VERBOSE[6433] app_dial.c: -- Now forwarding SIP/Trunk-Out_999999-000001db to 'Local/[email protected]' (thanks to SIP/20-000001dc) [2014-05-28 08:26:01] VERBOSE[6433] app_dial.c: -- Now forwarding SIP/Trunk-Out_999999-000001db to 'Local/[email protected]' (thanks to SIP/20-000001dc) [2014-05-28 08:26:01] NOTICE[6433] app_dial.c: Not accepting call completion offers from call-forward recipient Local/[email protected];1 [2014-05-28 08:26:01] NOTICE[6433] app_dial.c: Not accepting call completion offers from call-forward recipient Local/[email protected];1 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 17 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 17 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 27 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 27 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 12 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 12 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 11 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 11 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 32 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 32 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 18 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 18 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 31 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 31 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 19 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 19 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 26 (queued) [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 26 (queued) [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 15 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 15 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 22 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 22 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 29 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 29 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 21 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 21 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 20 [2014-05-28 08:26:01] VERBOSE[3277] chan_sip.c: == Extension Changed 20[ext-local] new state Idle for Notify User 20 [2014-05-28 08:26:01] VERBOSE[3445] chan_sip.c: == Extension Changed 20[from-internal] new state Idle for Notify User 26 [2014-05-28 08:26:01] VERBOSE[3445] chan_sip.c: == Extension Changed 20[from-internal] new state Idle for Notify User 26 [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] Macro("Local/[email protected];2", "user-callerid,LIMIT,EXTERNAL,") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] Macro("Local/[email protected];2", "user-callerid,LIMIT,EXTERNAL,") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] Set("Local/[email protected];2", "TOUCH_MONITOR=1401258361.524") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] Set("Local/[email protected];2", "TOUCH_MONITOR=1401258361.524") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:2] Set("Local/[email protected];2", "AMPUSER=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:2] Set("Local/[email protected];2", "AMPUSER=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:3] GotoIf("Local/[email protected];2", "0?report") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:3] GotoIf("Local/[email protected];2", "0?report") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:4] ExecIf("Local/[email protected];2", "1?Set(REALCALLERIDNUM=0612345678)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:4] ExecIf("Local/[email protected];2", "1?Set(REALCALLERIDNUM=0612345678)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:5] Set("Local/[email protected];2", "AMPUSER=") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:5] Set("Local/[email protected];2", "AMPUSER=") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:6] GotoIf("Local/[email protected];2", "0?limit") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:6] GotoIf("Local/[email protected];2", "0?limit") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "AMPUSERCIDNAME=") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "AMPUSERCIDNAME=") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:8] GotoIf("Local/[email protected];2", "1?report") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:8] GotoIf("Local/[email protected];2", "1?report") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Goto (macro-user-callerid,s,16) [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Goto (macro-user-callerid,s,16) [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:16] GotoIf("Local/[email protected];2", "1?continue") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:16] GotoIf("Local/[email protected];2", "1?continue") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Goto (macro-user-callerid,s,29) [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Goto (macro-user-callerid,s,29) [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:29] Set("Local/[email protected];2", "CALLERID(number)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:29] Set("Local/[email protected];2", "CALLERID(number)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:30] Set("Local/[email protected];2", "CALLERID(name)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:30] Set("Local/[email protected];2", "CALLERID(name)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:31] Set("Local/[email protected];2", "CDR(cnum)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:31] Set("Local/[email protected];2", "CDR(cnum)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:32] Set("Local/[email protected];2", "CDR(cnam)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:32] Set("Local/[email protected];2", "CDR(cnam)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:33] Set("Local/[email protected];2", "CHANNEL(language)=en") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:33] Set("Local/[email protected];2", "CHANNEL(language)=en") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:2] Gosub("Local/[email protected];2", "sub-record-check,s,1(force,0687654321,always)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:2] Gosub("Local/[email protected];2", "sub-record-check,s,1(force,0687654321,always)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] Set("Local/[email protected];2", "REC_POLICY_MODE_SAVE=always") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] Set("Local/[email protected];2", "REC_POLICY_MODE_SAVE=always") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "1?check") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "1?check") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Goto (sub-record-check,s,7) [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Goto (sub-record-check,s,7) [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "__MON_FMT=wav") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "__MON_FMT=wav") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:8] GotoIf("Local/[email protected];2", "0?next") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:8] GotoIf("Local/[email protected];2", "0?next") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:9] Set("Local/[email protected];2", "CDR(recordingfile)=force-31174999999-unknown-20140528-082557-1401258353.521.wav") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:9] Set("Local/[email protected];2", "CDR(recordingfile)=force-31174999999-unknown-20140528-082557-1401258353.521.wav") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:10] Return("Local/[email protected];2", "") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:10] Return("Local/[email protected];2", "") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:3] Set("Local/[email protected];2", "MOHCLASS=none") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:3] Set("Local/[email protected];2", "MOHCLASS=none") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "_NODEST=") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "_NODEST=") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:5] Gosub("Local/[email protected];2", "sub-record-check,s,1(out,0687654321,)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:5] Gosub("Local/[email protected];2", "sub-record-check,s,1(out,0687654321,)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] Set("Local/[email protected];2", "REC_POLICY_MODE_SAVE=always") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] Set("Local/[email protected];2", "REC_POLICY_MODE_SAVE=always") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "1?check") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "1?check") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Goto (sub-record-check,s,7) [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Goto (sub-record-check,s,7) [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "__MON_FMT=wav") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "__MON_FMT=wav") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:8] GotoIf("Local/[email protected];2", "0?next") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:8] GotoIf("Local/[email protected];2", "0?next") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:9] Set("Local/[email protected];2", "CDR(recordingfile)=force-31174999999-unknown-20140528-082557-1401258353.521.wav") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:9] Set("Local/[email protected];2", "CDR(recordingfile)=force-31174999999-unknown-20140528-082557-1401258353.521.wav") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:10] Return("Local/[email protected];2", "") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:10] Return("Local/[email protected];2", "") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:6] Macro("Local/[email protected];2", "dialout-trunk,10,0687654321,,off") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:6] Macro("Local/[email protected];2", "dialout-trunk,10,0687654321,,off") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] Set("Local/[email protected];2", "DIAL_TRUNK=10") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] Set("Local/[email protected];2", "DIAL_TRUNK=10") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:2] GosubIf("Local/[email protected];2", "0?sub-pincheck,s,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:2] GosubIf("Local/[email protected];2", "0?sub-pincheck,s,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:3] GotoIf("Local/[email protected];2", "0?disabletrunk,1") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:3] GotoIf("Local/[email protected];2", "0?disabletrunk,1") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "DIAL_NUMBER=0687654321") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "DIAL_NUMBER=0687654321") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:5] Set("Local/[email protected];2", "DIAL_TRUNK_OPTIONS=tr") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:5] Set("Local/[email protected];2", "DIAL_TRUNK_OPTIONS=tr") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:6] Set("Local/[email protected];2", "OUTBOUND_GROUP=OUT_10") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:6] Set("Local/[email protected];2", "OUTBOUND_GROUP=OUT_10") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:7] GotoIf("Local/[email protected];2", "1?nomax") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:7] GotoIf("Local/[email protected];2", "1?nomax") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Goto (macro-dialout-trunk,s,9) [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Goto (macro-dialout-trunk,s,9) [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:9] GotoIf("Local/[email protected];2", "0?skipoutcid") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:9] GotoIf("Local/[email protected];2", "0?skipoutcid") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:10] Set("Local/[email protected];2", "DIAL_TRUNK_OPTIONS=") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:10] Set("Local/[email protected];2", "DIAL_TRUNK_OPTIONS=") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:11] Macro("Local/[email protected];2", "outbound-callerid,10") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:11] Macro("Local/[email protected];2", "outbound-callerid,10") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] ExecIf("Local/[email protected];2", "1?Set(CALLERPRES()=allowed_not_screened)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] ExecIf("Local/[email protected];2", "1?Set(CALLERPRES()=allowed_not_screened)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:2] ExecIf("Local/[email protected];2", "0?Set(REALCALLERIDNUM=0612345678)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:2] ExecIf("Local/[email protected];2", "0?Set(REALCALLERIDNUM=0612345678)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:3] GotoIf("Local/[email protected];2", "0?normcid") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:3] GotoIf("Local/[email protected];2", "0?normcid") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "USEROUTCID=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "USEROUTCID=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:5] GotoIf("Local/[email protected];2", "1?bypass") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:5] GotoIf("Local/[email protected];2", "1?bypass") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Goto (macro-outbound-callerid,s,7) [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Goto (macro-outbound-callerid,s,7) [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "EMERGENCYCID=") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "EMERGENCYCID=") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:8] Set("Local/[email protected];2", "TRUNKOUTCID=31174999999") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:8] Set("Local/[email protected];2", "TRUNKOUTCID=31174999999") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:9] GotoIf("Local/[email protected];2", "1?trunkcid") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:9] GotoIf("Local/[email protected];2", "1?trunkcid") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Goto (macro-outbound-callerid,s,14) [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Goto (macro-outbound-callerid,s,14) [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:14] ExecIf("Local/[email protected];2", "1?Set(CALLERID(all)=31174999999)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:14] ExecIf("Local/[email protected];2", "1?Set(CALLERID(all)=31174999999)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:15] ExecIf("Local/[email protected];2", "1?Set(CALLERID(all)=0612345678)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:15] ExecIf("Local/[email protected];2", "1?Set(CALLERID(all)=0612345678)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:16] ExecIf("Local/[email protected];2", "0?Set(CALLERID(all)=)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:16] ExecIf("Local/[email protected];2", "0?Set(CALLERID(all)=)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:17] ExecIf("Local/[email protected];2", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:17] ExecIf("Local/[email protected];2", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:18] Set("Local/[email protected];2", "CDR(outbound_cnum)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:18] Set("Local/[email protected];2", "CDR(outbound_cnum)=0612345678") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:19] Set("Local/[email protected];2", "CDR(outbound_cnam)=") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:19] Set("Local/[email protected];2", "CDR(outbound_cnam)=") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:12] GosubIf("Local/[email protected];2", "0?sub-flp-10,s,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:12] GosubIf("Local/[email protected];2", "0?sub-flp-10,s,1()") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:13] Set("Local/[email protected];2", "OUTNUM=0687654321") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:13] Set("Local/[email protected];2", "OUTNUM=0687654321") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:14] Set("Local/[email protected];2", "custom=SIP/Trunk-Out_999999") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:14] Set("Local/[email protected];2", "custom=SIP/Trunk-Out_999999") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:15] ExecIf("Local/[email protected];2", "1?Set(DIAL_TRUNK_OPTIONS=M(setmusic^none))") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:15] ExecIf("Local/[email protected];2", "1?Set(DIAL_TRUNK_OPTIONS=M(setmusic^none))") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:16] ExecIf("Local/[email protected];2", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^none)M(confirm))") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:16] ExecIf("Local/[email protected];2", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^none)M(confirm))") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:17] Macro("Local/[email protected];2", "dialout-trunk-predial-hook,") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:17] Macro("Local/[email protected];2", "dialout-trunk-predial-hook,") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] MacroExit("Local/[email protected];2", "") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] MacroExit("Local/[email protected];2", "") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:18] GotoIf("Local/[email protected];2", "0?bypass,1") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:18] GotoIf("Local/[email protected];2", "0?bypass,1") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:19] ExecIf("Local/[email protected];2", "0?Set(CONNECTEDLINE(num,i)=0687654321)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:19] ExecIf("Local/[email protected];2", "0?Set(CONNECTEDLINE(num,i)=0687654321)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:20] ExecIf("Local/[email protected];2", "0?Set(CONNECTEDLINE(name,i)=CID:0612345678)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:20] ExecIf("Local/[email protected];2", "0?Set(CONNECTEDLINE(name,i)=CID:0612345678)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:21] GotoIf("Local/[email protected];2", "0?customtrunk") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:21] GotoIf("Local/[email protected];2", "0?customtrunk") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:22] Dial("Local/[email protected];2", "SIP/Trunk-Out_999999/0687654321,300,M(setmusic^none)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] pbx.c: -- Executing [[email protected]:22] Dial("Local/[email protected];2", "SIP/Trunk-Out_999999/0687654321,300,M(setmusic^none)") in new stack [2014-05-28 08:26:01] VERBOSE[6446] netsock.c: == Using UDPTL TOS bits 184 [2014-05-28 08:26:01] VERBOSE[6446] netsock.c: == Using UDPTL TOS bits 184 [2014-05-28 08:26:01] VERBOSE[6446] netsock.c: == Using UDPTL CoS mark 5 [2014-05-28 08:26:01] VERBOSE[6446] netsock.c: == Using UDPTL CoS mark 5 [2014-05-28 08:26:01] VERBOSE[6446] netsock2.c: == Using SIP RTP TOS bits 184 [2014-05-28 08:26:01] VERBOSE[6446] netsock2.c: == Using SIP RTP TOS bits 184 [2014-05-28 08:26:01] VERBOSE[6446] netsock2.c: == Using SIP RTP CoS mark 5 [2014-05-28 08:26:01] VERBOSE[6446] netsock2.c: == Using SIP RTP CoS mark 5 [2014-05-28 08:26:01] VERBOSE[6446] app_dial.c: -- Called SIP/Trunk-Out_999999/0687654321 [2014-05-28 08:26:01] VERBOSE[6446] app_dial.c: -- Called SIP/Trunk-Out_999999/0687654321 [2014-05-28 08:26:05] VERBOSE[6446] app_dial.c: -- SIP/Trunk-Out_999999-000001dd is ringing [2014-05-28 08:26:05] VERBOSE[6446] app_dial.c: -- SIP/Trunk-Out_999999-000001dd is ringing [2014-05-28 08:26:05] VERBOSE[6446] app_dial.c: -- SIP/Trunk-Out_999999-000001dd is making progress passing it to Local/[email protected];2 [2014-05-28 08:26:05] VERBOSE[6446] app_dial.c: -- SIP/Trunk-Out_999999-000001dd is making progress passing it to Local/[email protected];2 [2014-05-28 08:26:05] VERBOSE[6433] app_dial.c: -- Local/[email protected];1 is ringing [2014-05-28 08:26:05] VERBOSE[6433] app_dial.c: -- Local/[email protected];1 is ringing [2014-05-28 08:26:05] VERBOSE[6433] app_dial.c: -- Local/[email protected];1 is making progress passing it to SIP/Trunk-Out_999999-000001db [2014-05-28 08:26:05] VERBOSE[6433] app_dial.c: -- Local/[email protected];1 is making progress passing it to SIP/Trunk-Out_999999-000001db [2014-05-28 08:26:17] VERBOSE[6433] app_dial.c: -- Nobody picked up in 15000 ms [2014-05-28 08:26:17] VERBOSE[6433] app_dial.c: -- Nobody picked up in 15000 ms [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:43] ExecIf("SIP/Trunk-Out_999999-000001db", "0?MacroExit()") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:43] ExecIf("SIP/Trunk-Out_999999-000001db", "0?MacroExit()") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:44] ExecIf("SIP/Trunk-Out_999999-000001db", "0?Set(DIALSTATUS=)") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:44] ExecIf("SIP/Trunk-Out_999999-000001db", "0?Set(DIALSTATUS=)") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:45] GosubIf("SIP/Trunk-Out_999999-000001db", "0?s-NOANSWER,1()") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:45] GosubIf("SIP/Trunk-Out_999999-000001db", "0?s-NOANSWER,1()") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:46] MacroExit("SIP/Trunk-Out_999999-000001db", "") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:46] MacroExit("SIP/Trunk-Out_999999-000001db", "") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:15] Set("SIP/Trunk-Out_999999-000001db", "SV_DIALSTATUS=NOANSWER") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:15] Set("SIP/Trunk-Out_999999-000001db", "SV_DIALSTATUS=NOANSWER") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:16] GosubIf("SIP/Trunk-Out_999999-000001db", "0?docfu,1()") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:16] GosubIf("SIP/Trunk-Out_999999-000001db", "0?docfu,1()") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:17] GosubIf("SIP/Trunk-Out_999999-000001db", "0?docfb,1()") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:17] GosubIf("SIP/Trunk-Out_999999-000001db", "0?docfb,1()") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:18] Set("SIP/Trunk-Out_999999-000001db", "DIALSTATUS=NOANSWER") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:18] Set("SIP/Trunk-Out_999999-000001db", "DIALSTATUS=NOANSWER") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:19] ExecIf("SIP/Trunk-Out_999999-000001db", "1?MacroExit()") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:19] ExecIf("SIP/Trunk-Out_999999-000001db", "1?MacroExit()") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] Set("SIP/Trunk-Out_999999-000001db", "__PICKUPMARK=") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:3] Set("SIP/Trunk-Out_999999-000001db", "__PICKUPMARK=") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:4] GotoIf("SIP/Trunk-Out_999999-000001db", "1?app-blackhole,hangup,1") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:4] GotoIf("SIP/Trunk-Out_999999-000001db", "1?app-blackhole,hangup,1") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Goto (app-blackhole,hangup,1) [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Goto (app-blackhole,hangup,1) [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/Trunk-Out_999999-000001db", "Blackhole Dest: Hangup") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/Trunk-Out_999999-000001db", "Blackhole Dest: Hangup") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Hangup("SIP/Trunk-Out_999999-000001db", "") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: -- Executing [[email protected]:2] Hangup("SIP/Trunk-Out_999999-000001db", "") in new stack [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: == Spawn extension (app-blackhole, hangup, 2) exited non-zero on 'SIP/Trunk-Out_999999-000001db' [2014-05-28 08:26:17] VERBOSE[6433] pbx.c: == Spawn extension (app-blackhole, hangup, 2) exited non-zero on 'SIP/Trunk-Out_999999-000001db' [2014-05-28 08:26:17] VERBOSE[6446] app_macro.c: == Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on 'Local/[email protected];2' in macro 'dialout-trunk' [2014-05-28 08:26:17] VERBOSE[6446] app_macro.c: == Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on 'Local/[email protected];2' in macro 'dialout-trunk' [2014-05-28 08:26:17] VERBOSE[6446] pbx.c: == Spawn extension (from-internal, 0687654321, 6) exited non-zero on 'Local/[email protected];2' [2014-05-28 08:26:17] VERBOSE[6446] pbx.c: == Spawn extension (from-internal, 0687654321, 6) exited non-zero on 'Local/[email protected];2' [2014-05-28 08:26:17] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] Hangup("Local/[email protected];2", "") in new stack [2014-05-28 08:26:17] VERBOSE[6446] pbx.c: -- Executing [[email protected]:1] Hangup("Local/[email protected];2", "") in new stack [2014-05-28 08:26:17] VERBOSE[6446] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'Local/[email protected];2' [2014-05-28 08:26:17] VERBOSE[6446] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'Local/[email protected];2' [2014-05-28 08:26:17] VERBOSE[6440] app_mixmonitor.c: == MixMonitor close filestream [2014-05-28 08:26:17] VERBOSE[6440] app_mixmonitor.c: == MixMonitor close filestream [2014-05-28 08:26:17] VERBOSE[6440] app_mixmonitor.c: == End MixMonitor Recording SIP/Trunk-Out_999999-000001db [2014-05-28 08:26:17] VERBOSE[6440] app_mixmonitor.c: == End MixMonitor Recording SIP/Trunk-Out_999999-000001db [2014-05-28 08:26:24] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:24] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:24] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:24] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:24] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:24] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: -- Re-registration for [email protected] [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s) [2014-05-28 08:26:25] NOTICE[3445] chan_sip.c: Outbound Registration: Expiry for is 120 sec (Scheduling reregistration in 105 s)