I wonder if anyone can suggest where i can look, i have setup a new install of freepbx using the latest distro. I have added a trunk with the same provider and connection details as we have working on another system, just a different sip account.
Inbound is working as expected, however when i make an outbound call it is not arriving at the trunk and instead is entered into the queue for inbound! Its driving me crazy, i realise i will need to post the logs, but im on the train currently and just wondered if anyone could suggest anything i can check!
pastebin a trace of one of these calls:
https://wiki.freepbx.org/display/SUP/Providing+Great+Debug#ProvidingGreatDebug-AsteriskLogs-PartII
Lorne, thankyou for your help! Even that link was a great help to get me started!
I cant post the full report as it says new users cant post links!
I think the issue is this line, but I dont know how to change it! [2019-08-20 21:47:50] NOTICE[10116][C-00000022] chan_sip.c: Conflicting extension values given. Using āSIPIDā and not āDIALLED NUMBERā I think this is resulting in it calling back the trunk??
For the purposes of posting online I have replaced my sip id with SIPID, My trunk phone number with MY TRUNK NUMBER and called number with DIALLED NUMBER and my IP address with MY IP
I think the issue is this line, but I dont know how to change it! [2019-08-20 21:47:50] NOTICE[10116][C-00000022] chan_sip.c: Conflicting extension values given. Using āSIPIDā and not āDIALLED NUMBERā I think this is resulting in it calling back the trunk??
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [**DIALLED NUMBER**@from-internal:1] Macro("PJSIP/8001-00000017", "user-callerid,LIMIT,EXTERNAL,") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:1] Set("PJSIP/8001-00000017", "TOUCH_MONITOR=1566334069.63") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:2] Set("PJSIP/8001-00000017", "AMPUSER=8001") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:3] GotoIf("PJSIP/8001-00000017", "0?report") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:4] ExecIf("PJSIP/8001-00000017", "1?Set(REALCALLERIDNUM=8001)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:5] Set("PJSIP/8001-00000017", "AMPUSER=8001") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:6] GotoIf("PJSIP/8001-00000017", "0?limit") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:7] Set("PJSIP/8001-00000017", "AMPUSERCIDNAME=Stuart") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:8] ExecIf("PJSIP/8001-00000017", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:9] GotoIf("PJSIP/8001-00000017", "0?report") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:10] Set("PJSIP/8001-00000017", "AMPUSERCID=8001") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:11] Set("PJSIP/8001-00000017", "__DIAL_OPTIONS=HhTtr") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:12] Set("PJSIP/8001-00000017", "CALLERID(all)="Stuart" <8001>") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:13] GotoIf("PJSIP/8001-00000017", "0?limit") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:14] ExecIf("PJSIP/8001-00000017", "1?Set(GROUP(concurrency_limit)=8001)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:15] ExecIf("PJSIP/8001-00000017", "0?Set(CHANNEL(language)=)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:16] NoOp("PJSIP/8001-00000017", "Macro Depth is 1") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:17] GotoIf("PJSIP/8001-00000017", "1?report2:macroerror") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx_builtins.c: Goto (macro-user-callerid,s,18)
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:18] GotoIf("PJSIP/8001-00000017", "1?continue") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx_builtins.c: Goto (macro-user-callerid,s,37)
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:37] Set("PJSIP/8001-00000017", "CALLERID(number)=8001") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:38] Set("PJSIP/8001-00000017", "CALLERID(name)=Stuart") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:39] GotoIf("PJSIP/8001-00000017", "0?cnum") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:40] Set("PJSIP/8001-00000017", "CDR(cnam)=Stuart") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:41] Set("PJSIP/8001-00000017", "CDR(cnum)=8001") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-user-callerid:42] Set("PJSIP/8001-00000017", "CHANNEL(language)=en") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [**DIALLED NUMBER**@from-internal:2] Gosub("PJSIP/8001-00000017", "sub-record-check,s,1(out,**DIALLED NUMBER**,dontcare)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:1] GotoIf("PJSIP/8001-00000017", "0?initialized") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:2] Set("PJSIP/8001-00000017", "__REC_STATUS=INITIALIZED") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:3] Set("PJSIP/8001-00000017", "NOW=1566334069") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:4] Set("PJSIP/8001-00000017", "__DAY=20") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:5] Set("PJSIP/8001-00000017", "__MONTH=08") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:6] Set("PJSIP/8001-00000017", "__YEAR=2019") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:7] Set("PJSIP/8001-00000017", "__TIMESTR=20190820-214749") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:8] Set("PJSIP/8001-00000017", "__FROMEXTEN=8001") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:9] Set("PJSIP/8001-00000017", "__MON_FMT=wav") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:10] NoOp("PJSIP/8001-00000017", "Recordings initialized") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:11] ExecIf("PJSIP/8001-00000017", "0?Set(ARG3=dontcare)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:12] Set("PJSIP/8001-00000017", "REC_POLICY_MODE_SAVE=") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:13] ExecIf("PJSIP/8001-00000017", "0?Set(REC_STATUS=NO)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:14] GotoIf("PJSIP/8001-00000017", "3?checkaction") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx_builtins.c: Goto (sub-record-check,s,17)
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@sub-record-check:17] GotoIf("PJSIP/8001-00000017", "1?sub-record-check,out,1") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx_builtins.c: Goto (sub-record-check,out,1)
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [out@sub-record-check:1] NoOp("PJSIP/8001-00000017", "Outbound Recording Check from 8001 to **DIALLED NUMBER**") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [out@sub-record-check:2] Set("PJSIP/8001-00000017", "RECMODE=dontcare") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [out@sub-record-check:3] ExecIf("PJSIP/8001-00000017", "1?Goto(routewins)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx_builtins.c: Goto (sub-record-check,out,7)
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [out@sub-record-check:7] Gosub("PJSIP/8001-00000017", "recordcheck,1(dontcare,out,**DIALLED NUMBER**)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/8001-00000017", "Starting recording check against dontcare") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("PJSIP/8001-00000017", "dontcare") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [recordcheck@sub-record-check:3] Return("PJSIP/8001-00000017", "") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [out@sub-record-check:8] Return("PJSIP/8001-00000017", "") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [**DIALLED NUMBER**@from-internal:3] ExecIf("PJSIP/8001-00000017", "0 ?Set(CDR(accountcode)=)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [**DIALLED NUMBER**@from-internal:4] Set("PJSIP/8001-00000017", "MOHCLASS=default") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [**DIALLED NUMBER**@from-internal:5] Set("PJSIP/8001-00000017", "_NODEST=") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [**DIALLED NUMBER**@from-internal:6] Macro("PJSIP/8001-00000017", "dialout-trunk,2,**DIALLED NUMBER**,,off") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:1] Set("PJSIP/8001-00000017", "DIAL_TRUNK=2") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:2] ExecIf("PJSIP/8001-00000017", "0?Set(DIAL_OPTIONS=Hhtr)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:3] GosubIf("PJSIP/8001-00000017", "0?sub-pincheck,s,1()") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:4] ExecIf("PJSIP/8001-00000017", "0?Set(CALLERID(num)=8001)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:5] GotoIf("PJSIP/8001-00000017", "0?disabletrunk,1") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:6] Set("PJSIP/8001-00000017", "DIAL_NUMBER=**DIALLED NUMBER**") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:7] Set("PJSIP/8001-00000017", "DIAL_TRUNK_OPTIONS=HhTtr") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:8] Set("PJSIP/8001-00000017", "OUTBOUND_GROUP=OUT_2") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:9] Set("PJSIP/8001-00000017", "DIAL_TRUNK_OPTIONS=T") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:10] GotoIf("PJSIP/8001-00000017", "0?nomax") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:11] GotoIf("PJSIP/8001-00000017", "0?chanfull") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:12] GotoIf("PJSIP/8001-00000017", "0?skipoutcid") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:13] Macro("PJSIP/8001-00000017", "outbound-callerid,2") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:1] NoOp("PJSIP/8001-00000017", "8001") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:2] NoOp("PJSIP/8001-00000017", "") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:3] NoOp("PJSIP/8001-00000017", "off") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:4] ExecIf("PJSIP/8001-00000017", "0?Set(CALLERPRES(name-pres)=)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:5] ExecIf("PJSIP/8001-00000017", "0?Set(CALLERPRES(num-pres)=)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:6] ExecIf("PJSIP/8001-00000017", "0?Set(REALCALLERIDNUM=8001)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:7] ExecIf("PJSIP/8001-00000017", "0?Set(AMPUSER=8001)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:8] GotoIf("PJSIP/8001-00000017", "1?normcid") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx_builtins.c: Goto (macro-outbound-callerid,s,12)
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:12] Set("PJSIP/8001-00000017", "USEROUTCID=") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:13] Set("PJSIP/8001-00000017", "EMERGENCYCID=") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:14] Set("PJSIP/8001-00000017", "TRUNKOUTCID=**MY TRUNK NUMBER**") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:15] GotoIf("PJSIP/8001-00000017", "1?trunkcid") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx_builtins.c: Goto (macro-outbound-callerid,s,21)
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:21] ExecIf("PJSIP/8001-00000017", "1?Set(CALLERID(all)=**MY TRUNK NUMBER**)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:22] ExecIf("PJSIP/8001-00000017", "0?Set(CALLERID(all)=)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:23] ExecIf("PJSIP/8001-00000017", "0?Set(CALLERID(all)=)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:24] ExecIf("PJSIP/8001-00000017", "0?Set(CALLERPRES(name-pres)=prohib_passed_screen)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:25] ExecIf("PJSIP/8001-00000017", "0?Set(CALLERPRES(num-pres)=prohib_passed_screen)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:26] Set("PJSIP/8001-00000017", "CDR(outbound_cnum)=**MY TRUNK NUMBER**") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-outbound-callerid:27] Set("PJSIP/8001-00000017", "CDR(outbound_cnam)=") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:14] GosubIf("PJSIP/8001-00000017", "0?sub-flp-2,s,1()") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:15] Set("PJSIP/8001-00000017", "OUTNUM=**DIALLED NUMBER**") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:16] Set("PJSIP/8001-00000017", "custom=SIP/**SIPID**@draytel.org") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:17] ExecIf("PJSIP/8001-00000017", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:18] ExecIf("PJSIP/8001-00000017", "0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:19] Macro("PJSIP/8001-00000017", "dialout-trunk-predial-hook,") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("PJSIP/8001-00000017", "") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:20] GotoIf("PJSIP/8001-00000017", "0?skipcrm") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:21] Set("PJSIP/8001-00000017", "__CRM_DIRECTION=OUTBOUND") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:22] Set("PJSIP/8001-00000017", "__CRM_DESTINATION=**DIALLED NUMBER**") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:23] Set("PJSIP/8001-00000017", "__CRM_SOURCE=8001") in new stack
[2019-08-20 21:47:49] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:24] AGI("PJSIP/8001-00000017", "sangomacrm.agi") in new stack
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] res_agi.c: <PJSIP/8001-00000017>AGI Script sangomacrm.agi completed, returning 0
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:25] Set("PJSIP/8001-00000017", "CHANNEL(hangup_handler_push)=crm-hangup,s,1") in new stack
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:26] NoOp("PJSIP/8001-00000017", "CRM Finished") in new stack
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:27] GotoIf("PJSIP/8001-00000017", "0?bypass,1") in new stack
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:28] ExecIf("PJSIP/8001-00000017", "1?Set(CONNECTEDLINE(num,i)=**DIALLED NUMBER**)") in new stack
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:29] ExecIf("PJSIP/8001-00000017", "1?Set(CONNECTEDLINE(name,i)=CID:**MY TRUNK NUMBER**)") in new stack
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:30] ExecIf("PJSIP/8001-00000017", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)**MY TRUNK NUMBER**)") in new stack
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:31] GotoIf("PJSIP/8001-00000017", "0?customtrunk") in new stack
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-dialout-trunk:32] Dial("PJSIP/8001-00000017", "SIP/**SIPID**@draytel.org/**DIALLED NUMBER**,300,Tb(func-apply-sipheaders^s^1,(2))") in new stack
[2019-08-20 21:47:50] NOTICE[10116][C-00000022] chan_sip.c: Conflicting extension values given. Using '**SIPID**' and not '**DIALLED NUMBER**'
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] netsock2.c: Using SIP RTP TOS bits 184
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] netsock2.c: Using SIP RTP CoS mark 5
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] app_stack.c: SIP/draytel.org-00000014 Internal Gosub(func-apply-sipheaders,s,1(2)) start
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf("SIP/draytel.org-00000014", "0?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp("SIP/draytel.org-00000014", "Applying SIP Headers to channel SIP/draytel.org-00000014") in new stack
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] pbx.c: Executing [s@func-apply-sipheaders:3] Set("SIP/draytel.org-00000014", "TECH=SIP") in new stack
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] pbx.c: Executing [s@func-apply-sipheaders:4] Set("SIP/draytel.org-00000014", "SIPHEADERKEYS=") in new stack
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] pbx.c: Executing [s@func-apply-sipheaders:5] While("SIP/draytel.org-00000014", "0") in new stack
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] app_while.c: Jumping to priority 12
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] pbx.c: Executing [s@func-apply-sipheaders:13] Return("SIP/draytel.org-00000014", "") in new stack
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] app_stack.c: Spawn extension (from-sip-external, **DIALLED NUMBER**, 1) exited non-zero on 'SIP/draytel.org-00000014'
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] app_stack.c: SIP/draytel.org-00000014 Internal Gosub(func-apply-sipheaders,s,1(2)) complete GOSUB_RETVAL=
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] chan_sip.c: Audio is at 15924
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] chan_sip.c: Adding codec g722 to SDP
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] chan_sip.c: Adding codec ulaw to SDP
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] chan_sip.c: Adding codec alaw to SDP
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] chan_sip.c: Adding codec gsm to SDP
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] chan_sip.c: Adding codec g726 to SDP
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] chan_sip.c: Reliably Transmitting (no NAT) to 217.14.138.127:5060:
[2019-08-20 21:47:50] VERBOSE[10116][C-00000022] app_dial.c: Called SIP/**SIPID**@draytel.org/**DIALLED NUMBER**
[2019-08-20 21:47:51] VERBOSE[2099][C-00000022] chan_sip.c: Found RTP audio format 0
[2019-08-20 21:47:51] VERBOSE[2099][C-00000022] chan_sip.c: Found RTP audio format 101
[2019-08-20 21:47:51] VERBOSE[2099][C-00000022] chan_sip.c: Found audio description format PCMU for ID 0
[2019-08-20 21:47:51] VERBOSE[2099][C-00000022] chan_sip.c: Found audio description format telephone-event for ID 101
[2019-08-20 21:47:51] VERBOSE[2099][C-00000022] chan_sip.c: Capabilities: us - (ulaw|alaw|gsm|g726|g722), peer - audio=(ulaw)/video=(nothing)/text=(nothing), combined - (ulaw)
[2019-08-20 21:47:51] VERBOSE[2099][C-00000022] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2019-08-20 21:47:51] VERBOSE[2099][C-00000022] res_rtp_asterisk.c: 0x7f7374799970 -- Strict RTP learning after remote address set to: **MY PUBLIC IP**:17538
[2019-08-20 21:47:51] VERBOSE[2099][C-00000022] chan_sip.c: Peer audio RTP is at port **MY PUBLIC IP**:17538
[2019-08-20 21:47:51] VERBOSE[2099][C-00000022] sip/route.c: sip_route_dump: route/path hop: <sip:217.14.138.127;lr=on;ftag=as7e5a3d2a>
[2019-08-20 21:47:51] VERBOSE[2099][C-00000022] chan_sip.c: set_destination: Parsing <sip:217.14.138.127;lr=on;ftag=as7e5a3d2a> for address/port to send to
[2019-08-20 21:47:51] VERBOSE[2099][C-00000022] chan_sip.c: set_destination: set destination to 217.14.138.127:5060
[2019-08-20 21:47:51] VERBOSE[2099][C-00000022] chan_sip.c: Transmitting (no NAT) to 217.14.138.127:5060:
[2019-08-20 21:47:51] VERBOSE[10116][C-00000022] app_dial.c: SIP/draytel.org-00000014 answered PJSIP/8001-00000017
[2019-08-20 21:47:51] VERBOSE[10129][C-00000022] bridge_channel.c: Channel SIP/draytel.org-00000014 joined 'simple_bridge' basic-bridge <11e769ea-361a-4684-8baf-02d976efb472>
[2019-08-20 21:47:51] VERBOSE[10116][C-00000022] bridge_channel.c: Channel PJSIP/8001-00000017 joined 'simple_bridge' basic-bridge <11e769ea-361a-4684-8baf-02d976efb472>
[2019-08-20 21:47:51] VERBOSE[10116][C-00000022] res_rtp_asterisk.c: 0x7f7360019040 -- Strict RTP qualifying stream type: audio
[2019-08-20 21:47:51] VERBOSE[10116][C-00000022] res_rtp_asterisk.c: 0x7f7360019040 -- Strict RTP switching source address to 86.146.84.225:45104
[2019-08-20 21:47:51] VERBOSE[10129][C-00000022] res_rtp_asterisk.c: 0x7f7374799970 -- Strict RTP switching to RTP target address **MY PUBLIC IP**:17538 as source
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] bridge_channel.c: Channel PJSIP/8001-00000017 left 'simple_bridge' basic-bridge <11e769ea-361a-4684-8baf-02d976efb472>
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] app_macro.c: Spawn extension (macro-dialout-trunk, s, 32) exited non-zero on 'PJSIP/8001-00000017' in macro 'dialout-trunk'
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Spawn extension (from-internal, **DIALLED NUMBER**, 6) exited non-zero on 'PJSIP/8001-00000017'
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Executing [h@from-internal:1] Macro("PJSIP/8001-00000017", "hangupcall") in new stack
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("PJSIP/8001-00000017", "1?theend") in new stack
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2019-08-20 21:47:53] VERBOSE[10129][C-00000022] bridge_channel.c: Channel SIP/draytel.org-00000014 left 'simple_bridge' basic-bridge <11e769ea-361a-4684-8baf-02d976efb472>
[2019-08-20 21:47:53] VERBOSE[10129][C-00000022] chan_sip.c: Scheduling destruction of SIP dialog '54786ae0729fe17f40fcab19070dc8a6@**MY PUBLIC IP**:5160' in 32000 ms (Method: INVITE)
[2019-08-20 21:47:53] VERBOSE[10129][C-00000022] chan_sip.c: set_destination: Parsing <sip:217.14.138.127;lr=on;ftag=as7e5a3d2a> for address/port to send to
[2019-08-20 21:47:53] VERBOSE[10129][C-00000022] chan_sip.c: set_destination: set destination to 217.14.138.127:5060
[2019-08-20 21:47:53] VERBOSE[10129][C-00000022] chan_sip.c: Reliably Transmitting (no NAT) to 217.14.138.127:5060:
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("PJSIP/8001-00000017", "0?Set(CDR(recordingfile)=)") in new stack
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-hangupcall:4] NoOp("PJSIP/8001-00000017", "SIP/draytel.org-00000014 montior file= ") in new stack
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-hangupcall:5] GotoIf("PJSIP/8001-00000017", "1?skipagi") in new stack
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx_builtins.c: Goto (macro-hangupcall,s,7)
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Executing [s@macro-hangupcall:7] Hangup("PJSIP/8001-00000017", "") in new stack
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] app_macro.c: Spawn extension (macro-hangupcall, s, 7) exited non-zero on 'PJSIP/8001-00000017' in macro 'hangupcall'
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on 'PJSIP/8001-00000017'
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] app_stack.c: PJSIP/8001-00000017 Internal Gosub(crm-hangup,s,1) start
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Executing [s@crm-hangup:1] NoOp("PJSIP/8001-00000017", "Sending Hangup to CRM") in new stack
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Executing [s@crm-hangup:2] NoOp("PJSIP/8001-00000017", "HANGUP CAUSE: 16") in new stack
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Executing [s@crm-hangup:3] ExecIf("PJSIP/8001-00000017", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Executing [s@crm-hangup:4] NoOp("PJSIP/8001-00000017", "MASTER CHANNEL: 1566334069.63 = 1566334069.63") in new stack
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Executing [s@crm-hangup:5] GotoIf("PJSIP/8001-00000017", "0?return") in new stack
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Executing [s@crm-hangup:6] Set("PJSIP/8001-00000017", "__CRM_HANGUP=1") in new stack
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] pbx.c: Executing [s@crm-hangup:7] AGI("PJSIP/8001-00000017", "sangomacrm.agi") in new stack
[2019-08-20 21:47:53] VERBOSE[10116][C-00000022] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2019-08-20 21:47:55] VERBOSE[10116][C-00000022] res_agi.c: <PJSIP/8001-00000017>AGI Script sangomacrm.agi completed, returning 0
[2019-08-20 21:47:55] VERBOSE[10116][C-00000022] pbx.c: Executing [s@crm-hangup:8] Return("PJSIP/8001-00000017", "") in new stack
[2019-08-20 21:47:55] VERBOSE[10116][C-00000022] app_stack.c: Spawn extension (from-internal, h, 1) exited non-zero on 'PJSIP/8001-00000017'
[2019-08-20 21:47:55] VERBOSE[10116][C-00000022] app_stack.c: PJSIP/8001-00000017 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=Try restarting asterisk:
fwconsole restart
The dial string is malformed, and thru a confluence of coincidences, you are getting an inbound call instead of a failed dial.
I have done issued the command and watched it shut down and restart, previously I had restarted the entire machine to no avail. Still I am getting the same behavior, I will get the logs again, can you think of anything else I could check?
This time the call log only has a single entry from chan.c failed to authenticate, which is fine, Im sure I can find a solution to that, but I donāt understand how the call is still ending up on the inbound queue. When dialed from the internal extension which is in that queue I get a call waiting when ever I call out!
[2019-08-20 05:19:27] NOTICE[2099][C-00000000] chan_sip.c: Failed to authenticate device <sip:3022@MYPUBLICIP>;tag=1470188374
3022 isnāt a reference I recognize?
Has anyone got any idea what I can check? This is driving me crazy!!! 
The dial string is bad, is should be:
SIP/<peer name of trunk>/**DIALLED NUMBER**
Since a restart didnāt resolve, I presume you have a trunk misconfig.
Lorne, I appreciate your help very much, I am struggling to understand?
SIP/[email protected]/dialled number is not correct? how should the peer look?
Could this be related to the error message we had showing āConflicting extension values givenā?
The call logs are now only showing failed to authenticate, but incoming is working and the account details are the same in the trunk config and also the same as accounts with the same provider on another system which is working.
Sorry I just dont know where to look!
My sip trunk peer details;
username=123456
type=friend
trustrpid=yes
transport=UDP
sendrpid=yes
secret=Password
qualify=yes
nat=no
keepalive=20
insecure=port,invite
host=draytel.org
fromuser=123456
fromdomain=draytel.org
dtmfmode=rfc2833
disallow=all
directmedia=no
context=from-trunk
allow=ulaw
It is the name shown from the Asterisk CLI sip show peers
Name/username Host Dyn Forcerport Comedia ACL Port Status Description
[email protected]/84987 217.14.138.127 No No 5060 OK (3 ms)
1 sip peers [Monitored: 1 online, 0 offline Unmonitored: 0 online, 0 offline]yes, its shown and states ok.
Edit the trunk, on the SIP Settings tab, change the ātrunk nameā to something with only alpha numeric characters.
Lorne,
You have found the cause, thankyou so much! it is now resolved! My daft mistake using the peer as the trunk name!
I have literally been tearing my hair out, very grateful 
1 Like
This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.