Outgoing call to one number not delivered to trunk provider

FreePBX
1

When calling 5123535115 from my system I get an error message that the call cannot be completed at this time. The trunk provider says the call never hit their system. We can call other numbers without issue. I am unable to find a reason for this. The log output is below:

[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-user-callerid:31] Set(“SIP/101-00004a73”, “CALLERID(name)=Mark”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-user-callerid:32] Set(“SIP/101-00004a73”, “CDR(cnum)=101”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-user-callerid:33] Set(“SIP/101-00004a73”, “CDR(cnam)=Mark”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-user-callerid:34] Set(“SIP/101-00004a73”, “CHANNEL(language)=en”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [5123535115@from-internal:2] Gosub(“SIP/101-00004a73”, “sub-record-check,s,1(out,5123535115,dontcare)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:1] GotoIf(“SIP/101-00004a73”, “0?initialized”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:2] Set(“SIP/101-00004a73”, “__REC_STATUS=INITIALIZED”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:3] Set(“SIP/101-00004a73”, “NOW=1562599514”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:4] Set(“SIP/101-00004a73”, “__DAY=08”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:5] Set(“SIP/101-00004a73”, “__MONTH=07”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:6] Set(“SIP/101-00004a73”, “__YEAR=2019”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:7] Set(“SIP/101-00004a73”, “__TIMESTR=20190708-102514”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:8] Set(“SIP/101-00004a73”, “__FROMEXTEN=101”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:9] Set(“SIP/101-00004a73”, “__MON_FMT=wav”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:10] NoOp(“SIP/101-00004a73”, “Recordings initialized”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“SIP/101-00004a73”, “0?Set(ARG3=dontcare)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:12] Set(“SIP/101-00004a73”, “REC_POLICY_MODE_SAVE=”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:13] ExecIf(“SIP/101-00004a73”, “0?Set(REC_STATUS=NO)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:14] GotoIf(“SIP/101-00004a73”, “3?checkaction”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Goto (sub-record-check,s,17)
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@sub-record-check:17] GotoIf(“SIP/101-00004a73”, “1?sub-record-check,out,1”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Goto (sub-record-check,out,1)
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [out@sub-record-check:1] NoOp(“SIP/101-00004a73”, “Outbound Recording Check from 101 to 5123535115”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [out@sub-record-check:2] Set(“SIP/101-00004a73”, “RECMODE=dontcare”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [out@sub-record-check:3] ExecIf(“SIP/101-00004a73”, “1?Goto(routewins)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Goto (sub-record-check,out,7)
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [out@sub-record-check:7] Gosub(“SIP/101-00004a73”, “recordcheck,1(dontcare,out,5123535115)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [recordcheck@sub-record-check:1] NoOp(“SIP/101-00004a73”, “Starting recording check against dontcare”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [recordcheck@sub-record-check:2] Goto(“SIP/101-00004a73”, “dontcare”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Goto (sub-record-check,recordcheck,3)
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [recordcheck@sub-record-check:3] Return(“SIP/101-00004a73”, “”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [out@sub-record-check:8] Return(“SIP/101-00004a73”, “”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [5123535115@from-internal:3] ExecIf(“SIP/101-00004a73”, “0 ?Set(CDR(accountcode)=)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [5123535115@from-internal:4] Set(“SIP/101-00004a73”, “MOHCLASS=default”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [5123535115@from-internal:5] Set(“SIP/101-00004a73”, “_NODEST=”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [5123535115@from-internal:6] Macro(“SIP/101-00004a73”, “dialout-trunk,1,5123535115,off”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:1] Set(“SIP/101-00004a73”, “DIAL_TRUNK=1”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:2] GosubIf(“SIP/101-00004a73”, “0?sub-pincheck,s,1()”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:3] GotoIf(“SIP/101-00004a73”, “0?disabletrunk,1”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:4] Set(“SIP/101-00004a73”, “DIAL_NUMBER=5123535115”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:5] Set(“SIP/101-00004a73”, “DIAL_TRUNK_OPTIONS=”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:6] Set(“SIP/101-00004a73”, “OUTBOUND_GROUP=OUT_1”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:7] GotoIf(“SIP/101-00004a73”, “0?nomax”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:8] GotoIf(“SIP/101-00004a73”, “0?chanfull”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:9] GotoIf(“SIP/101-00004a73”, “0?skipoutcid”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:10] Set(“SIP/101-00004a73”, “DIAL_TRUNK_OPTIONS=Tt”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:11] Macro(“SIP/101-00004a73”, “outbound-callerid,1”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-outbound-callerid:1] ExecIf(“SIP/101-00004a73”, “0?Set(CALLERPRES()=)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-outbound-callerid:2] ExecIf(“SIP/101-00004a73”, “0?Set(REALCALLERIDNUM=101)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-outbound-callerid:3] GotoIf(“SIP/101-00004a73”, “1?normcid”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Goto (macro-outbound-callerid,s,6)
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-outbound-callerid:6] Set(“SIP/101-00004a73”, “USEROUTCID=”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-outbound-callerid:7] Set(“SIP/101-00004a73”, “EMERGENCYCID=”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-outbound-callerid:8] Set(“SIP/101-00004a73”, “TRUNKOUTCID=5127547963”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-outbound-callerid:9] GotoIf(“SIP/101-00004a73”, “1?trunkcid”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Goto (macro-outbound-callerid,s,14)
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-outbound-callerid:14] ExecIf(“SIP/101-00004a73”, “1?Set(CALLERID(all)=5127547963)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-outbound-callerid:15] ExecIf(“SIP/101-00004a73”, “0?Set(CALLERID(all)=)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-outbound-callerid:16] ExecIf(“SIP/101-00004a73”, “0?Set(CALLERID(all)=)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-outbound-callerid:17] ExecIf(“SIP/101-00004a73”, “0?Set(CALLERPRES()=prohib_passed_screen)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-outbound-callerid:18] Set(“SIP/101-00004a73”, “CDR(outbound_cnum)=5127547963”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-outbound-callerid:19] Set(“SIP/101-00004a73”, “CDR(outbound_cnam)=”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:12] GosubIf(“SIP/101-00004a73”, “0?sub-flp-1,s,1()”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:13] Set(“SIP/101-00004a73”, “OUTNUM=5123535115”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:14] Set(“SIP/101-00004a73”, “custom=SIP/5127547963”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:15] ExecIf(“SIP/101-00004a73”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)Tt)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:16] ExecIf(“SIP/101-00004a73”, “0?Set(DIAL_TRUNK_OPTIONS=TtM(confirm))”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:17] Macro(“SIP/101-00004a73”, “dialout-trunk-predial-hook,”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“SIP/101-00004a73”, “”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:18] GotoIf(“SIP/101-00004a73”, “0?bypass,1”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:19] ExecIf(“SIP/101-00004a73”, “1?Set(CONNECTEDLINE(num,i)=5123535115)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:20] ExecIf(“SIP/101-00004a73”, “1?Set(CONNECTEDLINE(name,i)=CID:5127547963)”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:21] GotoIf(“SIP/101-00004a73”, “0?customtrunk”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-dialout-trunk:22] Dial(“SIP/101-00004a73”, “SIP/5127547963/5123535115,300,Tt”) in new stack
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] netsock2.c: == Using SIP RTP TOS bits 184
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] netsock2.c: == Using SIP RTP CoS mark 5
[2019-07-08 10:25:14] VERBOSE[27044][C-0000138d] app_dial.c: – Called SIP/5127547963/5123535115
[2019-07-08 10:25:26] VERBOSE[27044][C-0000138d] app_dial.c: – SIP/5127547963-00004a74 is ringing
[2019-07-08 10:25:27] VERBOSE[27044][C-0000138d] app_dial.c: – SIP/5127547963-00004a74 answered SIP/101-00004a73
[2019-07-08 10:25:33] VERBOSE[27044][C-0000138d] pbx.c: – Executing [h@macro-dialout-trunk:1] Macro(“SIP/101-00004a73”, “hangupcall,”) in new stack
[2019-07-08 10:25:33] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-hangupcall:1] ExecIf(“SIP/101-00004a73”, “0?Set(CDR(recordingfile)=.wav)”) in new stack
[2019-07-08 10:25:33] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-hangupcall:2] GotoIf(“SIP/101-00004a73”, “1?theend”) in new stack
[2019-07-08 10:25:33] VERBOSE[27044][C-0000138d] pbx.c: – Goto (macro-hangupcall,s,4)
[2019-07-08 10:25:33] VERBOSE[27044][C-0000138d] pbx.c: – Executing [s@macro-hangupcall:4] Hangup(“SIP/101-00004a73”, “”) in new stack
[2019-07-08 10:25:33] VERBOSE[27044][C-0000138d] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/101-00004a73’ in macro ‘hangupcall’
[2019-07-08 10:25:33] VERBOSE[27044][C-0000138d] pbx.c: == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on ‘SIP/101-00004a73’
[2019-07-08 10:25:33] VERBOSE[27044][C-0000138d] app_macro.c: == Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on ‘SIP/101-00004a73’ in macro ‘dialout-trunk’
[2019-07-08 10:25:33] VERBOSE[27044][C-0000138d] pbx.c: == Spawn extension (from-internal, 5123535115, 6) exited non-zero on ‘SIP/101-00004a73’

2

The provider’s claim conflicts with the log entries provided. The call did go out the trunk, but it took 12 seconds to get ring back and another second before it was answered.

3

Your logs say the call not only hit your ITSP, but the call was answered.

4

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