FreePBX 10.13.66-17 - Random Outbound Routes Issue

I’ve installed FreePBX and setup a PJSIP trunk with Voipfone. I’ve historically used chan_sip, but after lots of research and documented help on this forum I’ve been able to get it to work fully with inbound routes and calls are routed in perfectly.

The issue I’ve got is I’ve created an Outbound route the same way as I’ve always done, and had the dial pattern so that users press 8 before dialing out ( [8] [X.] ) and it seems to be routing to the trunk for outbound calls successfully.

The issue is, whenever I dial the Voipfone balance number (154 - so 8154) it answers and hangs up straight away. If I call the voipfone speaking clock (8123), voipfone call / setup test line (8155) or their conference line (8156) it’s all working perfectly.

Even if I dial an external number, that’s actually a voipfone number - it all works perfectly.

But if I call a proper external / traditional landline or mobile number, or call the voipfone 154 balance number, it just hangs up. A log of it just hanging up is below.

I thought this must obviously be a voipfone issue, but I’ve spoken to them and there’s no issue their side. Also, their service is working fine on my other PBX, and even setup the SIP details directly on a softphone, everything works as expected there.

I’ve also removed my dial pattern so it’s calling direct - this isn’t a trunk / outbound routing issue and appears to be something else - network related maybe?

I’d be really grateful for any guidance, log below: (i’ve tried to remove any personal data, so strings and numbers have been changed)

[root@server ~]# asterisk -Rvvvvvvvvvv
Asterisk 13.12.1, Copyright (C) 1999 - 2014, Digium, Inc. and others.
Created by Mark Spencer [email protected]
Asterisk comes with ABSOLUTELY NO WARRANTY; type ‘core show warranty’ for details.
This is free software, with components licensed under the GNU General Public
License version 2 and other licenses; you are welcome to redistribute it under
certain conditions. Type ‘core show license’ for details.

Connected to Asterisk 13.12.1 currently running on service (pid = 1805)
– Executing [8154@from-internal:1] Macro(“PJSIP/1001-00000006”, “user-callerid,LIMIT”) in new stack
[2017-07-01 18:54:35] WARNING[1889]: res_pjsip_pubsub.c:3152 pubsub_on_rx_publish_request: No registered publish handler for event presence
– Executing [s@macro-user-callerid:1] Set(“PJSIP/1001-00000006”, “TOUCH_MONITOR=1498931675.6”) in new stack
– Executing [s@macro-user-callerid:2] Set(“PJSIP/1001-00000006”, “AMPUSER=1001”) in new stack
– Executing [s@macro-user-callerid:3] GotoIf(“PJSIP/1001-00000006”, “0?report”) in new stack
– Executing [s@macro-user-callerid:4] ExecIf(“PJSIP/1001-00000006”, “1?Set(REALCALLERIDNUM=1001)”) in new stack
[2017-07-01 18:54:35] WARNING[1889]: res_pjsip_pubsub.c:639 subscription_get_handler_from_rdata: No registered subscribe handler for event presence.winfo
– Executing [s@macro-user-callerid:5] Set(“PJSIP/1001-00000006”, “AMPUSER=1001”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“PJSIP/1001-00000006”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:7] Set(“PJSIP/1001-00000006”, “AMPUSERCIDNAME=My Phone”) in new stack
– Executing [s@macro-user-callerid:8] GotoIf(“PJSIP/1001-00000006”, “0?report”) in new stack
– Executing [s@macro-user-callerid:9] Set(“PJSIP/1001-00000006”, “AMPUSERCID=1001”) in new stack
– Executing [s@macro-user-callerid:10] Set(“PJSIP/1001-00000006”, “__DIAL_OPTIONS=Ttr”) in new stack
– Executing [s@macro-user-callerid:11] Set(“PJSIP/1001-00000006”, “CALLERID(all)=“My Phone” <1001>”) in new stack
– Executing [s@macro-user-callerid:12] GotoIf(“PJSIP/1001-00000006”, “0?limit”) in new stack
– Executing [s@macro-user-callerid:13] ExecIf(“PJSIP/1001-00000006”, “1?Set(GROUP(concurrency_limit)=1001)”) in new stack
– Executing [s@macro-user-callerid:14] ExecIf(“PJSIP/1001-00000006”, “0?Set(CHANNEL(language)=)”) in new stack
– Executing [s@macro-user-callerid:15] GotoIf(“PJSIP/1001-00000006”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,29)
– Executing [s@macro-user-callerid:29] Set(“PJSIP/1001-00000006”, “CALLERID(number)=1001”) in new stack
– Executing [s@macro-user-callerid:30] Set(“PJSIP/1001-00000006”, “CALLERID(name)=My Phone”) in new stack
– Executing [s@macro-user-callerid:31] GotoIf(“PJSIP/1001-00000006”, “0?cnum”) in new stack
– Executing [s@macro-user-callerid:32] Set(“PJSIP/1001-00000006”, “CDR(cnam)=My Phone”) in new stack
– Executing [s@macro-user-callerid:33] Set(“PJSIP/1001-00000006”, “CDR(cnum)=1001”) in new stack
– Executing [s@macro-user-callerid:34] Set(“PJSIP/1001-00000006”, “CHANNEL(language)=en_GB”) in new stack
– Executing [8154@from-internal:2] Set(“PJSIP/1001-00000006”, “ROUTEUSER=1001”) in new stack
– Executing [8154@from-internal:3] Set(“PJSIP/1001-00000006”, “ROUTEUSER=1001”) in new stack
– Executing [8154@from-internal:4] GotoIf(“PJSIP/1001-00000006”, “1?notblind”) in new stack
– Goto (from-internal,8154,7)
– Executing [8154@from-internal:7] GotoIf(“PJSIP/1001-00000006”, “1?restrictedroute-9r0f4e09tgiojgpreo9irjowefw8fu93,8154,2:outbound-allroutes,8154,2”) innew stack
– Goto (restrictedroute-9r0f4e09tgiojgpreo9irjowefw8fu93,8154,2)
– Executing [8154@restrictedroute-9r0f4e09tgiojgpreo9irjowefw8fu93:2] Gosub(“PJSIP/1001-00000006”, “sub-record-check,s,1(out,8154,dontcare)”) in new stack
– Executing [s@sub-record-check:1] GotoIf(“PJSIP/1001-00000006”, “0?initialized”) in new stack
– Executing [s@sub-record-check:2] Set(“PJSIP/1001-00000006”, “__REC_STATUS=INITIALIZED”) in new stack
– Executing [s@sub-record-check:3] Set(“PJSIP/1001-00000006”, “NOW=1498931675”) in new stack
– Executing [s@sub-record-check:4] Set(“PJSIP/1001-00000006”, “__DAY=01”) in new stack
– Executing [s@sub-record-check:5] Set(“PJSIP/1001-00000006”, “__MONTH=07”)in new stack
– Executing [s@sub-record-check:6] Set(“PJSIP/1001-00000006”, “__YEAR=2017”) in new stack
– Executing [s@sub-record-check:7] Set(“PJSIP/1001-00000006”, “__TIMESTR=20170701-185435”) in new stack
– Executing [s@sub-record-check:8] Set(“PJSIP/1001-00000006”, “__FROMEXTEN=1001”) in new stack
– Executing [s@sub-record-check:9] Set(“PJSIP/1001-00000006”, “__MON_FMT=wav”) in new stack
– Executing [s@sub-record-check:10] NoOp(“PJSIP/1001-00000006”, “Recordingsinitialized”) in new stack
– Executing [s@sub-record-check:11] ExecIf(“PJSIP/1001-00000006”, “0?Set(ARG3=dontcare)”) in new stack
– Executing [s@sub-record-check:12] Set(“PJSIP/1001-00000006”, “REC_POLICY_MODE_SAVE=”) in new stack
– Executing [s@sub-record-check:13] ExecIf(“PJSIP/1001-00000006”, “0?Set(REC_STATUS=NO)”) in new stack
– Executing [s@sub-record-check:14] GotoIf(“PJSIP/1001-00000006”, “3?checkaction”) in new stack
– Goto (sub-record-check,s,17)
– Executing [s@sub-record-check:17] GotoIf(“PJSIP/1001-00000006”, “1?sub-record-check,out,1”) in new stack
– Goto (sub-record-check,out,1)
– Executing [out@sub-record-check:1] NoOp(“PJSIP/1001-00000006”, “OutboundRecording Check from 1001 to 8154”) in new stack
– Executing [out@sub-record-check:2] Set(“PJSIP/1001-00000006”, “RECMODE=dontcare”) in new stack
– Executing [out@sub-record-check:3] ExecIf(“PJSIP/1001-00000006”, “1?Goto(routewins)”) in new stack
– Goto (sub-record-check,out,7)
– Executing [out@sub-record-check:7] Gosub(“PJSIP/1001-00000006”, “recordcheck,1(dontcare,out,8154)”) in new stack
– Executing [recordcheck@sub-record-check:1] NoOp(“PJSIP/1001-00000006”, “Starting recording check against dontcare”) in new stack
– Executing [recordcheck@sub-record-check:2] Goto(“PJSIP/1001-00000006”, “dontcare”) in new stack
– Goto (sub-record-check,recordcheck,3)
– Executing [recordcheck@sub-record-check:3] Return(“PJSIP/1001-00000006”,“”) in new stack
– Executing [out@sub-record-check:8] Return(“PJSIP/1001-00000006”, “”) in new stack
– Executing [8154@restrictedroute-9r0f4e09tgiojgpreo9irjowefw8fu93:3] ExecIf(“PJSIP/1001-00000006”, “0 ?Set(CDR(accountcode)=)”) in new stack
– Executing [8154@restrictedroute-9r0f4e09tgiojgpreo9irjowefw8fu93:4] Set(“PJSIP/1001-00000006”, “MOHCLASS=default”) in new stack
– Executing [8154@restrictedroute-9r0f4e09tgiojgpreo9irjowefw8fu93:5] ExecIf(“PJSIP/1001-00000006”, “1?Set(TRUNKCIDOVERRIDE=01492623222)”) in new stack
– Executing [8154@restrictedroute-9r0f4e09tgiojgpreo9irjowefw8fu93:6] Set(“PJSIP/1001-00000006”, “_NODEST=”) in new stack
– Executing [8154@restrictedroute-9r0f4e09tgiojgpreo9irjowefw8fu93:7] Macro(“PJSIP/1001-00000006”, “dialout-trunk,2,154,off”) in new stack
– Executing [s@macro-dialout-trunk:1] Set(“PJSIP/1001-00000006”, “DIAL_TRUNK=2”) in new stack
– Executing [s@macro-dialout-trunk:2] GosubIf(“PJSIP/1001-00000006”, “0?sub-pincheck,s,1()”) in new stack
– Executing [s@macro-dialout-trunk:3] GotoIf(“PJSIP/1001-00000006”, “0?disabletrunk,1”) in new stack
– Executing [s@macro-dialout-trunk:4] Set(“PJSIP/1001-00000006”, “DIAL_NUMBER=154”) in new stack
– Executing [s@macro-dialout-trunk:5] Set(“PJSIP/1001-00000006”, “DIAL_TRUNK_OPTIONS=Ttr”) in new stack
– Executing [s@macro-dialout-trunk:6] Set(“PJSIP/1001-00000006”, “OUTBOUND_GROUP=OUT_2”) in new stack
– Executing [s@macro-dialout-trunk:7] GotoIf(“PJSIP/1001-00000006”, “1?nomax”) in new stack
– Goto (macro-dialout-trunk,s,9)
– Executing [s@macro-dialout-trunk:9] GotoIf(“PJSIP/1001-00000006”, “0?skipoutcid”) in new stack
– Executing [s@macro-dialout-trunk:10] Set(“PJSIP/1001-00000006”, “DIAL_TRUNK_OPTIONS=T”) in new stack
– Executing [s@macro-dialout-trunk:11] Macro(“PJSIP/1001-00000006”, “outbound-callerid,2”) in new stack
– Executing [s@macro-outbound-callerid:1] ExecIf(“PJSIP/1001-00000006”, “0?Set(CALLERPRES(name-pres)=)”) in new stack
– Executing [s@macro-outbound-callerid:2] ExecIf(“PJSIP/1001-00000006”, “0?Set(CALLERPRES(num-pres)=)”) in new stack
– Executing [s@macro-outbound-callerid:3] ExecIf(“PJSIP/1001-00000006”, “0?Set(REALCALLERIDNUM=1001)”) in new stack
– Executing [s@macro-outbound-callerid:4] GotoIf(“PJSIP/1001-00000006”, “1?normcid”) in new stack
– Goto (macro-outbound-callerid,s,7)
– Executing [s@macro-outbound-callerid:7] Set(“PJSIP/1001-00000006”, “USEROUTCID=”) in new stack
– Executing [s@macro-outbound-callerid:8] Set(“PJSIP/1001-00000006”, “EMERGENCYCID=”) in new stack
– Executing [s@macro-outbound-callerid:9] Set(“PJSIP/1001-00000006”, “TRUNKOUTCID=01492623222”) in new stack
– Executing [s@macro-outbound-callerid:10] GotoIf(“PJSIP/1001-00000006”, “1?trunkcid”) in new stack
– Goto (macro-outbound-callerid,s,15)
– Executing [s@macro-outbound-callerid:15] ExecIf(“PJSIP/1001-00000006”, “1?Set(CALLERID(all)=01492623222)”) in new stack
– Executing [s@macro-outbound-callerid:16] ExecIf(“PJSIP/1001-00000006”, “0?Set(CALLERID(all)=)”) in new stack
– Executing [s@macro-outbound-callerid:17] ExecIf(“PJSIP/1001-00000006”, “1?Set(CALLERID(all)=01492623222)”) in new stack
– Executing [s@macro-outbound-callerid:18] ExecIf(“PJSIP/1001-00000006”, “0?Set(CALLERPRES(name-pres)=prohib_passed_screen)”) in new stack
– Executing [s@macro-outbound-callerid:19] ExecIf(“PJSIP/1001-00000006”, “0?Set(CALLERPRES(num-pres)=prohib_passed_screen)”) in new stack
– Executing [s@macro-outbound-callerid:20] Set(“PJSIP/1001-00000006”, “CDR(outbound_cnum)=01492623222”) in new stack
– Executing [s@macro-outbound-callerid:21] Set(“PJSIP/1001-00000006”, “CDR(outbound_cnam)=”) in new stack
[2017-07-01 18:54:35] WARNING[1845]: func_cdr.c:383 cdr_write_callback: CDR requires a value (CDR(variable)=value)
– Executing [s@macro-dialout-trunk:12] GosubIf(“PJSIP/1001-00000006”, “0?sub-flp-2,s,1()”) in new stack
– Executing [s@macro-dialout-trunk:13] Set(“PJSIP/1001-00000006”, “OUTNUM=154”) in new stack
– Executing [s@macro-dialout-trunk:14] Set(“PJSIP/1001-00000006”, “custom=PJSIP”) in new stack
– Executing [s@macro-dialout-trunk:15] ExecIf(“PJSIP/1001-00000006”, “0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^default)T)”) in new stack
– Executing [s@macro-dialout-trunk:16] ExecIf(“PJSIP/1001-00000006”, “0?Set(DIAL_TRUNK_OPTIONS=TM(confirm))”) in new stack
– Executing [s@macro-dialout-trunk:17] Macro(“PJSIP/1001-00000006”, “dialout-trunk-predial-hook,”) in new stack
– Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit(“PJSIP/1001-00000006”, “”) in new stack
– Executing [s@macro-dialout-trunk:18] GotoIf(“PJSIP/1001-00000006”, “0?skipcrm”) in new stack
– Executing [s@macro-dialout-trunk:19] Set(“PJSIP/1001-00000006”, “__CRM_DIRECTION=OUTBOUND”) in new stack
– Executing [s@macro-dialout-trunk:20] Set(“PJSIP/1001-00000006”, “__CRM_DESTINATION=154”) in new stack
– Executing [s@macro-dialout-trunk:21] Set(“PJSIP/1001-00000006”, “__CRM_SOURCE=1001”) in new stack
– Executing [s@macro-dialout-trunk:22] AGI(“PJSIP/1001-00000006”, “sangomacrm.agi”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
– <PJSIP/1001-00000006>AGI Script sangomacrm.agi completed, returning 0
– Executing [s@macro-dialout-trunk:23] Set(“PJSIP/1001-00000006”, “CHANNEL(hangup_handler_push)=crm-hangup,s,1”) in new stack
– Executing [s@macro-dialout-trunk:24] NoOp(“PJSIP/1001-00000006”, “CRM Finished”) in new stack
– Executing [s@macro-dialout-trunk:25] GotoIf(“PJSIP/1001-00000006”, “0?bypass,1”) in new stack
– Executing [s@macro-dialout-trunk:26] ExecIf(“PJSIP/1001-00000006”, “1?Set(CONNECTEDLINE(num,i)=154)”) in new stack
– Executing [s@macro-dialout-trunk:27] ExecIf(“PJSIP/1001-00000006”, “1?Set(CONNECTEDLINE(name,i)=CID:01492623222)”) in new stack
– Executing [s@macro-dialout-trunk:28] ExecIf(“PJSIP/1001-00000006”, “0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)01492623222)”) in new stack
– Executing [s@macro-dialout-trunk:29] GotoIf(“PJSIP/1001-00000006”, “0?customtrunk”) in new stack
– Executing [s@macro-dialout-trunk:30] Dial(“PJSIP/1001-00000006”, “PJSIP/154@my-voipfone-trunk,300,T”) in new stack
– Called PJSIP/154@my-voipfone-trunk
– PJSIP/my-voipfone-trunk-00000007 answered PJSIP/1001-00000006
– Channel PJSIP/my-voipfone-trunk-00000007 joined ‘simple_bridge’ basic-bridge <847e8c17-936e-48ea-9bf4-064900598c13>
– Channel PJSIP/1001-00000006 joined ‘simple_bridge’ basic-bridge <847e8c17-936e-48ea-9bf4-064900598c13>
[2017-07-01 18:54:36] WARNING[1889]: res_pjsip_pubsub.c:3152 pubsub_on_rx_publish_request: No registered publish handler for event presence
[2017-07-01 18:54:36] WARNING[1889]: res_pjsip_pubsub.c:639 subscription_get_handler_from_rdata: No registered subscribe handler for event presence.winfo

0x7f46fc01fd20 – Probation passed - setting RTP source address to 92.27.11.154:44011
0x7f46fc01fd20 – Probation passed - setting RTP source address to 92.27.11.154:44011
– Channel PJSIP/my-voipfone-trunk-00000007 left ‘simple_bridge’ basic-bridge <847e8c17-936e-48ea-9bf4-064900598c13>
– Channel PJSIP/1001-00000006 left ‘simple_bridge’ basic-bridge <847e8c17-936e-48ea-9bf4-064900598c13>
== Spawn extension (macro-dialout-trunk, s, 30) exited non-zero on ‘PJSIP/1001-00000006’ in macro ‘dialout-trunk’
== Spawn extension (restrictedroute-9r0f4e09tgiojgpreo9irjowefw8fu93, 8154, 7)exited non-zero on ‘PJSIP/1001-00000006’
– Executing [h@restrictedroute-9r0f4e09tgiojgpreo9irjowefw8fu93:1] Hangup(“PJSIP/1001-00000006”, “”) in new stack
== Spawn extension (restrictedroute-9r0f4e09tgiojgpreo9irjowefw8fu93, h, 1) exited non-zero on ‘PJSIP/1001-00000006’
– PJSIP/1001-00000006 Internal Gosub(crm-hangup,s,1) start
– Executing [s@crm-hangup:1] NoOp(“PJSIP/1001-00000006”, “Sending Hangup toCRM”) in new stack
– Executing [s@crm-hangup:2] NoOp(“PJSIP/1001-00000006”, “HANGUP CAUSE: 16”) in new stack
– Executing [s@crm-hangup:3] ExecIf(“PJSIP/1001-00000006”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
– Executing [s@crm-hangup:4] NoOp(“PJSIP/1001-00000006”, “MASTER CHANNEL: 1498931675.6 = 1498931675.6”) in new stack
– Executing [s@crm-hangup:5] GotoIf(“PJSIP/1001-00000006”, “0?return”) in new stack
– Executing [s@crm-hangup:6] Set(“PJSIP/1001-00000006”, “__CRM_HANGUP=1”) in new stack
– Executing [s@crm-hangup:7] AGI(“PJSIP/1001-00000006”, “sangomacrm.agi”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
– <PJSIP/1001-00000006>AGI Script sangomacrm.agi completed, returning 0
– Executing [s@crm-hangup:8] Return(“PJSIP/1001-00000006”, “”) in new stack
== Spawn extension (restrictedroute-9r0f4e09tgiojgpreo9irjowefw8fu93, h, 1) exited non-zero on ‘PJSIP/1001-00000006’
– PJSIP/1001-00000006 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
[2017-07-01 18:54:36] WARNING[1889]: res_pjsip_pubsub.c:3152 pubsub_on_rx_publish_request: No registered publish handler for event presence
[2017-07-01 18:54:36] WARNING[1889]: res_pjsip_pubsub.c:639 subscription_get_handler_from_rdata: No registered subscribe handler for event presence.winfo

I found the issue, for anyone experiencing this behaviour in the future when using PJSIP for a general SIP connection, set the ‘From User’ PJSIP setting to your authenticated username / ID. Done this and it’s working fine now.

Where did you set this setting?

In the PJSip extension settings. There was a couple of issues that needed resolving however I found a company that hosts FreePBX in the cloud, secures it for you and changes all settings needed to malke it safe and secure. They’ve sorted most of my config problems out for me now so remembering which settings fixed which issue is a bit faint lol

Ok thank you though for the reply.