Unable to create channel of type 'SIP' (cause 20 - Subscriber absent)

mgrant · November 29, 2015, 12:11am

I had FreePBX partly working and I seem to have broken something! I was able to call from one extension to another and from an extension to the call group (100) which hits all extensions. Now I can’t even do that and in the logs I see:

Unable to create channel of type ‘SIP’ (cause 20 - Subscriber absent)

Having searched extensively for this error, it seems it’s mostly associated with registration problems. However, both my extensions (101 and 102) and all my trunks are registered. Furthermore, I can see logging coming out in the log file when I try to dial outbound and inbound from my mobile.

On calls from say extension 102 to call group 100, I see this in the log:

[2015-11-28 22:41:15] VERBOSE[17808][C-00000055] pbx.c:     -- Executing [s@macro-dial:7] Dial("SIP/102-00000060", "SIP/101&SIP/102,20,TtrM(auto-blkvm)") in new stack
[2015-11-28 22:41:15] WARNING[17808][C-00000055] app_dial.c: Unable to create channel of type 'SIP' (cause 20 - Subscriber absent)
[2015-11-28 22:41:15] WARNING[17808][C-00000055] app_dial.c: Unable to create channel of type 'SIP' (cause 20 - Subscriber absent)
[2015-11-28 22:41:15] VERBOSE[17808][C-00000055] app_dial.c:   == Everyone is busy/congested at this time (2:0/0/2)

sip_additional.conf:

[101]
deny=0.0.0.0/0.0.0.0
secret=xyz
dtmfmode=rfc2833
canreinvite=no
context=from-internal
host=dynamic
trustrpid=yes
mediaencryption=no
sendrpid=no
type=friend
nat=force_rport,comedia
port=5060
qualify=no
qualifyfreq=60
transport=udp,tcp,tls
avpf=no
force_avp=no
icesupport=no
encryption=no
callgroup=
pickupgroup=
dial=SIP/101
permit=0.0.0.0/0.0.0.0
callerid=101 <101>
callcounter=yes
faxdetect=no

[102]
deny=0.0.0.0/0.0.0.0
secret=xyz
dtmfmode=rfc2833
canreinvite=no
context=from-internal
host=dynamic
trustrpid=yes
mediaencryption=no
sendrpid=no
type=friend
nat=force_rport,comedia
port=5060
qualify=no
qualifyfreq=60
transport=udp,tcp,tls
avpf=no
force_avp=no
icesupport=no
encryption=no
callgroup=
pickupgroup=
dial=SIP/102
permit=0.0.0.0/0.0.0.0
callerid=102 <102>
callcounter=yes
faxdetect=no

[Fone]
host=***provider ip address***
defaultuser=***userid***
secret=***password***
type=peer
context=from-trunk-sip-Fone

[OVH_FR]
host=***provider ip address***
defaultuser=***userid***
secret=***password***
type=peer
context=from-trunk-sip-OVH_FR

[OVH_UK]
host=***provider ip address***
defaultuser=***userid***
secret=***password***
type=peer
context=

sip_general_additional.conf:

vmexten=*97
context=from-sip-external
callerid=Unknown
notifyringing=yes
notifyhold=yes
tos_sip=cs3
tos_audio=ef
tos_video=af41
alwaysauthreject=yes
useragent=FPBX-12.0.76.2(11.20.0)
disallow=all
allow=ulaw
allow=alaw
allow=gsm
allow=g726
rtpend=20000
callevents=no
rtpstart=10000
bindport=5060
jbenable=no
registertimeout=20
registerattempts=0
rtpholdtimeout=300
allowguest=yes
rtpkeepalive=0
rtptimeout=30
srvlookup=no
notifyringing=yes
notifyhold=yes
canreinvite=no
checkmwi=10
defaultexpiry=120
videosupport=no
g726nonstandard=no
maxcallbitrate=384
maxexpiry=3600
minexpiry=60
nat=yes
externhost=example.dyndns.org
externrefresh=120
ALLOW_SIP_ANON=no
localnet=192.168.0.0/16

On the SIP Info page, all 3 trunks and 2 extensions show as registered. The extensions show registered on the phone base and the trunks show registered on their respective provider websites.

What other conf files would be useful to see? It’s quite difficult to copy/paste things off the web page.

mgrant · November 29, 2015, 10:44am

An update on this…

After going to bed last night in total frustration, I woke up this morning to discover that I can now call internally! I can call from 101 to 102 and visa-versa and also call 100 to ring all extensions. I can even receive calls from the 3 trunks.

However, I cannot make outbound calls. All outbound calls end up with the message …all circuits busy now please try your call again later.

Here’s what the log shows when I try to call my mobile number from extension 102:

[2015-11-29 10:30:21] VERBOSE[1443][C-00000008] netsock2.c:   == Using SIP RTP TOS bits 184
[2015-11-29 10:30:21] VERBOSE[1443][C-00000008] netsock2.c:   == Using SIP RTP CoS mark 5
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [07891234567@from-internal:1] Macro("SIP/102-00000011", "user-callerid,LIMIT,EXTERNAL,") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:1] Set("SIP/102-00000011", "TOUCH_MONITOR=1448793021.17") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:2] Set("SIP/102-00000011", "AMPUSER=102") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:3] GotoIf("SIP/102-00000011", "0?report") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:4] ExecIf("SIP/102-00000011", "1?Set(REALCALLERIDNUM=102)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:5] Set("SIP/102-00000011", "AMPUSER=102") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:6] GotoIf("SIP/102-00000011", "0?limit") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:7] Set("SIP/102-00000011", "AMPUSERCIDNAME=102") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:8] GotoIf("SIP/102-00000011", "0?report") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:9] Set("SIP/102-00000011", "AMPUSERCID=102") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:10] Set("SIP/102-00000011", "__DIAL_OPTIONS=Ttr") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:11] Set("SIP/102-00000011", "CALLERID(all)="102" <102>") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:12] GotoIf("SIP/102-00000011", "0?limit") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:13] ExecIf("SIP/102-00000011", "1?Set(GROUP(concurrency_limit)=102)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:14] GotoIf("SIP/102-00000011", "1?continue") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Goto (macro-user-callerid,s,27)
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:27] Set("SIP/102-00000011", "CALLERID(number)=102") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:28] Set("SIP/102-00000011", "CALLERID(name)=102") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:29] Set("SIP/102-00000011", "CDR(cnum)=102") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:30] Set("SIP/102-00000011", "CDR(cnam)=102") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-user-callerid:31] Set("SIP/102-00000011", "CHANNEL(language)=en") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [07891234567@from-internal:2] Gosub("SIP/102-00000011", "sub-record-check,s,1(out,07891234567,dontcare)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:1] GotoIf("SIP/102-00000011", "0?initialized") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:2] Set("SIP/102-00000011", "__REC_STATUS=INITIALIZED") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:3] Set("SIP/102-00000011", "NOW=1448793021") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:4] Set("SIP/102-00000011", "__DAY=29") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:5] Set("SIP/102-00000011", "__MONTH=11") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:6] Set("SIP/102-00000011", "__YEAR=2015") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:7] Set("SIP/102-00000011", "__TIMESTR=20151129-103021") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:8] Set("SIP/102-00000011", "__FROMEXTEN=102") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:9] Set("SIP/102-00000011", "__MON_FMT=wav") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:10] NoOp("SIP/102-00000011", "Recordings initialized") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:11] ExecIf("SIP/102-00000011", "0?Set(ARG3=dontcare)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:12] Set("SIP/102-00000011", "REC_POLICY_MODE_SAVE=") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:13] ExecIf("SIP/102-00000011", "0?Set(REC_STATUS=NO)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:14] GotoIf("SIP/102-00000011", "3?checkaction") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Goto (sub-record-check,s,17)
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@sub-record-check:17] GotoIf("SIP/102-00000011", "1?sub-record-check,out,1") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Goto (sub-record-check,out,1)
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [out@sub-record-check:1] NoOp("SIP/102-00000011", "Outbound Recording Check from 102 to 07891234567") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [out@sub-record-check:2] Set("SIP/102-00000011", "RECMODE=dontcare") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [out@sub-record-check:3] ExecIf("SIP/102-00000011", "1?Goto(routewins)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Goto (sub-record-check,out,7)
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [out@sub-record-check:7] Gosub("SIP/102-00000011", "recordcheck,1(dontcare,out,07891234567)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/102-00000011", "Starting recording check against dontcare") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [recordcheck@sub-record-check:2] Goto("SIP/102-00000011", "dontcare") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Goto (sub-record-check,recordcheck,3)
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [recordcheck@sub-record-check:3] Return("SIP/102-00000011", "") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [out@sub-record-check:8] Return("SIP/102-00000011", "") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [07891234567@from-internal:3] Set("SIP/102-00000011", "MOHCLASS=default") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [07891234567@from-internal:4] ExecIf("SIP/102-00000011", "1?Set(TRUNKCIDOVERRIDE=00442031234567)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [07891234567@from-internal:5] Set("SIP/102-00000011", "_NODEST=") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [07891234567@from-internal:6] Macro("SIP/102-00000011", "dialout-trunk,3,07891234567,,off") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:1] Set("SIP/102-00000011", "DIAL_TRUNK=3") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/102-00000011", "0?sub-pincheck,s,1()") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/102-00000011", "0?disabletrunk,1") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:4] Set("SIP/102-00000011", "DIAL_NUMBER=07891234567") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:5] Set("SIP/102-00000011", "DIAL_TRUNK_OPTIONS=Ttr") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:6] Set("SIP/102-00000011", "OUTBOUND_GROUP=OUT_3") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/102-00000011", "0?nomax") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:8] GotoIf("SIP/102-00000011", "0?chanfull") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/102-00000011", "0?skipoutcid") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:10] Set("SIP/102-00000011", "DIAL_TRUNK_OPTIONS=Tt") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:11] Macro("SIP/102-00000011", "outbound-callerid,3") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/102-00000011", "0?Set(CALLERPRES()=)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/102-00000011", "0?Set(REALCALLERIDNUM=102)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/102-00000011", "1?normcid") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Goto (macro-outbound-callerid,s,6)
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outbound-callerid:6] Set("SIP/102-00000011", "USEROUTCID=") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outbound-callerid:7] Set("SIP/102-00000011", "EMERGENCYCID=") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outbound-callerid:8] Set("SIP/102-00000011", "TRUNKOUTCID=00442031234567") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/102-00000011", "1?trunkcid") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Goto (macro-outbound-callerid,s,14)
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/102-00000011", "1?Set(CALLERID(all)=00442031234567)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outbound-callerid:15] ExecIf("SIP/102-00000011", "0?Set(CALLERID(all)=)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outbound-callerid:16] ExecIf("SIP/102-00000011", "1?Set(CALLERID(all)=00442031234567)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outbound-callerid:17] ExecIf("SIP/102-00000011", "0?Set(CALLERPRES()=prohib_passed_screen)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outbound-callerid:18] Set("SIP/102-00000011", "CDR(outbound_cnum)=00442031234567") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outbound-callerid:19] Set("SIP/102-00000011", "CDR(outbound_cnam)=") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:12] GosubIf("SIP/102-00000011", "0?sub-flp-3,s,1()") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:13] Set("SIP/102-00000011", "OUTNUM=07891234567") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:14] Set("SIP/102-00000011", "custom=SIP/OVH_UK") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/102-00000011", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:16] ExecIf("SIP/102-00000011", "0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:17] Macro("SIP/102-00000011", "dialout-trunk-predial-hook,") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/102-00000011", "") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/102-00000011", "0?bypass,1") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:19] ExecIf("SIP/102-00000011", "1?Set(CONNECTEDLINE(num,i)=07891234567)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:20] ExecIf("SIP/102-00000011", "1?Set(CONNECTEDLINE(name,i)=CID:00442031234567)") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:21] GotoIf("SIP/102-00000011", "0?customtrunk") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:22] Dial("SIP/102-00000011", "SIP/OVH_UK/07891234567,300,Tt") in new stack
[2015-11-29
 10:30:21] WARNING[27809][C-00000008] app_dial.c: Unable to create 
channel of type 'SIP' (cause 20 - Subscriber absent)
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] app_dial.c:   == Everyone is busy/congested at this time (1:0/0/1)
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:23] NoOp("SIP/102-00000011", "Dial failed for some reason with DIALSTATUS = CHANUNAVAIL and HANGUPCAUSE = 20") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-dialout-trunk:24] GotoIf("SIP/102-00000011", "0?continue,1:s-CHANUNAVAIL,1") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s-CHANUNAVAIL@macro-dialout-trunk:1] Set("SIP/102-00000011", "RC=20") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s-CHANUNAVAIL@macro-dialout-trunk:2] Goto("SIP/102-00000011", "20,1") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Goto (macro-dialout-trunk,20,1)
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [20@macro-dialout-trunk:1] Goto("SIP/102-00000011", "continue,1") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Goto (macro-dialout-trunk,continue,1)
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [continue@macro-dialout-trunk:1] NoOp("SIP/102-00000011", "TRUNK Dial failed due to CHANUNAVAIL HANGUPCAUSE: 20 - failing through to other trunks") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [continue@macro-dialout-trunk:2] Set("SIP/102-00000011", "CALLERID(number)=102") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [07891234567@from-internal:7] Macro("SIP/102-00000011", "outisbusy,") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outisbusy:1] Progress("SIP/102-00000011", "") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outisbusy:2] Playback("SIP/102-00000011", "all-circuits-busy-now,noanswer") in new stack
[2015-11-29 10:30:21] VERBOSE[27809][C-00000008] file.c:     --  Playing 'all-circuits-busy-now.ulaw' (language 'en')
[2015-11-29 10:30:23] VERBOSE[27809][C-00000008] pbx.c:     -- Executing [s@macro-outisbusy:3] Playback("SIP/102-00000011", "pls-try-call-later,noanswer") in new stack
[2015-11-29 10:30:23] VERBOSE[27809][C-00000008] file.c:     --  Playing 'pls-try-call-later.ulaw' (language 'en')