Unable to call out on more than one phone at a time

FreePBX version: 2.10.1.16
Asterisk version: 1.8.26.1

 So on my new PBX system I am able to do everything that I want to. Except for use more than one phone to call at the same time... 

 I am using DAHDI trunks which look like this:
      <a>https://www.diigo.com/item/image/4sa6q/e3qh</a>
 Here is what my outbound routes look like:
      <a>https://www.diigo.com/item/image/4sa6q/89u3?k=a660ffc8139f62b1f23b59cd6326951a</a>

 I also have a snippet of the log file from a call that failed while another call was in progress.
[2014-05-19 16:41:00] VERBOSE[31545] pbx.c: == Spawn extension (tc-maint, s, 8) exited non-zero on 'Local/[email protected];2' [2014-05-19 16:41:04] VERBOSE[31487] res_musiconhold.c: -- Stopped music on hold on DAHDI/1-1 [2014-05-19 16:41:38] VERBOSE[1904] netsock2.c: == Using SIP RTP TOS bits 184 [2014-05-19 16:41:38] VERBOSE[1904] netsock2.c: == Using SIP RTP CoS mark 5 [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:1] Macro("SIP/707-0000003a", "user-callerid,LIMIT,") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:1] Set("SIP/707-0000003a", "AMPUSER=707") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:2] GotoIf("SIP/707-0000003a", "0?report") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/707-0000003a", "1?Set(REALCALLERIDNUM=707)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:4] Set("SIP/707-0000003a", "AMPUSER=707") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:5] Set("SIP/707-0000003a", "AMPUSERCIDNAME=Molly McIntyre") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:6] GotoIf("SIP/707-0000003a", "0?report") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:7] Set("SIP/707-0000003a", "AMPUSERCID=707") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:8] Set("SIP/707-0000003a", "CALLERID(all)="Molly McIntyre" <707>") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/707-0000003a", "0?limit") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:10] ExecIf("SIP/707-0000003a", "1?Set(GROUP(concurrency_limit)=707)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:11] GosubIf("SIP/707-0000003a", "7?sub-ccss,s,1(from-internal,14356509950)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/707-0000003a", "0?Return()") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:2] Set("SIP/707-0000003a", "CCSS_SETUP=TRUE") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:3] GosubIf("SIP/707-0000003a", "0?monitor_config,1(from-internal,14356509950):monitor_default,1(from-internal,14356509950)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/707-0000003a", "0?is_exten") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:2] StackPop("SIP/707-0000003a", "") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:3] Return("SIP/707-0000003a", "FALSE") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:12] ExecIf("SIP/707-0000003a", "0?Set(CHANNEL(language)=)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:13] GotoIf("SIP/707-0000003a", "1?continue") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Goto (macro-user-callerid,s,26) [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:26] Set("SIP/707-0000003a", "CALLERID(number)=707") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:27] Set("SIP/707-0000003a", "CALLERID(name)=Molly McIntyre") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:28] Set("SIP/707-0000003a", "CHANNEL(language)=en") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:2] Set("SIP/707-0000003a", "MOHCLASS=default") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/707-0000003a", "0?Set(TRUNKCIDOVERRIDE="McIntyre & Golden" <8012663399>)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:4] Set("SIP/707-0000003a", "_NODEST=") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:5] Gosub("SIP/707-0000003a", "sub-record-check,s,1(out,14356509950,)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/707-0000003a", "1?check") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Goto (sub-record-check,s,6) [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:6] Set("SIP/707-0000003a", "__MON_FMT=wav") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:7] GotoIf("SIP/707-0000003a", "1?next") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Goto (sub-record-check,s,10) [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:10] ExecIf("SIP/707-0000003a", "0?Return()") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:11] GotoIf("SIP/707-0000003a", "0?out,1") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:12] Set("SIP/707-0000003a", "__REC_STATUS=INITIALIZED") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:13] ExecIf("SIP/707-0000003a", "0?Set(__REC_POLICY_MODE=)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:14] Set("SIP/707-0000003a", "NOW=1400539298") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:15] Set("SIP/707-0000003a", "__DAY=19") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:16] Set("SIP/707-0000003a", "__MONTH=05") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:17] Set("SIP/707-0000003a", "__YEAR=2014") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:18] Set("SIP/707-0000003a", "__TIMESTR=20140519-164138") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:19] Set("SIP/707-0000003a", "__FROMEXTEN=707") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:20] Set("SIP/707-0000003a", "__CALLFILENAME=out-14356509950-707-20140519-164138-1400539298.660") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:21] Goto("SIP/707-0000003a", "out,1") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Goto (sub-record-check,out,1) [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/707-0000003a", "1?Set(__REC_POLICY_MODE=dontcare)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:2] GosubIf("SIP/707-0000003a", "0?record,1(exten,14356509950,707)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:3] Return("SIP/707-0000003a", "") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:6] Macro("SIP/707-0000003a", "dialout-trunk,9,14356509950,") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:1] Set("SIP/707-0000003a", "DIAL_TRUNK=9") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:2] GosubIf("SIP/707-0000003a", "0?sub-pincheck,s,1()") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:3] GotoIf("SIP/707-0000003a", "0?disabletrunk,1") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:4] Set("SIP/707-0000003a", "DIAL_NUMBER=14356509950") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:5] Set("SIP/707-0000003a", "DIAL_TRUNK_OPTIONS=trwW") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:6] Set("SIP/707-0000003a", "OUTBOUND_GROUP=OUT_9") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:7] GotoIf("SIP/707-0000003a", "1?nomax") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Goto (macro-dialout-trunk,s,9) [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/707-0000003a", "0?skipoutcid") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:10] Set("SIP/707-0000003a", "DIAL_TRUNK_OPTIONS=wW") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:11] Macro("SIP/707-0000003a", "outbound-callerid,9") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/707-0000003a", "0?Set(CALLERPRES()=)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:2] ExecIf("SIP/707-0000003a", "0?Set(REALCALLERIDNUM=707)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:3] GotoIf("SIP/707-0000003a", "1?normcid") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Goto (macro-outbound-callerid,s,6) [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:6] Set("SIP/707-0000003a", "USEROUTCID="McIntyre&Golden" <801-266-3399>") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:7] Set("SIP/707-0000003a", "EMERGENCYCID=") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:8] Set("SIP/707-0000003a", "TRUNKOUTCID="McIntyre & Golden" <8012663399>") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/707-0000003a", "1?trunkcid") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Goto (macro-outbound-callerid,s,12) [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:12] ExecIf("SIP/707-0000003a", "1?Set(CALLERID(all)="McIntyre & Golden" <8012663399>)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:13] ExecIf("SIP/707-0000003a", "1?Set(CALLERID(all)="McIntyre&Golden" <801-266-3399>)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:14] ExecIf("SIP/707-0000003a", "0?Set(CALLERID(all)=)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:15] ExecIf("SIP/707-0000003a", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:12] GosubIf("SIP/707-0000003a", "0?sub-flp-9,s,1()") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:13] Set("SIP/707-0000003a", "OUTNUM=w14356509950") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:14] Set("SIP/707-0000003a", "custom=DAHDI/1") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:15] ExecIf("SIP/707-0000003a", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)wW)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:16] ExecIf("SIP/707-0000003a", "0?Set(DIAL_TRUNK_OPTIONS=wWM(confirm))") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:17] Macro("SIP/707-0000003a", "dialout-trunk-predial-hook,") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:1] MacroExit("SIP/707-0000003a", "") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:18] GotoIf("SIP/707-0000003a", "0?bypass,1") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:19] ExecIf("SIP/707-0000003a", "1?Set(CONNECTEDLINE(num,i)=14356509950)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:20] ExecIf("SIP/707-0000003a", "1?Set(CONNECTEDLINE(name,i)=CID:8012663399)") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:21] GotoIf("SIP/707-0000003a", "0?customtrunk") in new stack [2014-05-19 16:41:38] VERBOSE[31642] pbx.c: -- Executing [[email protected]:22] Dial("SIP/707-0000003a", "DAHDI/1/w14356509950,300,wW") in new stack [2014-05-19 16:41:38] WARNING[31642] app_dial.c: Unable to create channel of type 'DAHDI' (cause 17 - User busy) [2014-05-19 16:41:38] VERBOSE[31642] app_dial.c: == Everyone is busy/congested at this time (1:1/0/0)
 Any help would be much apreciated! Thanks!

– T-Apgood

Some additional information:
I was using Zap trunks at first and was having the same issue. So I switched to DAHDI trunks (because they are the successor to Zap) and have the same problem. I do believe that my problem has to do with how the outbound routes search for an open trunk to use.

Here is a log snippet from the newer DAHDI trunks

[2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] Macro("SIP/714-0000000f", "user-callerid,LIMIT,") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] Set("SIP/714-0000000f", "AMPUSER=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] GotoIf("SIP/714-0000000f", "0?report") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/714-0000000f", "1?Set(REALCALLERIDNUM=714)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:4] Set("SIP/714-0000000f", "AMPUSER=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:5] Set("SIP/714-0000000f", "AMPUSERCIDNAME=Legal") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]user-callerid:6] GotoIf("SIP/714-0000000f", "0?report") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:7] Set("SIP/714-0000000f", "AMPUSERCID=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:8] Set("SIP/714-0000000f", "CALLERID(all)="Legal" <714>") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/714-0000000f", "0?limit") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:10] ExecIf("SIP/714-0000000f", "1?Set(GROUP(concurrency_limit)=714)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:11] GosubIf("SIP/714-0000000f", "7?sub-ccss,s,1(from-internal,8018031867)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/714-0000000f", "0?Return()") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] Set("SIP/714-0000000f", "CCSS_SETUP=TRUE") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] GosubIf("SIP/714-0000000f", "0?monitor_config,1(from-internal,8018031867):monitor_default,1(from-internal,8018031867)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/714-0000000f", "0?is_exten") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] StackPop("SIP/714-0000000f", "") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] Return("SIP/714-0000000f", "FALSE") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:12] ExecIf("SIP/714-0000000f", "0?Set(CHANNEL(language)=)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:13] GotoIf("SIP/714-0000000f", "1?continue") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (macro-user-callerid,s,26) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:26] Set("SIP/714-0000000f", "CALLERID(number)=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:27] Set("SIP/714-0000000f", "CALLERID(name)=Legal") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:28] Set("SIP/714-0000000f", "CHANNEL(language)=en") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] Set("SIP/714-0000000f", "MOHCLASS=default") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/714-0000000f", "0?Set(TRUNKCIDOVERRIDE="McIntyre & Golden" <8012663399>)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:4] Set("SIP/714-0000000f", "_NODEST=") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:5] Gosub("SIP/714-0000000f", "sub-record-check,s,1(out,8018031867,)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/714-0000000f", "1?check") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (sub-record-check,s,6) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:6] Set("SIP/714-0000000f", "__MON_FMT=wav") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:7] GotoIf("SIP/714-0000000f", "1?next") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (sub-record-check,s,10) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:10] ExecIf("SIP/714-0000000f", "0?Return()") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:11] GotoIf("SIP/714-0000000f", "0?out,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:12] Set("SIP/714-0000000f", "__REC_STATUS=INITIALIZED") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:13] ExecIf("SIP/714-0000000f", "0?Set(__REC_POLICY_MODE=)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:14] Set("SIP/714-0000000f", "NOW=1400616843") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:15] Set("SIP/714-0000000f", "__DAY=20") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:16] Set("SIP/714-0000000f", "__MONTH=05") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:17] Set("SIP/714-0000000f", "__YEAR=2014") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:18] Set("SIP/714-0000000f", "__TIMESTR=20140520-141403") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:19] Set("SIP/714-0000000f", "__FROMEXTEN=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:20] Set("SIP/714-0000000f", "__CALLFILENAME=out-8018031867-714-20140520-141403-1400616843.276") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:21] Goto("SIP/714-0000000f", "out,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (sub-record-check,out,1) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/714-0000000f", "1?Set(__REC_POLICY_MODE=dontcare)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] GosubIf("SIP/714-0000000f", "0?record,1(exten,8018031867,714)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] Return("SIP/714-0000000f", "") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:6] Macro("SIP/714-0000000f", "dialout-trunk,1,8018031867,") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] Set("SIP/714-0000000f", "DIAL_TRUNK=1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] GosubIf("SIP/714-0000000f", "0?sub-pincheck,s,1()") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] GotoIf("SIP/714-0000000f", "0?disabletrunk,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:4] Set("SIP/714-0000000f", "DIAL_NUMBER=8018031867") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:5] Set("SIP/714-0000000f", "DIAL_TRUNK_OPTIONS=trwW") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:6] Set("SIP/714-0000000f", "OUTBOUND_GROUP=OUT_1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:7] GotoIf("SIP/714-0000000f", "0?nomax") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:8] GotoIf("SIP/714-0000000f", "0?chanfull") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/714-0000000f", "0?skipoutcid") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:10] Set("SIP/714-0000000f", "DIAL_TRUNK_OPTIONS=wW") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:11] Macro("SIP/714-0000000f", "outbound-callerid,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/714-0000000f", "0?Set(CALLERPRES()=)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] ExecIf("SIP/714-0000000f", "0?Set(REALCALLERIDNUM=714)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] GotoIf("SIP/714-0000000f", "1?normcid") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (macro-outbound-callerid,s,6) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:6] Set("SIP/714-0000000f", "USEROUTCID=8012663399") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:7] Set("SIP/714-0000000f", "EMERGENCYCID=") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:8] Set("SIP/714-0000000f", "TRUNKOUTCID="McIntyre & Golden"<8012663399>") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/714-0000000f", "1?trunkcid") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (macro-outbound-callerid,s,12) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:12] ExecIf("SIP/714-0000000f", "1?Set(CALLERID(all)="McIntyre & Golden"<8012663399>)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:13] ExecIf("SIP/714-0000000f", "1?Set(CALLERID(all)=8012663399)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:14] ExecIf("SIP/714-0000000f", "0?Set(CALLERID(all)=)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:15] ExecIf("SIP/714-0000000f", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:12] GosubIf("SIP/714-0000000f", "0?sub-flp-1,s,1()") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:13] Set("SIP/714-0000000f", "OUTNUM=w8018031867") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:14] Set("SIP/714-0000000f", "custom=DAHDI/1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:15] ExecIf("SIP/714-0000000f", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)wW)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:16] ExecIf("SIP/714-0000000f", "0?Set(DIAL_TRUNK_OPTIONS=wWM(confirm))") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:17] Macro("SIP/714-0000000f", "dialout-trunk-predial-hook,") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] MacroExit("SIP/714-0000000f", "") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:18] GotoIf("SIP/714-0000000f", "0?bypass,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:19] ExecIf("SIP/714-0000000f", "1?Set(CONNECTEDLINE(num,i)=8018031867)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:20] ExecIf("SIP/714-0000000f", "1?Set(CONNECTEDLINE(name,i)=CID:8012663399)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:21] GotoIf("SIP/714-0000000f", "0?customtrunk") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:22] Dial("SIP/714-0000000f", "DAHDI/1/w8018031867,300,wW") in new stack [2014-05-20 14:14:03] WARNING[1909] app_dial.c: Unable to create channel of type 'DAHDI' (cause 17 - User busy) [2014-05-20 14:14:03] VERBOSE[1909] app_dial.c: == Everyone is busy/congested at this time (1:1/0/0) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:23] NoOp("SIP/714-0000000f", "Dial failed for some reason with DIALSTATUS = BUSY and HANGUPCAUSE = 17") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:24] Goto("SIP/714-0000000f", "s-BUSY,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (macro-dialout-trunk,s-BUSY,1) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/714-0000000f", "Dial failed due to trunk reporting BUSY - giving up") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] PlayTones("SIP/714-0000000f", "busy") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [s-BUS[email protected]:3] Busy("SIP/714-0000000f", "20") in new stack [2014-05-20 14:14:03] VERBOSE[1909] app_macro.c: == Spawn extension (macro-dialout-trunk, s-BUSY, 3) exited non-zero on 'SIP/714-0000000f' in macro 'dialout-trunk' [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: == Spawn extension (from-internal, 8018031867, 6) exited non-zero on 'SIP/714-0000000f' [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] Hangup("SIP/714-0000000f", "") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/714-0000000f' [2014-05-20 14:14:06] VERBOSE[1921] pbx_spool.c: -- Attempting call on Local/[email protected] for application NoCDR() (Retry 1) [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] NoCDR("Local/[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:2] Set("Local/[email protected];2", "TCMAINT=RETURN") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:3] Gosub("Local/[email protected];2", "timeconditions,6,1()") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] GotoIfTime("Local/[email protected];2", "09:00-12:00,mon-fri,*,*?truestate") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "0?truegoto") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?Set(DB(TC/6)=)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC6)=INUSE") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:5] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:6] GotoIf("Local/[email protected];2", "0?timeconditions,7,1") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "TCSTATE=false") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:8] Return("Local/[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:4] Gosub("Local/[email protected];2", "timeconditions,8,1()") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] GotoIfTime("Local/[email protected];2", "00:00-23:59,sat-sun,*,*?truestate") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "0?truegoto") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?Set(DB(TC/8)=)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC8)=INUSE") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:5] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:6] GotoIf("Local/[email protected];2", "0?timeconditions,6,1") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "TCSTATE=false") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:8] Return("Local/[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:5] Gosub("Local/[email protected];2", "timeconditions,7,1()") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] GotoIfTime("Local/[email protected];2", "13:00-17:00,mon-fri,*,*?truestate") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Goto (timeconditions,7,9) [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:9] GotoIf("Local/[email protected];2", "0?falsegoto") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:10] ExecIf("Local/[email protected];2", "0?Set(DB(TC/7)=)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:11] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC7)=NOT_INUSE") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:12] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:13] GotoIf("Local/[email protected];2", "0?ext-group,601,1") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:14] Set("Local/[email protected];2", "TCSTATE=true") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:15] Return("Local/[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:6] Gosub("Local/[email protected];2", "timeconditions,9,1()") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] GotoIfTime("Local/[email protected];2", "12:00-12:59,*,*,*?truestate") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "0?truegoto") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?Set(DB(TC/9)=)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC9)=INUSE") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:5] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:6] GotoIf("Local/[email protected];2", "0?timeconditions,7,1") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "TCSTATE=false") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:8] Return("Local/[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:7] System("Local/[email protected];2", "/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 1") in new stack [2014-05-20 14:14:07] VERBOSE[1922] pbx.c: -- Executing [[email protected]:8] Answer("Local/[email protected];2", "") in new stack [2014-05-20 14:14:07] NOTICE[1921] pbx_spool.c: Call completed to Local/[email protected] [2014-05-20 14:14:07] VERBOSE[1922] pbx.c: == Spawn extension (tc-maint, s, 8) exited non-zero on 'Local/[email protected];2'

Some additional information:
I was using Zap trunks at first and was having the same issue. So I switched to DAHDI trunks (because they are the successor to Zap) and have the same problem. I do believe that my problem has to do with how the outbound routes search for an open trunk to use.

Here is a log snippet from the newer DAHDI trunks

[2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] Macro("SIP/714-0000000f", "user-callerid,LIMIT,") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] Set("SIP/714-0000000f", "AMPUSER=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] GotoIf("SIP/714-0000000f", "0?report") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/714-0000000f", "1?Set(REALCALLERIDNUM=714)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:4] Set("SIP/714-0000000f", "AMPUSER=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:5] Set("SIP/714-0000000f", "AMPUSERCIDNAME=Legal") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:6] GotoIf("SIP/714-0000000f", "0?report") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:7] Set("SIP/714-0000000f", "AMPUSERCID=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:8] Set("SIP/714-0000000f", "CALLERID(all)="Legal" <714>") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/714-0000000f", "0?limit") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:10] ExecIf("SIP/714-0000000f", "1?Set(GROUP(concurrency_limit)=714)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:11] GosubIf("SIP/714-0000000f", "7?sub-ccss,s,1(from-internal,8018031867)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/714-0000000f", "0?Return()") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] Set("SIP/714-0000000f", "CCSS_SETUP=TRUE") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] GosubIf("SIP/714-0000000f", "0?monitor_config,1(from-internal,8018031867):monitor_default,1(from-internal,8018031867)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/714-0000000f", "0?is_exten") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] StackPop("SIP/714-0000000f", "") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] Return("SIP/714-0000000f", "FALSE") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:12] ExecIf("SIP/714-0000000f", "0?Set(CHANNEL(language)=)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:13] GotoIf("SIP/714-0000000f", "1?continue") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (macro-user-callerid,s,26) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:26] Set("SIP/714-0000000f", "CALLERID(number)=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:27] Set("SIP/714-0000000f", "CALLERID(name)=Legal") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:28] Set("SIP/714-0000000f", "CHANNEL(language)=en") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] Set("SIP/714-0000000f", "MOHCLASS=default") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/714-0000000f", "0?Set(TRUNKCIDOVERRIDE="McIntyre & Golden" <8012663399>)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:4] Set("SIP/714-0000000f", "_NODEST=") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:5] Gosub("SIP/714-0000000f", "sub-record-check,s,1(out,8018031867,)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/714-0000000f", "1?check") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (sub-record-check,s,6) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:6] Set("SIP/714-0000000f", "__MON_FMT=wav") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:7] GotoIf("SIP/714-0000000f", "1?next") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (sub-record-check,s,10) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:10] ExecIf("SIP/714-0000000f", "0?Return()") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:11] GotoIf("SIP/714-0000000f", "0?out,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:12] Set("SIP/714-0000000f", "__REC_STATUS=INITIALIZED") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:13] ExecIf("SIP/714-0000000f", "0?Set(__REC_POLICY_MODE=)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:14] Set("SIP/714-0000000f", "NOW=1400616843") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:15] Set("SIP/714-0000000f", "__DAY=20") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:16] Set("SIP/714-0000000f", "__MONTH=05") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:17] Set("SIP/714-0000000f", "__YEAR=2014") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:18] Set("SIP/714-0000000f", "__TIMESTR=20140520-141403") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:19] Set("SIP/714-0000000f", "__FROMEXTEN=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:20] Set("SIP/714-0000000f", "__CALLFILENAME=out-8018031867-714-20140520-141403-1400616843.276") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:21] Goto("SIP/714-0000000f", "out,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (sub-record-check,out,1) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/714-0000000f", "1?Set(__REC_POLICY_MODE=dontcare)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] GosubIf("SIP/714-0000000f", "0?record,1(exten,8018031867,714)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] Return("SIP/714-0000000f", "") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]ernal:6] Macro("SIP/714-0000000f", "dialout-trunk,1,8018031867,") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] Set("SIP/714-0000000f", "DIAL_TRUNK=1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] GosubIf("SIP/714-0000000f", "0?sub-pincheck,s,1()") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] GotoIf("SIP/714-0000000f", "0?disabletrunk,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:4] Set("SIP/714-0000000f", "DIAL_NUMBER=8018031867") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:5] Set("SIP/714-0000000f", "DIAL_TRUNK_OPTIONS=trwW") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:6] Set("SIP/714-0000000f", "OUTBOUND_GROUP=OUT_1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:7] GotoIf("SIP/714-0000000f", "0?nomax") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:8] GotoIf("SIP/714-0000000f", "0?chanfull") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/714-0000000f", "0?skipoutcid") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:10] Set("SIP/714-0000000f", "DIAL_TRUNK_OPTIONS=wW") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:11] Macro("SIP/714-0000000f", "outbound-callerid,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/714-0000000f", "0?Set(CALLERPRES()=)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] ExecIf("SIP/714-0000000f", "0?Set(REALCALLERIDNUM=714)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] GotoIf("SIP/714-0000000f", "1?normcid") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (macro-outbound-callerid,s,6) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:6] Set("SIP/714-0000000f", "USEROUTCID=8012663399") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:7] Set("SIP/714-0000000f", "EMERGENCYCID=") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:8] Set("SIP/714-0000000f", "TRUNKOUTCID="McIntyre & Golden"<8012663399>") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/714-0000000f", "1?trunkcid") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (macro-outbound-callerid,s,12) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:12] ExecIf("SIP/714-0000000f", "1?Set(CALLERID(all)="McIntyre & Golden"<8012663399>)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:13] ExecIf("SIP/714-0000000f", "1?Set(CALLERID(all)=8012663399)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:14] ExecIf("SIP/714-0000000f", "0?Set(CALLERID(all)=)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:15] ExecIf("SIP/714-0000000f", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:12] GosubIf("SIP/714-0000000f", "0?sub-flp-1,s,1()") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:13] Set("SIP/714-0000000f", "OUTNUM=w8018031867") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:14] Set("SIP/714-0000000f", "custom=DAHDI/1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:15] ExecIf("SIP/714-0000000f", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)wW)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:16] ExecIf("SIP/714-0000000f", "0?Set(DIAL_TRUNK_OPTIONS=wWM(confirm))") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:17] Macro("SIP/714-0000000f", "dialout-trunk-predial-hook,") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] MacroExit("SIP/714-0000000f", "") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:18] GotoIf("SIP/714-0000000f", "0?bypass,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:19] ExecIf("SIP/714-0000000f", "1?Set(CONNECTEDLINE(num,i)=8018031867)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:20] ExecIf("SIP/714-0000000f", "1?Set(CONNECTEDLINE(name,i)=CID:8012663399)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:21] GotoIf("SIP/714-0000000f", "0?customtrunk") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:22] Dial("SIP/714-0000000f", "DAHDI/1/w8018031867,300,wW") in new stack [2014-05-20 14:14:03] WARNING[1909] app_dial.c: Unable to create channel of type 'DAHDI' (cause 17 - User busy) [2014-05-20 14:14:03] VERBOSE[1909] app_dial.c: == Everyone is busy/congested at this time (1:1/0/0) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:23] NoOp("SIP/714-0000000f", "Dial failed for some reason with DIALSTATUS = BUSY and HANGUPCAUSE = 17") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:24] Goto("SIP/714-0000000f", "s-BUSY,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (macro-dialout-trunk,s-BUSY,1) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/714-0000000f", "Dial failed due to trunk reporting BUSY - giving up") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] PlayTones("SIP/714-0000000f", "busy") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] Busy("SIP/714-0000000f", "20") in new stack [2014-05-20 14:14:03] VERBOSE[1909] app_macro.c: == Spawn extension (macro-dialout-trunk, s-BUSY, 3) exited non-zero on 'SIP/714-0000000f' in macro 'dialout-trunk' [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: == Spawn extension (from-internal, 8018031867, 6) exited non-zero on 'SIP/714-0000000f' [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] Hangup("SIP/714-0000000f", "") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/714-0000000f' [2014-05-20 14:14:06] VERBOSE[1921] pbx_spool.c: -- Attempting call on Local/[email protected] for application NoCDR() (Retry 1) [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] NoCDR("Local/[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:2] Set("Local/[email protected];2", "TCMAINT=RETURN") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:3] Gosub("Local/[email protected];2", "timeconditions,6,1()") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] GotoIfTime("Local/[email protected];2", "09:00-12:00,mon-fri,*,*?truestate") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "0?truegoto") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?Set(DB(TC/6)=)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC6)=INUSE") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:5] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:6] GotoIf("Local/[email protected];2", "0?timeconditions,7,1") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "TCSTATE=false") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:8] Return("Local/[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:4] Gosub("Local/[email protected];2", "timeconditions,8,1()") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] GotoIfTime("Local/[email protected];2", "00:00-23:59,sat-sun,*,*?truestate") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "0?truegoto") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?Set(DB(TC/8)=)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC8)=INUSE") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:5] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:6] GotoIf("Local/[email protected];2", "0?timeconditions,6,1") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "TCSTATE=false") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:8] Return("Local/[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:5] Gosub("Local/[email protected];2", "timeconditions,7,1()") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] GotoIfTime("Local/[email protected];2", "13:00-17:00,mon-fri,*,*?truestate") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Goto (timeconditions,7,9) [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:9] GotoIf("Local/[email protected];2", "0?falsegoto") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:10] ExecIf("Local/[email protected];2", "0?Set(DB(TC/7)=)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:11] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC7)=NOT_INUSE") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:12] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:13] GotoIf("Local/[email protected];2", "0?ext-group,601,1") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:14] Set("Local/[email protected];2", "TCSTATE=true") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:15] Return("Local/[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:6] Gosub("Local/[email protected];2", "timeconditions,9,1()") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] GotoIfTime("Local/[email protected];2", "12:00-12:59,*,*,*?truestate") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "0?truegoto") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?Set(DB(TC/9)=)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC9)=INUSE") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:5] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:6] GotoIf("Local/[email protected];2", "0?timeconditions,7,1") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "TCSTATE=false") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:8] Return("Local/[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:7] System("Local/[email protected];2", "/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 1") in new stack [2014-05-20 14:14:07] VERBOSE[1922] pbx.c: -- Executing [[email protected]:8] Answer("Local/[email protected];2", "") in new stack [2014-05-20 14:14:07] NOTICE[1921] pbx_spool.c: Call completed to Local/[email protected] [2014-05-20 14:14:07] VERBOSE[1922] pbx.c: == Spawn extension (tc-maint, s, 8) exited non-zero on 'Local/[email protected];2'

Some additional information:
I was using Zap trunks at first and was having the same issue. So I switched to DAHDI trunks (because they are the successor to Zap) and have the same problem. I do believe that my problem has to do with how the outbound routes search for an open trunk to use.

Here is a log snippet from the newer DAHDI trunks

[2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] Macro("SIP/714-0000000f", "user-callerid,LIMIT,") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] Set("SIP/714-0000000f", "AMPUSER=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] GotoIf("SIP/714-0000000f", "0?report") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]erid:3] ExecIf("SIP/714-0000000f", "1?Set(REALCALLERIDNUM=714)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:4] Set("SIP/714-0000000f", "AMPUSER=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:5] Set("SIP/714-0000000f", "AMPUSERCIDNAME=Legal") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:6] GotoIf("SIP/714-0000000f", "0?report") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:7] Set("SIP/714-0000000f", "AMPUSERCID=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:8] Set("SIP/714-0000000f", "CALLERID(all)="Legal" <714>") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/714-0000000f", "0?limit") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:10] ExecIf("SIP/714-0000000f", "1?Set(GROUP(concurrency_limit)=714)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:11] GosubIf("SIP/714-0000000f", "7?sub-ccss,s,1(from-internal,8018031867)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/714-0000000f", "0?Return()") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] Set("SIP/714-0000000f", "CCSS_SETUP=TRUE") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] GosubIf("SIP/714-0000000f", "0?monitor_config,1(from-internal,8018031867):monitor_default,1(from-internal,8018031867)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/714-0000000f", "0?is_exten") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] StackPop("SIP/714-0000000f", "") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] Return("SIP/714-0000000f", "FALSE") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:12] ExecIf("SIP/714-0000000f", "0?Set(CHANNEL(language)=)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:13] GotoIf("SIP/714-0000000f", "1?continue") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (macro-user-callerid,s,26) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:26] Set("SIP/714-0000000f", "CALLERID(number)=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:27] Set("SIP/714-0000000f", "CALLERID(name)=Legal") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:28] Set("SIP/714-0000000f", "CHANNEL(language)=en") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] Set("SIP/714-0000000f", "MOHCLASS=default") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] ExecIf("SIP/714-0000000f", "0?Set(TRUNKCIDOVERRIDE="McIntyre & Golden" <8012663399>)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:4] Set("SIP/714-0000000f", "_NODEST=") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:5] Gosub("SIP/714-0000000f", "sub-record-check,s,1(out,8018031867,)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] GotoIf("SIP/714-0000000f", "1?check") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (sub-record-check,s,6) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:6] Set("SIP/714-0000000f", "__MON_FMT=wav") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:7] GotoIf("SIP/714-0000000f", "1?next") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (sub-record-check,s,10) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:10] ExecIf("SIP/714-0000000f", "0?Return()") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:11] GotoIf("SIP/714-0000000f", "0?out,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:12] Set("SIP/714-0000000f", "__REC_STATUS=INITIALIZED") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:13] ExecIf("SIP/714-0000000f", "0?Set(__REC_POLICY_MODE=)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:14] Set("SIP/714-0000000f", "NOW=1400616843") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:15] Set("SIP/714-0000000f", "__DAY=20") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:16] Set("SIP/714-0000000f", "__MONTH=05") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:17] Set("SIP/714-0000000f", "__YEAR=2014") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:18] Set("SIP/714-0000000f", "__TIMESTR=20140520-141403") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:19] Set("SIP/714-0000000f", "__FROMEXTEN=714") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:20] Set("SIP/714-0000000f", "__CALLFILENAME=out-8018031867-714-20140520-141403-1400616843.276") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:21] Goto("SIP/714-0000000f", "out,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (sub-record-check,out,1) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/714-0000000f", "1?Set(__REC_POLICY_MODE=dontcare)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] GosubIf("SIP/714-0000000f", "0?record,1(exten,8018031867,714)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] Return("SIP/714-0000000f", "") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:6] Macro("SIP/714-0000000f", "dialout-trunk,1,8018031867,") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] Set("SIP/714-0000000f", "DIAL_TRUNK=1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] GosubIf("SIP/714-0000000f", "0?sub-pincheck,s,1()") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] GotoIf("SIP/714-0000000f", "0?disabletrunk,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:4] Set("SIP/714-0000000f", "DIAL_NUMBER=8018031867") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:5] Set("SIP/714-0000000f", "DIAL_TRUNK_OPTIONS=trwW") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:6] Set("SIP/714-0000000f", "OUTBOUND_GROUP=OUT_1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:7] GotoIf("SIP/714-0000000f", "0?nomax") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:8] GotoIf("SIP/714-0000000f", "0?chanfull") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/714-0000000f", "0?skipoutcid") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:10] Set("SIP/714-0000000f", "DIAL_TRUNK_OPTIONS=wW") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:11] Macro("SIP/714-0000000f", "outbound-callerid,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] ExecIf("SIP/714-0000000f", "0?Set(CALLERPRES()=)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] ExecIf("SIP/714-0000000f", "0?Set(REALCALLERIDNUM=714)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] GotoIf("SIP/714-0000000f", "1?normcid") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (macro-outbound-callerid,s,6) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:6] Set("SIP/714-0000000f", "USEROUTCID=8012663399") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:7] Set("SIP/714-0000000f", "EMERGENCYCID=") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:8] Set("SIP/714-0000000f", "TRUNKOUTCID="McIntyre & Golden"<8012663399>") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:9] GotoIf("SIP/714-0000000f", "1?trunkcid") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (macro-outbound-callerid,s,12) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:12] ExecIf("SIP/714-0000000f", "1?Set(CALLERID(all)="McIntyre & Golden"<8012663399>)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:13] ExecIf("SIP/714-0000000f", "1?Set(CALLERID(all)=8012663399)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:14] ExecIf("SIP/714-0000000f", "0?Set(CALLERID(all)=)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:15] ExecIf("SIP/714-0000000f", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:12] GosubIf("SIP/714-0000000f", "0?sub-flp-1,s,1()") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:13] Set("SIP/714-0000000f", "OUTNUM=w8018031867") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:14] Set("SIP/714-0000000f", "custom=DAHDI/1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:15] ExecIf("SIP/714-0000000f", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)wW)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:16] ExecIf("SIP/714-0000000f", "0?Set(DIAL_TRUNK_OPTIONS=wWM(confirm))") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:17] Macro("SIP/714-0000000f", "dialout-trunk-predial-hook,") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] MacroExit("SIP/714-0000000f", "") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:18] GotoIf("SIP/714-0000000f", "0?bypass,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:19] ExecIf("SIP/714-0000000f", "1?Set(CONNECTEDLINE(num,i)=8018031867)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:20] ExecIf("SIP/714-0000000f", "1?Set(CONNECTEDLINE(name,i)=CID:8012663399)") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:21] GotoIf("SIP/714-0000000f", "0?customtrunk") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:22] Dial("SIP/714-0000000f", "DAHDI/1/w8018031867,300,wW") in new stack [2014-05-20 14:14:03] WARNING[1909] app_dial.c: Unable to create channel of type 'DAHDI' (cause 17 - User busy) [2014-05-20 14:14:03] VERBOSE[1909] app_dial.c: == Everyone is busy/congested at this time (1:1/0/0) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:23] NoOp("SIP/714-0000000f", "Dial failed for some reason with DIALSTATUS = BUSY and HANGUPCAUSE = 17") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:24] Goto("SIP/714-0000000f", "s-BUSY,1") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Goto (macro-dialout-trunk,s-BUSY,1) [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] NoOp("SIP/714-0000000f", "Dial failed due to trunk reporting BUSY - giving up") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:2] PlayTones("SIP/714-0000000f", "busy") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:3] Busy("SIP/714-0000000f", "20") in new stack [2014-05-20 14:14:03] VERBOSE[1909] app_macro.c: == Spawn extension (macro-dialout-trunk, s-BUSY, 3) exited non-zero on 'SIP/714-0000000f' in macro 'dialout-trunk' [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: == Spawn extension (from-internal, 8018031867, 6) exited non-zero on 'SIP/714-0000000f' [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: -- Executing [[email protected]:1] Hangup("SIP/714-0000000f", "") in new stack [2014-05-20 14:14:03] VERBOSE[1909] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/714-0000000f' [2014-05-20 14:14:06] VERBOSE[1921] pbx_spool.c: -- Attempting call on Local/[email protected] for application NoCDR() (Retry 1) [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] NoCDR("Local/[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:2] Set("Local/[email protected];2", "TCMAINT=RETURN") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:3] Gosub("Local/[email protected];2", "timeconditions,6,1()") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] GotoIfTime("Local/[email protected];2", "09:00-12:00,mon-fri,*,*?truestate") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "0?truegoto") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?Set(DB(TC/6)=)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC6)=INUSE") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:5] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:6] GotoIf("Local/[email protected];2", "0?timeconditions,7,1") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "TCSTATE=false") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:8] Return("Local/[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:4] Gosub("Local/[email protected];2", "timeconditions,8,1()") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] GotoIfTime("Local/[email protected];2", "00:00-23:59,sat-sun,*,*?truestate") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "0?truegoto") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?Set(DB(TC/8)=)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC8)=INUSE") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:5] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:6] GotoIf("Local/[email protected];2", "0?timeconditions,6,1") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "TCSTATE=false") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:8] Return("Local/s[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:5] Gosub("Local/[email protected];2", "timeconditions,7,1()") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] GotoIfTime("Local/[email protected];2", "13:00-17:00,mon-fri,*,*?truestate") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Goto (timeconditions,7,9) [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:9] GotoIf("Local/[email protected];2", "0?falsegoto") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:10] ExecIf("Local/[email protected];2", "0?Set(DB(TC/7)=)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:11] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC7)=NOT_INUSE") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:12] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:13] GotoIf("Local/[email protected];2", "0?ext-group,601,1") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:14] Set("Local/[email protected];2", "TCSTATE=true") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:15] Return("Local/[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:6] Gosub("Local/[email protected];2", "timeconditions,9,1()") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:1] GotoIfTime("Local/[email protected];2", "12:00-12:59,*,*,*?truestate") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "0?truegoto") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?Set(DB(TC/9)=)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:4] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC9)=INUSE") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:5] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:6] GotoIf("Local/[email protected];2", "0?timeconditions,7,1") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:7] Set("Local/[email protected];2", "TCSTATE=false") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:8] Return("Local/[email protected];2", "") in new stack [2014-05-20 14:14:06] VERBOSE[1922] pbx.c: -- Executing [[email protected]:7] System("Local/[email protected];2", "/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 1") in new stack [2014-05-20 14:14:07] VERBOSE[1922] pbx.c: -- Executing [[email protected]:8] Answer("Local/[email protected];2", "") in new stack [2014-05-20 14:14:07] NOTICE[1921] pbx_spool.c: Call completed to Local/[email protected] [2014-05-20 14:14:07] VERBOSE[1922] pbx.c: == Spawn extension (tc-maint, s, 8) exited non-zero on 'Local/[email protected];2'