Trunk "No Response" or "404" Timeout Settings

Hello,

I have set up a test FreePBX with the first two trunks with SIP provider Alpha simulating a “failed” state and the third trunk with SIP provider Beta is still active. They’re actually pointing to a host that doesn’t exist, but that could also occur if our SIP provider’s SIP switch or the ISPs to their equipment were down, their datacenter, etc.

My scenario is this:

I have two trunks with SIP provider Alpha - one is primary, the other is secondary. I then have a third trunk out SIP provider Beta which I use if carrier Alpha were to go down entirely. I noticed that when FreePBX attempts to send the call to the first trunk, then the next, and the last, each trunk would take 30 seconds to timeout when no response is received prior to going out the last trunk.

I have investigated the cause of this issue and found the trunk timeout option in Advanced Settings can lower this timeout, but that is also a timeout even if nobody picks up after the trunk is actually connected and ringing.

I have attached a log file that details my scenario. I am trying to find out if there is a way to lower the trunk “no response” timeout (as in, the trunk doesn’t send us a 408, a 503, and is instead a 404 or “not found”). I do not want to lower the timeout that would be used when users hear a ringing sound - I simply want to lower the timeout before a given trunk is deemed unavailable by FreePBX.

The reason this is even an issue to me is if carrier Alpha were to go down, users would have to wait beyond 60 seconds of silence on their phone before the call would actually connect out carrier Beta. Almost all of our users would give up somewhere around 30 seconds of silence before they wait and hear it connect 30 seconds later.

My question: Is it possible to have the first two trunks attempted simultaneously, or is it possible that I can lower the “no response” timeout value without affecting the “ringing, no response” timeout value?

Any help or advice is appreciated. I’d be glad to share my findings after adjusting anything on my end.

Thank you,

Jon

Here’s my log file:

[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:31] Set("SIP/100-00000418", "CALLERID(name)=John Smith") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:32] Set("SIP/100-00000418", "CDR(cnum)=115") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:33] Set("SIP/100-00000418", "CDR(cnam)=John Smith") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:34] Set("SIP/100-00000418", "CHANNEL(language)=en") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:2] Gosub("SIP/100-00000418", "sub-record-check,s,1(out,7775554422,dontcare)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] GotoIf("SIP/100-00000418", "0?initialized") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:2] Set("SIP/100-00000418", "__REC_STATUS=INITIALIZED") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:3] Set("SIP/100-00000418", "NOW=1441208197") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:4] Set("SIP/100-00000418", "__DAY=02") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:5] Set("SIP/100-00000418", "__MONTH=09") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:6] Set("SIP/100-00000418", "__YEAR=2015") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:7] Set("SIP/100-00000418", "__TIMESTR=20150902-113637") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:8] Set("SIP/100-00000418", "__FROMEXTEN=115") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:9] Set("SIP/100-00000418", "__MON_FMT=wav") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:10] NoOp("SIP/100-00000418", "Recordings initialized") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:11] ExecIf("SIP/100-00000418", "0?Set(ARG3=dontcare)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:12] Set("SIP/100-00000418", "REC_POLICY_MODE_SAVE=") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:13] ExecIf("SIP/100-00000418", "0?Set(REC_STATUS=NO)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:14] GotoIf("SIP/100-00000418", "3?checkaction") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (sub-record-check,s,17)
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:17] GotoIf("SIP/100-00000418", "1?sub-record-check,out,1") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (sub-record-check,out,1)
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] NoOp("SIP/100-00000418", "Outbound Recording Check from 115 to 7775554422") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:2] Set("SIP/100-00000418", "RECMODE=dontcare") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:3] ExecIf("SIP/100-00000418", "1?Goto(routewins)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (sub-record-check,out,7)
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:7] Gosub("SIP/100-00000418", "recordcheck,1(dontcare,out,7775554422)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] NoOp("SIP/100-00000418", "Starting recording check against dontcare") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:2] Goto("SIP/100-00000418", "dontcare") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (sub-record-check,recordcheck,3)
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:3] Return("SIP/100-00000418", "") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:8] Return("SIP/100-00000418", "") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:3] ExecIf("SIP/100-00000418", "0 ?Set(CDR(accountcode)=)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:4] Set("SIP/100-00000418", "MOHCLASS=default") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:5] Set("SIP/100-00000418", "_NODEST=") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:6] Macro("SIP/100-00000418", "dialout-trunk,8,7775554422,,on") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] Set("SIP/100-00000418", "DIAL_TRUNK=8") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:2] GosubIf("SIP/100-00000418", "0?sub-pincheck,s,1()") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:3] GotoIf("SIP/100-00000418", "1?disabletrunk,1") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (macro-dialout-trunk,disabletrunk,1)
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] NoOp("SIP/100-00000418", "TRUNK: AMP:Local/[email protected] DISABLED - falling through to next trunk") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:7] Macro("SIP/100-00000418", "dialout-trunk,1,7775554422,,on") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] Set("SIP/100-00000418", "DIAL_TRUNK=1") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:2] GosubIf("SIP/100-00000418", "0?sub-pincheck,s,1()") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:3] GotoIf("SIP/100-00000418", "0?disabletrunk,1") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:4] Set("SIP/100-00000418", "DIAL_NUMBER=7775554422") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:5] Set("SIP/100-00000418", "DIAL_TRUNK_OPTIONS=Ttr") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:6] Set("SIP/100-00000418", "OUTBOUND_GROUP=OUT_1") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:7] GotoIf("SIP/100-00000418", "1?nomax") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (macro-dialout-trunk,s,9)
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:9] GotoIf("SIP/100-00000418", "0?skipoutcid") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:10] Set("SIP/100-00000418", "DIAL_TRUNK_OPTIONS=Tt") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:11] Macro("SIP/100-00000418", "outbound-callerid,1") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] ExecIf("SIP/100-00000418", "0?Set(CALLERPRES()=)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]allerid:2] ExecIf("SIP/100-00000418", "0?Set(REALCALLERIDNUM=115)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:3] GotoIf("SIP/100-00000418", "1?normcid") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (macro-outbound-callerid,s,6)
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:6] Set("SIP/100-00000418", "USEROUTCID=<5554442222>") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:7] Set("SIP/100-00000418", "EMERGENCYCID=") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:8] Set("SIP/100-00000418", "TRUNKOUTCID=") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:9] GotoIf("SIP/100-00000418", "1?trunkcid") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (macro-outbound-callerid,s,14)
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:14] ExecIf("SIP/100-00000418", "0?Set(CALLERID(all)=)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:15] ExecIf("SIP/100-00000418", "1?Set(CALLERID(all)=<5554442222>)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:16] ExecIf("SIP/100-00000418", "0?Set(CALLERID(all)=)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:17] ExecIf("SIP/100-00000418", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:18] Set("SIP/100-00000418", "CDR(outbound_cnum)=5554442222") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:19] Set("SIP/100-00000418", "CDR(outbound_cnam)=") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:12] GosubIf("SIP/100-00000418", "0?sub-flp-1,s,1()") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:13] Set("SIP/100-00000418", "OUTNUM=7775554422") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:14] Set("SIP/100-00000418", "custom=SIP/ICE") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:15] ExecIf("SIP/100-00000418", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:16] ExecIf("SIP/100-00000418", "0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:17] Macro("SIP/100-00000418", "dialout-trunk-predial-hook,") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] MacroExit("SIP/100-00000418", "") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:18] GotoIf("SIP/100-00000418", "0?bypass,1") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:19] ExecIf("SIP/100-00000418", "1?Set(CONNECTEDLINE(num,i)=7775554422)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:20] ExecIf("SIP/100-00000418", "1?Set(CONNECTEDLINE(name,i)=CID:5554442222)") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:21] GotoIf("SIP/100-00000418", "0?customtrunk") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:22] Dial("SIP/100-00000418", "SIP/ICE/7775554422,300,Tt") in new stack
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] netsock2.c:   == Using SIP RTP TOS bits 184
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] netsock2.c:   == Using SIP RTP CoS mark 5
[2015-09-02 11:36:37] VERBOSE[8928][C-00000eee] app_dial.c:     -- Called SIP/ICE/7775554422
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] app_dial.c:   == Everyone is busy/congested at this time (1:0/0/1)
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:23] NoOp("SIP/100-00000418", "Dial failed for some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 18") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:24] GotoIf("SIP/100-00000418", "1?continue,1:s-CHANUNAVAIL,1") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (macro-dialout-trunk,continue,1)
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] NoOp("SIP/100-00000418", "TRUNK Dial failed due to CHANUNAVAIL HANGUPCAUSE: 18 - failing through to other trunks") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:2] Set("SIP/100-00000418", "CALLERID(number)=115") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:8] Macro("SIP/100-00000418", "dialout-trunk,3,7775554422,,on") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] Set("SIP/100-00000418", "DIAL_TRUNK=3") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:2] GosubIf("SIP/100-00000418", "0?sub-pincheck,s,1()") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:3] GotoIf("SIP/100-00000418", "0?disabletrunk,1") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:4] Set("SIP/100-00000418", "DIAL_NUMBER=7775554422") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:5] Set("SIP/100-00000418", "DIAL_TRUNK_OPTIONS=Ttr") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:6] Set("SIP/100-00000418", "OUTBOUND_GROUP=OUT_3") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:7] GotoIf("SIP/100-00000418", "0?nomax") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:8] GotoIf("SIP/100-00000418", "0?chanfull") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:9] GotoIf("SIP/100-00000418", "0?skipoutcid") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:10] Set("SIP/100-00000418", "DIAL_TRUNK_OPTIONS=Tt") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:11] Macro("SIP/100-00000418", "outbound-callerid,3") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] ExecIf("SIP/100-00000418", "0?Set(CALLERPRES()=)") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:2] ExecIf("SIP/100-00000418", "0?Set(REALCALLERIDNUM=115)") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:3] GotoIf("SIP/100-00000418", "1?normcid") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (macro-outbound-callerid,s,6)
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:6] Set("SIP/100-00000418", "USEROUTCID=<5554442222>") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:7] Set("SIP/100-00000418", "EMERGENCYCID=") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:8] Set("SIP/100-00000418", "TRUNKOUTCID=") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:9] GotoIf("SIP/100-00000418", "1?trunkcid") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (macro-outbound-callerid,s,14)
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:14] ExecIf("SIP/100-00000418", "0?Set(CALLERID(all)=)") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:15] ExecIf("SIP/100-00000418", "1?Set(CALLERID(all)=<5554442222>)") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:16] ExecIf("SIP/100-00000418", "0?Set(CALLERID(all)=)") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:17] ExecIf("SIP/100-00000418", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:18] Set("SIP/100-00000418", "CDR(outbound_cnum)=5554442222") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:19] Set("SIP/100-00000418", "CDR(outbound_cnam)=") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:12] GosubIf("SIP/100-00000418", "0?sub-flp-3,s,1()") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:13] Set("SIP/100-00000418", "OUTNUM=7775554422") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:14] Set("SIP/100-00000418", "custom=SIP/ICE-International") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:15] ExecIf("SIP/100-00000418", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:16] ExecIf("SIP/100-00000418", "0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:17] Macro("SIP/100-00000418", "dialout-trunk-predial-hook,") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] MacroExit("SIP/100-00000418", "") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:18] GotoIf("SIP/100-00000418", "0?bypass,1") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:19] ExecIf("SIP/100-00000418", "1?Set(CONNECTEDLINE(num,i)=7775554422)") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:20] ExecIf("SIP/100-00000418", "1?Set(CONNECTEDLINE(name,i)=CID:5554442222)") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:21] GotoIf("SIP/100-00000418", "0?customtrunk") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:22] Dial("SIP/100-00000418", "SIP/ICE-International/7775554422,300,Tt") in new stack
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] netsock2.c:   == Using SIP RTP TOS bits 184
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] netsock2.c:   == Using SIP RTP CoS mark 5
[2015-09-02 11:37:09] VERBOSE[8928][C-00000eee] app_dial.c:     -- Called SIP/ICE-International/7775554422
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] app_dial.c:     -- SIP/ICE-International-0000041a is circuit-busy
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] app_dial.c:   == Everyone is busy/congested at this time (1:0/1/0)
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:23] NoOp("SIP/100-00000418", "Dial failed for some reason with DIALSTATUS = CONGESTION and HANGUPCAUSE = 18") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:24] GotoIf("SIP/100-00000418", "1?continue,1:s-CONGESTION,1") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (macro-dialout-trunk,continue,1)
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] NoOp("SIP/100-00000418", "TRUNK Dial failed due to CONGESTION HANGUPCAUSE: 18 - failing through to other trunks") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:2] Set("SIP/100-00000418", "CALLERID(number)=115") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:9] Macro("SIP/100-00000418", "dialout-trunk,7,7775554422,,off") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] Set("SIP/100-00000418", "DIAL_TRUNK=7") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:2] GosubIf("SIP/100-00000418", "0?sub-pincheck,s,1()") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:3] GotoIf("SIP/100-00000418", "0?disabletrunk,1") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:4] Set("SIP/100-00000418", "DIAL_NUMBER=7775554422") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:5] Set("SIP/100-00000418", "DIAL_TRUNK_OPTIONS=Ttr") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:6] Set("SIP/100-00000418", "OUTBOUND_GROUP=OUT_7") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:7] GotoIf("SIP/100-00000418", "1?nomax") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (macro-dialout-trunk,s,9)
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:9] GotoIf("SIP/100-00000418", "0?skipoutcid") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:10] Set("SIP/100-00000418", "DIAL_TRUNK_OPTIONS=Tt") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:11] Macro("SIP/100-00000418", "outbound-callerid,7") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] ExecIf("SIP/100-00000418", "0?Set(CALLERPRES()=)") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:2] ExecIf("SIP/100-00000418", "0?Set(REALCALLERIDNUM=115)") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:3] GotoIf("SIP/100-00000418", "1?normcid") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (macro-outbound-callerid,s,6)
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:6] Set("SIP/100-00000418", "USEROUTCID=<5554442222>") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:7] Set("SIP/100-00000418", "EMERGENCYCID=") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:8] Set("SIP/100-00000418", "TRUNKOUTCID=") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:9] GotoIf("SIP/100-00000418", "1?trunkcid") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (macro-outbound-callerid,s,14)
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]ound-callerid:14] ExecIf("SIP/100-00000418", "0?Set(CALLERID(all)=)") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:15] ExecIf("SIP/100-00000418", "1?Set(CALLERID(all)=<5554442222>)") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:16] ExecIf("SIP/100-00000418", "0?Set(CALLERID(all)=)") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:17] ExecIf("SIP/100-00000418", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:18] Set("SIP/100-00000418", "CDR(outbound_cnum)=5554442222") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:19] Set("SIP/100-00000418", "CDR(outbound_cnam)=") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:12] GosubIf("SIP/100-00000418", "1?sub-flp-7,s,1()") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] ExecIf("SIP/100-00000418", "0?Set(TARGET_FLP_7=AUTHCODE*7775554422)") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:2] GotoIf("SIP/100-00000418", "0?match") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:3] ExecIf("SIP/100-00000418", "1?Set(TARGET_FLP_7=AUTHCODE*17775554422)") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:4] GotoIf("SIP/100-00000418", "1?match") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (sub-flp-7,s,8)
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:8] Set("SIP/100-00000418", "DIAL_NUMBER=AUTHCODE*17775554422") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:9] Return("SIP/100-00000418", "") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:13] Set("SIP/100-00000418", "OUTNUM=AUTHCODE*17775554422") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:14] Set("SIP/100-00000418", "custom=SIP/ICE-FR") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:15] ExecIf("SIP/100-00000418", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:16] ExecIf("SIP/100-00000418", "0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:17] Macro("SIP/100-00000418", "dialout-trunk-predial-hook,") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] MacroExit("SIP/100-00000418", "") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:18] GotoIf("SIP/100-00000418", "0?bypass,1") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:19] ExecIf("SIP/100-00000418", "1?Set(CONNECTEDLINE(num,i)=AUTHCODE*17775554422)") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:20] ExecIf("SIP/100-00000418", "1?Set(CONNECTEDLINE(name,i)=CID:5554442222)") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:21] GotoIf("SIP/100-00000418", "0?customtrunk") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:22] Dial("SIP/100-00000418", "SIP/ICE-FR/AUTHCODE*17775554422,300,Tt") in new stack
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] netsock2.c:   == Using SIP VIDEO TOS bits 136
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] netsock2.c:   == Using SIP VIDEO CoS mark 6
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] netsock2.c:   == Using SIP RTP TOS bits 184
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] netsock2.c:   == Using SIP RTP CoS mark 5
[2015-09-02 11:37:41] VERBOSE[8928][C-00000eee] app_dial.c:     -- Called SIP/ICE-FR/AUTHCODE*17775554422
[2015-09-02 11:37:43] VERBOSE[8928][C-00000eee] app_dial.c:     -- SIP/ICE-FR-0000041b is making progress passing it to SIP/100-00000418
[2015-09-02 11:37:49] VERBOSE[8928][C-00000eee] app_dial.c:     -- SIP/ICE-FR-0000041b answered SIP/100-00000418
[2015-09-02 11:37:52] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] Macro("SIP/100-00000418", "hangupcall,") in new stack
[2015-09-02 11:37:52] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:1] ExecIf("SIP/100-00000418", "0?Set(CDR(recordingfile)=.wav)") in new stack
[2015-09-02 11:37:52] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:2] GotoIf("SIP/100-00000418", "1?theend") in new stack
[2015-09-02 11:37:52] VERBOSE[8928][C-00000eee] pbx.c:     -- Goto (macro-hangupcall,s,4)
[2015-09-02 11:37:52] VERBOSE[8928][C-00000eee] pbx.c:     -- Executing [[email protected]:4] Hangup("SIP/100-00000418", "") in new stack
[2015-09-02 11:37:52] VERBOSE[8928][C-00000eee] app_macro.c:   == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/100-00000418' in macro 'hangupcall'
[2015-09-02 11:37:52] VERBOSE[8928][C-00000eee] pbx.c:   == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on 'SIP/100-00000418'
[2015-09-02 11:37:52] VERBOSE[8928][C-00000eee] app_macro.c:   == Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on 'SIP/100-00000418' in macro 'dialout-trunk'
[2015-09-02 11:37:52] VERBOSE[8928][C-00000eee] pbx.c:   == Spawn extension (from-internal, 7775554422, 9) exited non-zero on 'SIP/100-00000418'