1 out of each 10 calls from twilio keep failing

I keep having this weird issue were approximately 1 out of 10 calls to from a twilio trunk into Astrix fails. I have already added all the twilio service IP addreses but it still happens. Any Ideas?

Not without logs for a failed call.

How do I enable\tail the logs

Here we ago. Attached is a log file the first portion shows a failed call. to number 602-362-7646. A minute later I made another call to the same number and call connected successfully

phone number 602-362-7646

Failed call

[2018-04-20 11:48:23] VERBOSE[2086][C-000000de] netsock2.c: == Using SIP RTP TOS bits 184
[2018-04-20 11:48:23] VERBOSE[2086][C-000000de] netsock2.c: == Using SIP RTP CoS mark 5
[2018-04-20 11:48:23] NOTICE[2086][C-000000de] chan_sip.c: Call from '54.172.60.2 ’ (54.172.60.2:5060) to extension ‘+16023627646’ rejected because extension not found in context ‘from-trunk-sip-54172.60.2’

success call

[2018-04-20 11:54:18] VERBOSE[2086][C-000000df] netsock2.c: == Using SIP RTP CoS mark 5
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [[email protected]:1] Set(“SIP/54.172.60.1-00000034”, “GROUP()=OUT_6”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [[email protected]:2] Goto(“SIP/54.172.60.1-00000034”, “from-trunk,+16023627646,1”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (from-trunk,+16023627646,1)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:1] Set(“SIP/54.172.60.1-00000034”, “__DIRECTION=INBOUND”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:2] Gosub(“SIP/54.172.60.1-00000034”, “sub-record-check,s,1(in,+16023627646,dontcare)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:1] GotoIf(“SIP/54.172.60.1-00000034”, “0?initialized”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:2] Set(“SIP/54.172.60.1-00000034”, “__REC_STATUS=INITIALIZED”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:3] Set(“SIP/54.172.60.1-00000034”, “NOW=1524250458”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:4] Set(“SIP/54.172.60.1-00000034”, “__DAY=20”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:5] Set(“SIP/54.172.60.1-00000034”, “__MONTH=04”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:6] Set(“SIP/54.172.60.1-00000034”, “__YEAR=2018”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:7] Set(“SIP/54.172.60.1-00000034”, “__TIMESTR=20180420-115418”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:8] Set(“SIP/54.172.60.1-00000034”, “__FROMEXTEN=unknown”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:9] Set(“SIP/54.172.60.1-00000034”, “__MON_FMT=wav”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:10] NoOp(“SIP/54.172.60.1-00000034”, “Recordings initialized”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(ARG3=dontcare)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:12] Set(“SIP/54.172.60.1-00000034”, “REC_POLICY_MODE_SAVE=”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:13] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(REC_STATUS=NO)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:14] GotoIf(“SIP/54.172.60.1-00000034”, “2?checkaction”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (sub-record-check,s,17)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:17] GotoIf(“SIP/54.172.60.1-00000034”, “1?sub-record-check,in,1”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (sub-record-check,in,1)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [in@sub-record-check:1] NoOp(“SIP/54.172.60.1-00000034”, “Inbound Recording Check to +16023627646”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [in@sub-record-check:2] Set(“SIP/54.172.60.1-00000034”, “FROMEXTEN=unknown”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [in@sub-record-check:3] ExecIf(“SIP/54.172.60.1-00000034”, “12?Set(FROMEXTEN=+14808622782)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [in@sub-record-check:4] Gosub(“SIP/54.172.60.1-00000034”, “recordcheck,1(dontcare,in,+16023627646)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [recordcheck@sub-record-check:1] NoOp(“SIP/54.172.60.1-00000034”, “Starting recording check against dontcare”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [recordcheck@sub-record-check:2] Goto(“SIP/54.172.60.1-00000034”, “dontcare”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (sub-record-check,recordcheck,3)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [recordcheck@sub-record-check:3] Return(“SIP/54.172.60.1-00000034”, “”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [in@sub-record-check:5] Return(“SIP/54.172.60.1-00000034”, “”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:3] Gosub(“SIP/54.172.60.1-00000034”, “app-blacklist-check,s,1()”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“SIP/54.172.60.1-00000034”, “0?blacklisted”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@app-blacklist-check:2] Set(“SIP/54.172.60.1-00000034”, “CALLED_BLACKLIST=1”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@app-blacklist-check:3] Return(“SIP/54.172.60.1-00000034”, “”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:4] Set(“SIP/54.172.60.1-00000034”, “__FROM_DID=+16023627646”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:5] Set(“SIP/54.172.60.1-00000034”, “CDR(did)=+16023627646”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:6] ExecIf(“SIP/54.172.60.1-00000034”, “1 ?Set(CALLERID(name)=+14808622782)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:7] Set(“SIP/54.172.60.1-00000034”, “__MOHCLASS=”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:8] Set(“SIP/54.172.60.1-00000034”, “__REVERSAL_REJECT=FALSE”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:9] GotoIf(“SIP/54.172.60.1-00000034”, “1?post-reverse-charge”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (from-trunk,+16023627646,11)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:11] NoOp(“SIP/54.172.60.1-00000034”, “”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:12] Set(“SIP/54.172.60.1-00000034”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:13] Set(“SIP/54.172.60.1-00000034”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:14] Set(“SIP/54.172.60.1-00000034”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:15] Set(“SIP/54.172.60.1-00000034”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:16] NoOp(“SIP/54.172.60.1-00000034”, “CallerID Entry Point”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:17] Set(“SIP/54.172.60.1-00000034”, “__CRM_DIRECTION=INBOUND”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:18] Set(“SIP/54.172.60.1-00000034”, “__CRM_SOURCE=+14808622782”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:19] Set(“SIP/54.172.60.1-00000034”, “__CRM_LINKEDID=1524250458.52”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:20] ExecIf(“SIP/54.172.60.1-00000034”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [+16023627646@from-trunk:21] Goto(“SIP/54.172.60.1-00000034”, “ext-miscdests,2,1”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (ext-miscdests,2,1)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [2@ext-miscdests:1] NoOp(“SIP/54.172.60.1-00000034”, "MiscDest: Zeacom Main AA ") in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [2@ext-miscdests:2] Goto(“SIP/54.172.60.1-00000034”, “from-internal,1005,1”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (from-internal,1005,1)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [1005@from-internal:1] Macro(“SIP/54.172.60.1-00000034”, “user-callerid,LIMIT,EXTERNAL,”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/54.172.60.1-00000034”, “TOUCH_MONITOR=1524250458.52”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:2] Set(“SIP/54.172.60.1-00000034”, “AMPUSER=+14808622782”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/54.172.60.1-00000034”, “0?report”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:4] ExecIf(“SIP/54.172.60.1-00000034”, “1?Set(REALCALLERIDNUM=+14808622782)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/54.172.60.1-00000034”, “AMPUSER=”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/54.172.60.1-00000034”, “0?limit”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:7] Set(“SIP/54.172.60.1-00000034”, “AMPUSERCIDNAME=”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:8] GotoIf(“SIP/54.172.60.1-00000034”, “1?report”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (macro-user-callerid,s,15)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:15] NoOp(“SIP/54.172.60.1-00000034”, “Macro Depth is 1”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:16] GotoIf(“SIP/54.172.60.1-00000034”, “1?report2:macroerror”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (macro-user-callerid,s,18)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:18] GotoIf(“SIP/54.172.60.1-00000034”, “1?continue”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (macro-user-callerid,s,36)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:36] Set(“SIP/54.172.60.1-00000034”, “CALLERID(number)=+14808622782”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:37] Set(“SIP/54.172.60.1-00000034”, “CALLERID(name)=+14808622782”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:38] GotoIf(“SIP/54.172.60.1-00000034”, “0?cnum”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:39] Set(“SIP/54.172.60.1-00000034”, “CDR(cnam)=+14808622782”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:40] Set(“SIP/54.172.60.1-00000034”, “CDR(cnum)=+14808622782”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-user-callerid:41] Set(“SIP/54.172.60.1-00000034”, “CHANNEL(language)=en”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [1005@from-internal:2] Gosub(“SIP/54.172.60.1-00000034”, “sub-record-check,s,1(out,1005,dontcare)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:1] GotoIf(“SIP/54.172.60.1-00000034”, “12?initialized”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (sub-record-check,s,10)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:10] NoOp(“SIP/54.172.60.1-00000034”, “Recordings initialized”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(ARG3=dontcare)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:12] Set(“SIP/54.172.60.1-00000034”, “REC_POLICY_MODE_SAVE=”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:13] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(REC_STATUS=NO)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:14] GotoIf(“SIP/54.172.60.1-00000034”, “3?checkaction”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (sub-record-check,s,17)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@sub-record-check:17] GotoIf(“SIP/54.172.60.1-00000034”, “1?sub-record-check,out,1”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (sub-record-check,out,1)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [out@sub-record-check:1] NoOp(“SIP/54.172.60.1-00000034”, “Outbound Recording Check from +14808622782 to 1005”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [out@sub-record-check:2] Set(“SIP/54.172.60.1-00000034”, “RECMODE=”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [out@sub-record-check:3] ExecIf(“SIP/54.172.60.1-00000034”, “1?Goto(routewins)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (sub-record-check,out,7)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [out@sub-record-check:7] Gosub(“SIP/54.172.60.1-00000034”, “recordcheck,1(dontcare,out,1005)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [recordcheck@sub-record-check:1] NoOp(“SIP/54.172.60.1-00000034”, “Starting recording check against dontcare”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [recordcheck@sub-record-check:2] Goto(“SIP/54.172.60.1-00000034”, “dontcare”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (sub-record-check,recordcheck,3)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [recordcheck@sub-record-check:3] Return(“SIP/54.172.60.1-00000034”, “”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [out@sub-record-check:8] Return(“SIP/54.172.60.1-00000034”, “”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [1005@from-internal:3] ExecIf(“SIP/54.172.60.1-00000034”, “0 ?Set(CDR(accountcode)=)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [1005@from-internal:4] Set(“SIP/54.172.60.1-00000034”, “MOHCLASS=default”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [1005@from-internal:5] Set(“SIP/54.172.60.1-00000034”, “_NODEST=”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [1005@from-internal:6] Macro(“SIP/54.172.60.1-00000034”, “dialout-trunk,3,1005,off”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/54.172.60.1-00000034”, “DIAL_TRUNK=3”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/54.172.60.1-00000034”, “0?sub-pincheck,s,1()”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/54.172.60.1-00000034”, “0?disabletrunk,1”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:4] Set(“SIP/54.172.60.1-00000034”, “DIAL_NUMBER=1005”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/54.172.60.1-00000034”, “DIAL_TRUNK_OPTIONS=Ttr”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/54.172.60.1-00000034”, “OUTBOUND_GROUP=OUT_3”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:7] Set(“SIP/54.172.60.1-00000034”, “DIAL_TRUNK_OPTIONS=T”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:8] GotoIf(“SIP/54.172.60.1-00000034”, “1?nomax”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (macro-dialout-trunk,s,10)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:10] GotoIf(“SIP/54.172.60.1-00000034”, “0?skipoutcid”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/54.172.60.1-00000034”, “outbound-callerid,3”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/54.172.60.1-00000034”, “1?Set(CALLERPRES(name-pres)=allowed_not_screened)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/54.172.60.1-00000034”, “1?Set(CALLERPRES(num-pres)=allowed_not_screened)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:3] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(REALCALLERIDNUM=+14808622782)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:4] GotoIf(“SIP/54.172.60.1-00000034”, “1?normcid”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (macro-outbound-callerid,s,7)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:7] Set(“SIP/54.172.60.1-00000034”, “USEROUTCID=”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:8] Set(“SIP/54.172.60.1-00000034”, “EMERGENCYCID=”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:9] Set(“SIP/54.172.60.1-00000034”, “TRUNKOUTCID=”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:10] GotoIf(“SIP/54.172.60.1-00000034”, “1?trunkcid”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (macro-outbound-callerid,s,15)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(CALLERID(all)=)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:16] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(CALLERID(all)=)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:17] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(CALLERID(all)=)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:18] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(CALLERPRES(name-pres)=prohib_passed_screen)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:19] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(CALLERPRES(num-pres)=prohib_passed_screen)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:20] ExecIf(“SIP/54.172.60.1-00000034”, “1?Set(CALLERID(name)=)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:21] Set(“SIP/54.172.60.1-00000034”, “CDR(outbound_cnum)=+14808622782”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-outbound-callerid:22] Set(“SIP/54.172.60.1-00000034”, “CDR(outbound_cnam)=”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:12] GosubIf(“SIP/54.172.60.1-00000034”, “0?sub-flp-3,s,1()”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/54.172.60.1-00000034”, “OUTNUM=1005”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/54.172.60.1-00000034”, “custom=SIP/Trunk to cucm”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:16] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:17] Macro(“SIP/54.172.60.1-00000034”, “dialout-trunk-predial-hook,”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/54.172.60.1-00000034”, “”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/54.172.60.1-00000034”, “1?skipcrm”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Goto (macro-dialout-trunk,s,24)
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:24] NoOp(“SIP/54.172.60.1-00000034”, “CRM Finished”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:25] GotoIf(“SIP/54.172.60.1-00000034”, “0?bypass,1”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:26] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(CONNECTEDLINE(num,i)=1005)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:27] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(CONNECTEDLINE(name,i)=CID:+14808622782)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:28] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)+14808622782)”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:29] GotoIf(“SIP/54.172.60.1-00000034”, “0?customtrunk”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-dialout-trunk:30] Dial(“SIP/54.172.60.1-00000034”, “SIP/Trunk to cucm/1005,300,T”) in new stack
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] netsock2.c: == Using SIP RTP TOS bits 184
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] netsock2.c: == Using SIP RTP CoS mark 5
[2018-04-20 11:54:18] VERBOSE[12998][C-000000df] app_dial.c: – Called SIP/Trunk to cucm/1005
[2018-04-20 11:54:19] VERBOSE[12998][C-000000df] app_dial.c: – SIP/Trunk to cucm-00000035 is ringing
[2018-04-20 11:54:19] VERBOSE[12998][C-000000df] app_dial.c: – SIP/Trunk to cucm-00000035 answered SIP/54.172.60.1-00000034
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: – Executing [h@macro-dialout-trunk:1] Macro(“SIP/54.172.60.1-00000034”, “hangupcall,”) in new stack
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-hangupcall:1] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(CDR(recordingfile)=.wav)”) in new stack
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-hangupcall:2] GotoIf(“SIP/54.172.60.1-00000034”, “1?theend”) in new stack
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: – Goto (macro-hangupcall,s,4)
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-hangupcall:4] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(CDR(recordingfile)=)”) in new stack
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@macro-hangupcall:5] Hangup(“SIP/54.172.60.1-00000034”, “”) in new stack
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] app_macro.c: == Spawn extension (macro-hangupcall, s, 5) exited non-zero on ‘SIP/54.172.60.1-00000034’ in macro ‘hangupcall’
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on ‘SIP/54.172.60.1-00000034’
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] app_stack.c: – SIP/54.172.60.1-00000034 Internal Gosub(crm-hangup,s,1) start
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@crm-hangup:1] NoOp(“SIP/54.172.60.1-00000034”, “Sending Hangup to CRM”) in new stack
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@crm-hangup:2] NoOp(“SIP/54.172.60.1-00000034”, “HANGUP CAUSE: 16”) in new stack
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@crm-hangup:3] ExecIf(“SIP/54.172.60.1-00000034”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@crm-hangup:4] NoOp(“SIP/54.172.60.1-00000034”, “MASTER CHANNEL: 1524250458.52 = 1524250458.52”) in new stack
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@crm-hangup:5] GotoIf(“SIP/54.172.60.1-00000034”, “0?return”) in new stack
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@crm-hangup:6] Set(“SIP/54.172.60.1-00000034”, “__CRM_HANGUP=1”) in new stack
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@crm-hangup:7] AGI(“SIP/54.172.60.1-00000034”, “sangomacrm.agi”) in new stack
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] res_agi.c: – <SIP/54.172.60.1-00000034>AGI Script sangomacrm.agi completed, returning 0
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: – Executing [s@crm-hangup:8] Return(“SIP/54.172.60.1-00000034”, “”) in new stack
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] app_stack.c: == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on ‘SIP/54.172.60.1-00000034’
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] app_stack.c: – SIP/54.172.60.1-00000034 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] app_macro.c: == Spawn extension (macro-dialout-trunk, s, 30) exited non-zero on ‘SIP/54.172.60.1-00000034’ in macro ‘dialout-trunk’
[2018-04-20 11:54:25] VERBOSE[12998][C-000000df] pbx.c: == Spawn extension (from-internal, 1005, 6) exited non-zero on ‘SIP/54.172.60.1-00000034’

In the first case, the ‘54172.60.2’ has a dot missing. If you entered that manually, see whether fixing it cures the problem. If not, please explain how you handle the multiple source addresses (separate trunks, listing the addresses in Match, something else?)

This could also be a DNS failure. If your DNS has an invalid entry in the local DNS, it could also cause this.

How do I check this?

I have each trunk configure separately is there a better way to do this. Attach is how I have it configure. The one in question is configure the same as all others.

It was the call sent from 54.172.60.2 that failed. I suspected that the settings for that trunk had a typo because the error message referred to from-trunk-sip-54172.60.2 (no dot between the 54 and the 172). If you’re sure that you didn’t enter 54172 anywhere, it might be a bug. You could try
grep -R 54172 /etc/asterisk
to see whether and where this number is in your config.

With a pjsip trunk, you can allow calls from multiple addresses by simply listing them in the Match field.

For a chan_sip trunk, you can define the trunk with one address and add two lines to sip_custom.conf for each additional host, similar to what is shown in https://www.callcentric.com/support/device/asterisk/14 .

1 Like


I ran this command and got no result back grep -R 54172 /etc/asterisk

so I updated al the modules because they were out of date to see if it fix the issue made a test call and got the same from another port and I have that IP on the trunk lis

[2018-04-21 17:32:49] VERBOSE[2086][C-00000339] netsock2.c: == Using SIP RTP TOS bits 184
[2018-04-21 17:32:49] VERBOSE[2086][C-00000339] netsock2.c: == Using SIP RTP CoS mark 5
[2018-04-21 17:32:49] NOTICE[2086][C-00000339] chan_sip.c: Call from '54.172.60.3 ’ (54.172.60.3:5060) to extens ion ‘+16023627646’ rejected because extension not found in context ‘from-trunk-sip-54.172.60.3’

We see you have cucm involved, please explain how that is integrated with twilio. Your “trunk name” could also be adjusted to prevent further confusion

When the calls come in from the specific twilio number they are routed to a misc destination that points to an extension in my cucm. Internal call between twilio extension and cucm extension never failed only when coming via twilio.

I know its been a while but can I get some help I am still having the same issue.

This topic was automatically closed 365 days after the last reply. New replies are no longer allowed.