FreePBX does not recognise DID

Hi there!

So I have successfully installed and configured FreePBX distro on a web-server. I use two different SIP-providers. I can make and receive calls.

BUT:

FreePBX does not recognise any DIDs. All I get in the Asterisk logs is:

– Executing [s@from-pstn-toheader:1] NoOp (" SIP/203078.tenios.com-000000b1 ", " Attempting to extract DID from SIP To header ") in new stack

– Executing [s@from-pstn-toheader:2] GotoIf (" SIP/203078.tenios.com-000000b1 ", " 1?SIP ") in new stack

I have already set context of the trunk to β€œcontext=from-pstn-toheader”. Still no change.

What am I doing wrong? :slight_smile:
Christian

Post a SIP INVITE from an inbound call , Use

sngrep

Probably this:

To: is not meant to be used for call routing. It’s just an informational header.

Do you have a single DID with each provider? If so and you are using SIP registration, add the DID to the end of your chan_sip registration string, e.g.

username:[email protected]/5551212

replacing 5551212 with your DID.

1 Like

[ ] 1 INVITE [email protected]. [email protected] 6 80.239.139.207:5060 178.254.21.183:5160 COMPLETED
[ ] 2 OPTIONS [email protected]:51 203078.tenios.com 2 178.254.21.183:5160 80.239.139.207:5060
[ ] 3 REGISTER [email protected]. [email protected]. 4 178.254.21.183:5160 80.239.139.207:5060
[ ] 4 OPTIONS [email protected] [email protected] 2 178.254.21.183:5060 93.131.42.40:63569

Thank you! Now I can see the DID in the logs but the inbound route still does not work. I get a No Service announcement.

Thank you so much for your call! How nice of you! :slight_smile:

Here is the log:

== Using SIP RTP TOS bits 184

== Using SIP RTP CoS mark 5

> 0x7fd5b8093e80 – Strict RTP learning after remote address set to: 80.239.139.207:31786

– Executing [[email protected]:1] Set (" SIP/203078.tenios.com-000000c2 ", " GROUP()=OUT_1 ") in new stack

– Executing [[email protected]:2] Goto (" SIP/203078.tenios.com-000000c2 ", " from-trunk,498003227766,1 ") in new stack

– Goto (from-trunk,498003227766,1)

– Executing [498003227766@from-trunk:1] Set (" SIP/203078.tenios.com-000000c2 ", " __FROM_DID=498003227766 ") in new stack

– Executing [498003227766@from-trunk:2] NoOp (" SIP/203078.tenios.com-000000c2 ", " Received an unknown call with DID set to 498003227766 ") in new stack

– Executing [498003227766@from-trunk:3] Goto (" SIP/203078.tenios.com-000000c2 ", " s,a2 ") in new stack

– Goto (from-trunk,s,2)

– Executing [s@from-trunk:2] Answer (" SIP/203078.tenios.com-000000c2 ", β€œβ€) in new stack

> 0x7fd5b8093e80 – Strict RTP switching to RTP target address 80.239.139.207:31786 as source

– Executing [s@from-trunk:3] Log (" SIP/203078.tenios.com-000000c2 ", " WARNING,Friendly Scanner from 80.239.139.207;rport;branch=z9hG4bKgy3Sr94HmFFUa ") in new stack

[2021-04-28 17:11:41] WARNING [15950][C-000000d2]: Ext. s : 3 @ from-trunk : Friendly Scanner from 80.239.139.207;rport;branch=z9hG4bKgy3Sr94HmFFUa

– Executing [s@from-trunk:4] Wait (" SIP/203078.tenios.com-000000c2 ", " 2 ") in new stack

– Executing [s@from-trunk:5] Playback (" SIP/203078.tenios.com-000000c2 ", " ss-noservice ") in new stack

– <SIP/203078.tenios.com-000000c2> Playing β€˜ss-noservice.ulaw’ (language β€˜de_DE’)

– Executing [h@from-trunk:1] Macro (" SIP/203078.tenios.com-000000c2 ", " hangupcall, ") in new stack

– Executing [s@macro-hangupcall:1] GotoIf (" SIP/203078.tenios.com-000000c2 ", " 1?theend ") in new stack

– Goto (macro-hangupcall,s,3)

– Executing [s@macro-hangupcall:3] ExecIf (" SIP/203078.tenios.com-000000c2 ", " 0?Set(CDR(recordingfile)=) ") in new stack

– Executing [s@macro-hangupcall:4] NoOp (" SIP/203078.tenios.com-000000c2 ", " montior file= ") in new stack

– Executing [s@macro-hangupcall:5] GotoIf (" SIP/203078.tenios.com-000000c2 ", " 1?skipagi ") in new stack

– Goto (macro-hangupcall,s,7)

– Executing [s@macro-hangupcall:7] Hangup (" SIP/203078.tenios.com-000000c2 ", β€œβ€) in new stack

== Spawn extension (macro-hangupcall, s, 7) exited non-zero on β€˜SIP/203078.tenios.com-000000c2’ in macro β€˜hangupcall’

== Spawn extension (from-trunk, h, 1) exited non-zero on β€˜SIP/203078.tenios.com-000000c2’

You’re not matching the trunk. chan_sip trunk config would need this line to match on the IP address of the trunk provider:

insecure=port,invite
1 Like

Well when a SIP registration is used and multiple DIDs are sent over it the request uri always has the sip account as the user while the To header contains the actual DID that was dialed. So yes, the To header is used for routing in a sense.

1 Like

The line β€œinsecure=port,invite” is in my trunk configuration. When I leave out the DID in my inbound route the call goes through as expected.

Share your trunk config please.

This is what the provider told me to put in the outgoing config:

type=peer
host=203078.tenios.com
domain=203078.tenios.com
username=talkradio1
outboundproxy:5060=203078.tenios.com
insecure=port,invite
qualify=yes
disallow=all
registertimeout=600
allow=alaw&ulaw
dtmfmode=rtc2833

And the registration string in the incoming section:
[email protected]:[email protected]:5060/498003227766

XXX stands for the password

Your Inbound Route should look something like:

1 Like

I forget about hacks like that. Sorry, you are right. Someday we will implement RFC 6140 - Registration for Multiple Phone Numbers in the Session Initiation Protocol (SIP) or similar.

that is exactly what it looks like :slight_smile:

This line looks to be malformed. I think you want

outboundproxy=203078.tenios.com:5060

That is actually what it says. The forum keeps mixing it up when I post it.

Yeah, I’m kind of glad they haven’t.

I am really puzzled here, because it’s not clear whether Asterisk is taking the β€œunknown DID” path or the β€œunknown trunk address” path; the log shows signs of both.

Do you have a default Inbound Route (DID and CID both set to Any)? If so, and the incoming call takes that route, we can look at the generated dial plan to see why the DID doesn’t get matched. If it still takes the β€˜friendly scanner’ path, we can look for why the trunk context isn’t being followed.

When I remove the DID from the inbound route it works as expected:

> 0x7fd5b8093e80 – Strict RTP learning after remote address set to: 80.239.139.207:29000

– Executing [[email protected]:1] Set (" SIP/203078.tenios.com-000000c4 ", " GROUP()=OUT_1 ") in new stack

– Executing [[email protected]:2] Goto (" SIP/203078.tenios.com-000000c4 ", " from-trunk,498003227766,1 ") in new stack

– Goto (from-trunk,498003227766,1)

– Executing [498003227766@from-trunk:1] NoOp (" SIP/203078.tenios.com-000000c4 ", " Catch-All DID Match - Found 498003227766 - You probably want a DID for this. ") in new stack

– Executing [498003227766@from-trunk:2] Set (" SIP/203078.tenios.com-000000c4 ", " __FROM_DID=498003227766 ") in new stack

– Executing [498003227766@from-trunk:3] Goto (" SIP/203078.tenios.com-000000c4 ", " ext-did,s,1 ") in new stack

– Goto (ext-did,s,1)

– Executing [s@ext-did:1] Set (" SIP/203078.tenios.com-000000c4 ", " __DIRECTION=INBOUND ") in new stack

– Executing [s@ext-did:2] Gosub (" SIP/203078.tenios.com-000000c4 ", " sub-record-check,s,1(in,s,dontcare) ") in new stack

– Executing [s@sub-record-check:1] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?initialized ") in new stack

– Executing [s@sub-record-check:2] Set (" SIP/203078.tenios.com-000000c4 ", " __REC_STATUS=INITIALIZED ") in new stack

– Executing [s@sub-record-check:3] Set (" SIP/203078.tenios.com-000000c4 ", " NOW=1619626621 ") in new stack

– Executing [s@sub-record-check:4] Set (" SIP/203078.tenios.com-000000c4 ", " __DAY=28 ") in new stack

– Executing [s@sub-record-check:5] Set (" SIP/203078.tenios.com-000000c4 ", " __MONTH=04 ") in new stack

– Executing [s@sub-record-check:6] Set (" SIP/203078.tenios.com-000000c4 ", " __YEAR=2021 ") in new stack

– Executing [s@sub-record-check:7] Set (" SIP/203078.tenios.com-000000c4 ", " __TIMESTR=20210428-181701 ") in new stack

– Executing [s@sub-record-check:8] Set (" SIP/203078.tenios.com-000000c4 ", " __FROMEXTEN=unknown ") in new stack

– Executing [s@sub-record-check:9] Set (" SIP/203078.tenios.com-000000c4 ", " __MON_FMT=wav ") in new stack

– Executing [s@sub-record-check:10] NoOp (" SIP/203078.tenios.com-000000c4 ", " Recordings initialized ") in new stack

– Executing [s@sub-record-check:11] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(ARG3=dontcare) ") in new stack

– Executing [s@sub-record-check:12] Set (" SIP/203078.tenios.com-000000c4 ", " REC_POLICY_MODE_SAVE= ") in new stack

– Executing [s@sub-record-check:13] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(REC_STATUS=NO) ") in new stack

– Executing [s@sub-record-check:14] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 2?checkaction ") in new stack

– Goto (sub-record-check,s,17)

– Executing [s@sub-record-check:17] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 1?sub-record-check,in,1 ") in new stack

– Goto (sub-record-check,in,1)

– Executing [in@sub-record-check:1] NoOp (" SIP/203078.tenios.com-000000c4 ", " Inbound Recording Check to s ") in new stack

– Executing [in@sub-record-check:2] Set (" SIP/203078.tenios.com-000000c4 ", " FROMEXTEN=unknown ") in new stack

– Executing [in@sub-record-check:3] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 13?Set(FROMEXTEN=+491603774112) ") in new stack

– Executing [in@sub-record-check:4] Gosub (" SIP/203078.tenios.com-000000c4 ", " recordcheck,1(dontcare,in,s) ") in new stack

– Executing [recordcheck@sub-record-check:1] NoOp (" SIP/203078.tenios.com-000000c4 ", " Starting recording check against dontcare ") in new stack

– Executing [recordcheck@sub-record-check:2] Goto (" SIP/203078.tenios.com-000000c4 ", " dontcare ") in new stack

– Goto (sub-record-check,recordcheck,3)

– Executing [recordcheck@sub-record-check:3] Return (" SIP/203078.tenios.com-000000c4 ", β€œβ€) in new stack

– Executing [in@sub-record-check:5] Return (" SIP/203078.tenios.com-000000c4 ", β€œβ€) in new stack

– Executing [s@ext-did:3] Set (" SIP/203078.tenios.com-000000c4 ", " CHANNEL(tonezone)=us ") in new stack

– Executing [s@ext-did:4] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(__FROM_DID=s) ") in new stack

– Executing [s@ext-did:5] Set (" SIP/203078.tenios.com-000000c4 ", " returnhere=1 ") in new stack

– Executing [s@ext-did:6] Gosub (" SIP/203078.tenios.com-000000c4 ", " app-blacklist-check,s,1() ") in new stack

– Executing [s@app-blacklist-check:1] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?blacklisted ") in new stack

– Executing [s@app-blacklist-check:2] Set (" SIP/203078.tenios.com-000000c4 ", " CALLED_BLACKLIST=1 ") in new stack

– Executing [s@app-blacklist-check:3] Return (" SIP/203078.tenios.com-000000c4 ", β€œβ€) in new stack

– Executing [s@ext-did:7] Set (" SIP/203078.tenios.com-000000c4 ", " CDR(did)=498003227766 ") in new stack

– Executing [s@ext-did:8] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0? ") in new stack

– Executing [s@ext-did:9] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0 ?Set(CALLERID(name)=+491603774112) ") in new stack

– Executing [s@ext-did:10] Set (" SIP/203078.tenios.com-000000c4 ", " __MOHCLASS= ") in new stack

– Executing [s@ext-did:11] Set (" SIP/203078.tenios.com-000000c4 ", " __REVERSAL_REJECT=FALSE ") in new stack

– Executing [s@ext-did:12] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 1?post-reverse-charge ") in new stack

– Goto (ext-did,s,14)

– Executing [s@ext-did:14] NoOp (" SIP/203078.tenios.com-000000c4 ", β€œβ€) in new stack

– Executing [s@ext-did:15] Set (" SIP/203078.tenios.com-000000c4 ", " __CALLINGNAMEPRES_SV=allowed_not_screened ") in new stack

– Executing [s@ext-did:16] Set (" SIP/203078.tenios.com-000000c4 ", " __CALLINGNUMPRES_SV=allowed_not_screened ") in new stack

– Executing [s@ext-did:17] Set (" SIP/203078.tenios.com-000000c4 ", " CALLERID(name-pres)=allowed_not_screened ") in new stack

– Executing [s@ext-did:18] Set (" SIP/203078.tenios.com-000000c4 ", " CALLERID(num-pres)=allowed_not_screened ") in new stack

– Executing [s@ext-did:19] NoOp (" SIP/203078.tenios.com-000000c4 ", " CallerID Entry Point ") in new stack

– Executing [s@ext-did:20] Set (" SIP/203078.tenios.com-000000c4 ", " __CRM_DIRECTION=INBOUND ") in new stack

– Executing [s@ext-did:21] Set (" SIP/203078.tenios.com-000000c4 ", " __CRM_SOURCE=+491603774112 ") in new stack

– Executing [s@ext-did:22] Set (" SIP/203078.tenios.com-000000c4 ", " __CRM_LINKEDID=1619626621.239 ") in new stack

– Executing [s@ext-did:23] AGI (" SIP/203078.tenios.com-000000c4 ", " agi://127.0.0.1/sangomacrm.agi,true ") in new stack

– <SIP/203078.tenios.com-000000c4>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0

– Executing [s@ext-did:24] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1) ") in new stack

– Executing [s@ext-did:25] Goto (" SIP/203078.tenios.com-000000c4 ", " from-did-direct,1,1 ") in new stack

– Goto (from-did-direct,1,1)

– Executing [1@from-did-direct:1] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 1?ext-local,1,1:followme-check,1,1 ") in new stack

– Goto (ext-local,1,1)

– Executing [1@ext-local:1] Set (" SIP/203078.tenios.com-000000c4 ", " __RINGTIMER=15 ") in new stack

– Executing [1@ext-local:2] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(__CWIGNORE=) ") in new stack

– Executing [1@ext-local:3] Macro (" SIP/203078.tenios.com-000000c4 ", " exten-vm,novm,1,0,0,0 ") in new stack

– Executing [s@macro-exten-vm:1] Macro (" SIP/203078.tenios.com-000000c4 ", " user-callerid, ") in new stack

– Executing [s@macro-user-callerid:1] Set (" SIP/203078.tenios.com-000000c4 ", " TOUCH_MONITOR=1619626621.239 ") in new stack

– Executing [s@macro-user-callerid:2] Set (" SIP/203078.tenios.com-000000c4 ", " AMPUSER=+491603774112 ") in new stack

– Executing [s@macro-user-callerid:3] Set (" SIP/203078.tenios.com-000000c4 ", " HOTDESCKCHAN=203078.tenios.com-000000c4 ") in new stack

– Executing [s@macro-user-callerid:4] Set (" SIP/203078.tenios.com-000000c4 ", " HOTDESKEXTEN=203078.tenios.com ") in new stack

– Executing [s@macro-user-callerid:5] Set (" SIP/203078.tenios.com-000000c4 ", " HOTDESKCALL=0 ") in new stack

– Executing [s@macro-user-callerid:6] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(HOTDESKCALL=1) ") in new stack

– Executing [s@macro-user-callerid:7] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(CALLERID(name)=) ") in new stack

– Executing [s@macro-user-callerid:8] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?report ") in new stack

– Executing [s@macro-user-callerid:9] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 1?Set(REALCALLERIDNUM=+491603774112) ") in new stack

– Executing [s@macro-user-callerid:10] Set (" SIP/203078.tenios.com-000000c4 ", " AMPUSER= ") in new stack

– Executing [s@macro-user-callerid:11] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?limit ") in new stack

– Executing [s@macro-user-callerid:12] Set (" SIP/203078.tenios.com-000000c4 ", " AMPUSERCIDNAME= ") in new stack

– Executing [s@macro-user-callerid:13] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(__CIDMASQUERADING=TRUE) ") in new stack

– Executing [s@macro-user-callerid:14] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 1?report ") in new stack

– Goto (macro-user-callerid,s,23)

– Executing [s@macro-user-callerid:23] NoOp (" SIP/203078.tenios.com-000000c4 ", " Macro Depth is 2 ") in new stack

– Executing [s@macro-user-callerid:24] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 1?report2:macroerror ") in new stack

– Goto (macro-user-callerid,s,25)

– Executing [s@macro-user-callerid:25] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?continue ") in new stack

– Executing [s@macro-user-callerid:26] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 1?Set(__CALLEE_ACCOUNCODE=) ") in new stack

– Executing [s@macro-user-callerid:27] Set (" SIP/203078.tenios.com-000000c4 ", " __TTL=64 ") in new stack

– Executing [s@macro-user-callerid:28] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 1?continue ") in new stack

– Goto (macro-user-callerid,s,44)

– Executing [s@macro-user-callerid:44] Set (" SIP/203078.tenios.com-000000c4 ", " CALLERID(number)=+491603774112 ") in new stack

– Executing [s@macro-user-callerid:45] Set (" SIP/203078.tenios.com-000000c4 ", " CALLERID(name)=+491603774112 ") in new stack

– Executing [s@macro-user-callerid:46] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?cnum ") in new stack

– Executing [s@macro-user-callerid:47] Set (" SIP/203078.tenios.com-000000c4 ", " CDR(cnam)=+491603774112 ") in new stack

– Executing [s@macro-user-callerid:48] Set (" SIP/203078.tenios.com-000000c4 ", " CDR(cnum)=+491603774112 ") in new stack

– Executing [s@macro-user-callerid:49] Set (" SIP/203078.tenios.com-000000c4 ", " CHANNEL(language)=de_DE ") in new stack

– Executing [s@macro-exten-vm:2] Set (" SIP/203078.tenios.com-000000c4 ", " RingGroupMethod=none ") in new stack

– Executing [s@macro-exten-vm:3] Set (" SIP/203078.tenios.com-000000c4 ", " __EXTTOCALL=1 ") in new stack

– Executing [s@macro-exten-vm:4] Set (" SIP/203078.tenios.com-000000c4 ", " __PICKUPMARK=1 ") in new stack

– Executing [s@macro-exten-vm:5] Set (" SIP/203078.tenios.com-000000c4 ", " RT= ") in new stack

– Executing [s@macro-exten-vm:6] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Macro(vm,novm,DIRECTDIAL,) ") in new stack

– Executing [s@macro-exten-vm:7] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?MacroExit() ") in new stack

– Executing [s@macro-exten-vm:8] ExecIf (" SIP/203078.tenios.com-000000c4 ", " *0?Gosub(ext-intercom,801,1()) ") in new stack

– Executing [s@macro-exten-vm:9] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?MacroExit() ") in new stack

– Executing [s@macro-exten-vm:10] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?ChanSpy(PJSIP/1,q) ") in new stack

– Executing [s@macro-exten-vm:11] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?MacroExit() ") in new stack

[2021-04-28 18:17:02] ERROR [24465][C-000000d4]: res_pjsip_header_funcs.c : 454 func_read_header : This function requires a PJSIP channel.

– Executing [s@macro-exten-vm:12] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Macro(vm,novm,DIRECTDIAL,) ") in new stack

[2021-04-28 18:17:02] ERROR [24465][C-000000d4]: res_pjsip_header_funcs.c : 454 func_read_header : This function requires a PJSIP channel.

[2021-04-28 18:17:02] ERROR [24465][C-000000d4]: res_pjsip_header_funcs.c : 454 func_read_header : This function requires a PJSIP channel.

– Executing [s@macro-exten-vm:13] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?MacroExit() ") in new stack

[2021-04-28 18:17:02] ERROR [24465][C-000000d4]: res_pjsip_header_funcs.c : 454 func_read_header : This function requires a PJSIP channel.

[2021-04-28 18:17:02] ERROR [24465][C-000000d4]: res_pjsip_header_funcs.c : 454 func_read_header : This function requires a PJSIP channel.

– Executing [s@macro-exten-vm:14] ExecIf (" SIP/203078.tenios.com-000000c4 ", " *0?Gosub(ext-intercom,801,1()) ") in new stack

[2021-04-28 18:17:02] ERROR [24465][C-000000d4]: res_pjsip_header_funcs.c : 454 func_read_header : This function requires a PJSIP channel.

[2021-04-28 18:17:02] ERROR [24465][C-000000d4]: res_pjsip_header_funcs.c : 454 func_read_header : This function requires a PJSIP channel.

– Executing [s@macro-exten-vm:15] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?MacroExit() ") in new stack

[2021-04-28 18:17:02] ERROR [24465][C-000000d4]: res_pjsip_header_funcs.c : 454 func_read_header : This function requires a PJSIP channel.

[2021-04-28 18:17:02] ERROR [24465][C-000000d4]: res_pjsip_header_funcs.c : 454 func_read_header : This function requires a PJSIP channel.

– Executing [s@macro-exten-vm:16] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?ChanSpy(PJSIP/1,q) ") in new stack

[2021-04-28 18:17:02] ERROR [24465][C-000000d4]: res_pjsip_header_funcs.c : 454 func_read_header : This function requires a PJSIP channel.

[2021-04-28 18:17:02] ERROR [24465][C-000000d4]: res_pjsip_header_funcs.c : 454 func_read_header : This function requires a PJSIP channel.

– Executing [s@macro-exten-vm:17] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?MacroExit() ") in new stack

[2021-04-28 18:17:02] ERROR [24465][C-000000d4]: res_pjsip_header_funcs.c : 454 func_read_header : This function requires a PJSIP channel.

– Executing [s@macro-exten-vm:18] Gosub (" SIP/203078.tenios.com-000000c4 ", " sub-record-check,s,1(exten,1,dontcare) ") in new stack

– Executing [s@sub-record-check:1] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 13?initialized ") in new stack

– Goto (sub-record-check,s,10)

– Executing [s@sub-record-check:10] NoOp (" SIP/203078.tenios.com-000000c4 ", " Recordings initialized ") in new stack

– Executing [s@sub-record-check:11] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(ARG3=dontcare) ") in new stack

– Executing [s@sub-record-check:12] Set (" SIP/203078.tenios.com-000000c4 ", " REC_POLICY_MODE_SAVE= ") in new stack

– Executing [s@sub-record-check:13] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(REC_STATUS=NO) ") in new stack

– Executing [s@sub-record-check:14] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 5?checkaction ") in new stack

– Goto (sub-record-check,s,17)

– Executing [s@sub-record-check:17] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 1?sub-record-check,exten,1 ") in new stack

– Goto (sub-record-check,exten,1)

– Executing [exten@sub-record-check:1] NoOp (" SIP/203078.tenios.com-000000c4 ", " Exten Recording Check between +491603774112 and 1 ") in new stack

– Executing [exten@sub-record-check:2] Set (" SIP/203078.tenios.com-000000c4 ", " CALLTYPE=external ") in new stack

– Executing [exten@sub-record-check:3] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(CALLTYPE=) ") in new stack

– Executing [exten@sub-record-check:4] Set (" SIP/203078.tenios.com-000000c4 ", " CALLEE=dontcare ") in new stack

– Executing [exten@sub-record-check:5] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(CALLEE=dontcare) ") in new stack

– Executing [exten@sub-record-check:6] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 1?callee ") in new stack

– Goto (sub-record-check,exten,11)

– Executing [exten@sub-record-check:11] Gosub (" SIP/203078.tenios.com-000000c4 ", " recordcheck,1(dontcare,external,1) ") in new stack

– Executing [recordcheck@sub-record-check:1] NoOp (" SIP/203078.tenios.com-000000c4 ", " Starting recording check against dontcare ") in new stack

– Executing [recordcheck@sub-record-check:2] Goto (" SIP/203078.tenios.com-000000c4 ", " dontcare ") in new stack

– Goto (sub-record-check,recordcheck,3)

– Executing [recordcheck@sub-record-check:3] Return (" SIP/203078.tenios.com-000000c4 ", β€œβ€) in new stack

– Executing [exten@sub-record-check:12] Return (" SIP/203078.tenios.com-000000c4 ", β€œβ€) in new stack

– Executing [s@macro-exten-vm:19] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 1?macrodial ") in new stack

– Goto (macro-exten-vm,s,25)

– Executing [s@macro-exten-vm:25] GosubIf (" SIP/203078.tenios.com-000000c4 ", " 0?clrheader,1() ") in new stack

– Executing [s@macro-exten-vm:26] Macro (" SIP/203078.tenios.com-000000c4 ", " dial-one,HhTtr,1 ") in new stack

– Executing [s@macro-dial-one:1] Set (" SIP/203078.tenios.com-000000c4 ", " DEXTEN=1 ") in new stack

– Executing [s@macro-dial-one:2] Set (" SIP/203078.tenios.com-000000c4 ", " __CRM_SOURCE=+491603774112 ") in new stack

– Executing [s@macro-dial-one:3] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(__EXTTOCALL=1) ") in new stack

– Executing [s@macro-dial-one:4] Set (" SIP/203078.tenios.com-000000c4 ", " DIALSTATUS_CW= ") in new stack

– Executing [s@macro-dial-one:5] GosubIf (" SIP/203078.tenios.com-000000c4 ", " 0?screen,1() ") in new stack

– Executing [s@macro-dial-one:6] GosubIf (" SIP/203078.tenios.com-000000c4 ", " 0?cf,1() ") in new stack

– Executing [s@macro-dial-one:7] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 1?skip1 ") in new stack

– Goto (macro-dial-one,s,10)

– Executing [s@macro-dial-one:10] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?nodial ") in new stack

– Executing [s@macro-dial-one:11] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?continue ") in new stack

– Executing [s@macro-dial-one:12] Set (" SIP/203078.tenios.com-000000c4 ", " EXTHASCW=ENABLED ") in new stack

– Executing [s@macro-dial-one:13] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?next1:cwinusebusy ") in new stack

– Goto (macro-dial-one,s,25)

– Executing [s@macro-dial-one:25] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?next3:continue ") in new stack

– Goto (macro-dial-one,s,27)

– Executing [s@macro-dial-one:27] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?nodial ") in new stack

– Executing [s@macro-dial-one:28] GosubIf (" SIP/203078.tenios.com-000000c4 ", " 1?dstring,1():dlocal,1() ") in new stack

– Executing [dstring@macro-dial-one:1] Set (" SIP/203078.tenios.com-000000c4 ", " DSTRING= ") in new stack

– Executing [dstring@macro-dial-one:2] Set (" SIP/203078.tenios.com-000000c4 ", " DEVICES=1 ") in new stack

– Executing [dstring@macro-dial-one:3] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Return() ") in new stack

– Executing [dstring@macro-dial-one:4] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(DEVICES=) ") in new stack

– Executing [dstring@macro-dial-one:5] Set (" SIP/203078.tenios.com-000000c4 ", " LOOPCNT=1 ") in new stack

– Executing [dstring@macro-dial-one:6] Set (" SIP/203078.tenios.com-000000c4 ", " ITER=1 ") in new stack

– Executing [dstring@macro-dial-one:7] Set (" SIP/203078.tenios.com-000000c4 ", " THISDIAL=PJSIP/1 ") in new stack

– Executing [dstring@macro-dial-one:8] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?docheck ") in new stack

– Executing [dstring@macro-dial-one:9] NoOp (" SIP/203078.tenios.com-000000c4 ", " Debug: Found PJSIP Destination PJSIP/1 ") in new stack

– Executing [dstring@macro-dial-one:10] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?doset ") in new stack

– Executing [dstring@macro-dial-one:11] NoOp (" SIP/203078.tenios.com-000000c4 ", " Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS ") in new stack

– Executing [dstring@macro-dial-one:12] Set (" SIP/203078.tenios.com-000000c4 ", " THISDIAL=PJSIP/1/sip:[email protected]:63569;x-ast-orig-host=192.168.178.87:5060 ") in new stack

– Executing [dstring@macro-dial-one:13] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(DIALSTATUS=CHANUNAVAIL) ") in new stack

– Executing [dstring@macro-dial-one:14] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?skipset ") in new stack

– Executing [dstring@macro-dial-one:15] Set (" SIP/203078.tenios.com-000000c4 ", " DSTRING=PJSIP/1/sip:[email protected]:63569;x-ast-orig-host=192.168.178.87:5060& ") in new stack

– Executing [dstring@macro-dial-one:16] Set (" SIP/203078.tenios.com-000000c4 ", " ITER=2 ") in new stack

– Executing [dstring@macro-dial-one:17] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?begin ") in new stack

– Executing [dstring@macro-dial-one:18] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Return() ") in new stack

– Executing [dstring@macro-dial-one:19] Set (" SIP/203078.tenios.com-000000c4 ", " DSTRING=PJSIP/1/sip:[email protected]:63569;x-ast-orig-host=192.168.178.87:5060 ") in new stack

– Executing [dstring@macro-dial-one:20] Return (" SIP/203078.tenios.com-000000c4 ", β€œβ€) in new stack

– Executing [s@macro-dial-one:29] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?nodial ") in new stack

– Executing [s@macro-dial-one:30] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?skiptrace ") in new stack

– Executing [s@macro-dial-one:31] GosubIf (" SIP/203078.tenios.com-000000c4 ", " 1?ctset,1():ctclear,1() ") in new stack

– Executing [ctset@macro-dial-one:1] Set (" SIP/203078.tenios.com-000000c4 ", " DB(CALLTRACE/1)=+491603774112 ") in new stack

– Executing [ctset@macro-dial-one:2] Return (" SIP/203078.tenios.com-000000c4 ", β€œβ€) in new stack

– Executing [s@macro-dial-one:32] Set (" SIP/203078.tenios.com-000000c4 ", " D_OPTIONS=HhTtr ") in new stack

– Executing [s@macro-dial-one:33] GosubIf (" SIP/203078.tenios.com-000000c4 ", " 0?func-set-sipheader,s,1(Alert-Info,) ") in new stack

– Executing [s@macro-dial-one:34] NoOp (" SIP/203078.tenios.com-000000c4 ", " Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack

– Executing [s@macro-dial-one:35] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(ALERT_INFO=) ") in new stack

– Executing [s@macro-dial-one:36] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(ALERT_INFO=) ") in new stack

– Executing [s@macro-dial-one:37] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(ALERT_INFO=) ") in new stack

– Executing [s@macro-dial-one:38] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(ALERT_INFO=Normal;volume=) ") in new stack

– Executing [s@macro-dial-one:39] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(ALERT_INFO=Normal;volume=) ") in new stack

– Executing [s@macro-dial-one:40] GosubIf (" SIP/203078.tenios.com-000000c4 ", " 0?func-set-sipheader,s,1(Alert-Info,) ") in new stack

– Executing [s@macro-dial-one:41] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(CHANNEL(musicclass)=) ") in new stack

– Executing [s@macro-dial-one:42] GosubIf (" SIP/203078.tenios.com-000000c4 ", " 0?qwait,1() ") in new stack

– Executing [s@macro-dial-one:43] Set (" SIP/203078.tenios.com-000000c4 ", " __CWIGNORE= ") in new stack

– Executing [s@macro-dial-one:44] Set (" SIP/203078.tenios.com-000000c4 ", " __KEEPCID=TRUE ") in new stack

– Executing [s@macro-dial-one:45] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 0?usegoto,1 ") in new stack

– Executing [s@macro-dial-one:46] GotoIf (" SIP/203078.tenios.com-000000c4 ", " 1?godial ") in new stack

– Goto (macro-dial-one,s,51)

– Executing [s@macro-dial-one:51] Macro (" SIP/203078.tenios.com-000000c4 ", " dialout-one-predial-hook, ") in new stack

– Executing [s@macro-dialout-one-predial-hook:1] MacroExit (" SIP/203078.tenios.com-000000c4 ", β€œβ€) in new stack

– Executing [s@macro-dial-one:52] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 1?Set(D_OPTIONS=HhtrI) ") in new stack

– Executing [s@macro-dial-one:53] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(CWRING=r(callwaiting)):Set(CWRING=) ") in new stack

– Executing [s@macro-dial-one:54] NoOp (" SIP/203078.tenios.com-000000c4 ", β€œβ€) in new stack

– Executing [s@macro-dial-one:55] ExecIf (" SIP/203078.tenios.com-000000c4 ", " 0?Set(D_OPTIONS=HhtrIg) ") in new stack

– Executing [s@macro-dial-one:56] Dial (" SIP/203078.tenios.com-000000c4 ", " PJSIP/1/sip:[email protected]:63569;x-ast-orig-host=192.168.178.87:5060,HhtrIb(func-apply-sipheaders^s^1) ") in new stack

– PJSIP/1-0000001b Internal Gosub(func-apply-sipheaders,s,1) start

– Executing [s@func-apply-sipheaders:1] ExecIf (" PJSIP/1-0000001b ", " 1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1) ") in new stack

– Executing [s@func-apply-sipheaders:2] NoOp (" PJSIP/1-0000001b ", " Applying SIP Headers to channel PJSIP/1-0000001b ") in new stack

– Executing [s@func-apply-sipheaders:3] Set (" PJSIP/1-0000001b ", " TECH=PJSIP ") in new stack

– Executing [s@func-apply-sipheaders:4] Set (" PJSIP/1-0000001b ", " SIPHEADERKEYS= ") in new stack

– Executing [s@func-apply-sipheaders:5] While (" PJSIP/1-0000001b ", " 0 ") in new stack

– Jumping to priority 13

– Executing [s@func-apply-sipheaders:14] Return (" PJSIP/1-0000001b ", β€œβ€) in new stack

== Spawn extension (from-internal, 1, 1) exited non-zero on β€˜PJSIP/1-0000001b’

– PJSIP/1-0000001b Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=

– Called PJSIP/1/sip:[email protected]:63569;x-ast-orig-host=192.168.178.87:5060

== Using SIP RTP Audio TOS bits 184

== Using SIP RTP Audio TOS bits 184 in TCLASS field.

== Using SIP RTP Audio CoS mark 5

– Connected line update to SIP/203078.tenios.com-000000c4 prevented.

– PJSIP/1-0000001b is ringing

– PJSIP/1-0000001b is ringing

– PJSIP/1-0000001b Internal Gosub(crm-hangup,s,1) start

OK, so it appears that FreePBX is somehow generating incorrect dialplan.

At the Asterisk command prompt, type
dialplan show ext-did
and you should see something like

[ Context 'ext-did' created by 'pbx_config' ]
  'foo' =>          1. Noop(bar)                                  [extensions_additional.conf:5510]
  Include =>        'ext-did-custom'                              [pbx_config]
  Include =>        'ext-did-0001'                                [pbx_config]
  Include =>        'ext-did-0002'                                [pbx_config]

Then, issue
dialplan show ext-did-0002
which should show code for all inbound routes that have a DID but no CID specified.
If you have no routes with a CID specified, you may need to show ext-did-0001 instead.

The question is whether 498003227766 appears as an extension in that output. If not, does it appear in garbled form or is it just missing?