Freepbx 16 with new SIP dial number plan issue? SIP username gets called instead of actual phone number

ogghi · September 30, 2022, 7:17am

Hi there,

—Crossposting from Reddit—

since years there is a SIP trunk set up for a specific purpose.

Now I added another one, this receives calls just fine, but sending them out it tries to call the SIP username instead of the actual number it should dial.

Dial plan is the same as for the other trunk. They are both registered at peoplefone if that matters.

Dial pattern in outbound routes is “X.”

Dial pattern in general trunk settings: “.”

This works perfectly fine on one, not on the other though.

Settings are just the same…ideas here? Might be (as so often) something stupid…

david55 · September 30, 2022, 9:54am

I don’t see how this could happen unless you customised the dialplan to do this, or the provider is broken.

Please provide logs as in Providing Great Debug - Support Services - Documentation and also please enable protocol logging (CLI command “pjsip set logger on”, or with the obsolescent channel driver, “sip set debug on”.

ogghi · September 30, 2022, 11:05am

Hi David, cool name

Please find the sip debug log when I try to call. Redacted info.
Thanks for helping!

freepbx2*CLI> sip set debug on
SIP Debugging enabled

<--- SIP read from UDP:SIPserverIP:5060 --->
OPTIONS sip:[email protected]:5160 SIP/2.0
Via: SIP/2.0/UDP SIPserverIP:5060;branch=z9hG4bK7574917
From: sip:[email protected];tag=uloc-631d1233-29db-547fb21-e006c117-daf12ffa
To: sip:[email protected]:5160
Call-ID: fdd4b955-128c3446-900b562@SIPserverIP
CSeq: 1 OPTIONS
Content-Length: 0

<------------->
--- (7 headers 0 lines) ---
Sending to SIPserverIP:5060 (NAT)
Looking for SIPserverUserNAME in from-sip-external (domain 172.16.0.158)

<--- Transmitting (NAT) to SIPserverIP:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP SIPserverIP:5060;branch=z9hG4bK7574917;received=SIPserverIP;rport=5060
From: sip:[email protected];tag=uloc-631d1233-29db-547fb21-e006c117-daf12ffa
To: sip:[email protected]:5160;tag=as2df5e058
Call-ID: fdd4b955-128c3446-900b562@SIPserverIP
CSeq: 1 OPTIONS
Server: FPBX-16.0.21.21(13.38.3)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:172.16.0.158:5160>
Accept: application/sdp
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog 'fdd4b955-128c3446-900b562@SIPserverIP' in 32000 ms (Method: OPTIONS)
Really destroying SIP dialog 'fdd4b955-65e63446-befa562@SIPserverIP' Method: OPTIONS
[2022-09-30 12:56:36] SECURITY[3296]: res_security_log.c:116 security_event_stasis_cb: SecurityEvent="SuccessfulAuth",EventTV="2022-09-30T12:56:36.433+0200",Severity="Informational",Service="AMI",EventVersion="1",AccountID="admin",SessionID="0x7faabc011d08",LocalAddress="IPV4/TCP/0.0.0.0/5038",RemoteAddress="IPV4/TCP/127.0.0.1/35440",UsingPassword="0",SessionTV="2022-09-30T12:56:36.433+0200"
[2022-09-30 12:56:36] SECURITY[3296]: res_security_log.c:116 security_event_stasis_cb: SecurityEvent="SuccessfulAuth",EventTV="2022-09-30T12:56:36.967+0200",Severity="Informational",Service="AMI",EventVersion="1",AccountID="admin",SessionID="0x7faabc011d08",LocalAddress="IPV4/TCP/0.0.0.0/5038",RemoteAddress="IPV4/TCP/127.0.0.1/35446",UsingPassword="0",SessionTV="2022-09-30T12:56:36.967+0200"
freepbx2*CLI> 
Disconnected from Asterisk server
Asterisk cleanly ending (0).
Executing last minute cleanups
[root@freepbx2 ~]# tail -f /var/log/asterisk/full
Server: FPBX-16.0.21.21(13.38.3)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:172.16.0.158:5160>
Accept: application/sdp
Content-Length: 0


<------------>
[2022-09-30 12:56:50] VERBOSE[3269] chan_sip.c: Scheduling destruction of SIP dialog 'fdd4b955-e2e04446-120b562@SIPserverIP' in 32000 ms (Method: OPTIONS)
[2022-09-30 12:56:51] VERBOSE[3269] chan_sip.c: Really destroying SIP dialog 'fdd4b955-f54b3446-200b562@SIPserverIP' Method: OPTIONS
[2022-09-30 12:56:57] VERBOSE[3269] chan_sip.c: 
<--- SIP read from UDP:SIPserverIP:5060 --->
OPTIONS sip:[email protected]:5160 SIP/2.0
Via: SIP/2.0/UDP SIPserverIP:5060;branch=z9hG4bK4115889
From: sip:[email protected];tag=uloc-631d1233-29db-547fb21-e006c117-48972ffa
To: sip:[email protected]:5160
Call-ID: fdd4b955-8f124446-820b562@SIPserverIP
CSeq: 1 OPTIONS
Content-Length: 0

<------------->
[2022-09-30 12:56:57] VERBOSE[3269] chan_sip.c: --- (7 headers 0 lines) ---
[2022-09-30 12:56:57] VERBOSE[3269] chan_sip.c: Sending to SIPserverIP:5060 (NAT)
[2022-09-30 12:56:57] VERBOSE[3269] chan_sip.c: Looking for SIPserverUserNAME in from-sip-external (domain 172.16.0.158)
[2022-09-30 12:56:57] VERBOSE[3269] chan_sip.c: 
<--- Transmitting (NAT) to SIPserverIP:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP SIPserverIP:5060;branch=z9hG4bK4115889;received=SIPserverIP;rport=5060
From: sip:[email protected];tag=uloc-631d1233-29db-547fb21-e006c117-48972ffa
To: sip:[email protected]:5160;tag=as5cb7bb0e
Call-ID: fdd4b955-8f124446-820b562@SIPserverIP
CSeq: 1 OPTIONS
Server: FPBX-16.0.21.21(13.38.3)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:172.16.0.158:5160>
Accept: application/sdp
Content-Length: 0


<------------>
[2022-09-30 12:56:57] VERBOSE[3269] chan_sip.c: Scheduling destruction of SIP dialog 'fdd4b955-8f124446-820b562@SIPserverIP' in 32000 ms (Method: OPTIONS)
[2022-09-30 12:56:59] VERBOSE[3269] chan_sip.c: Really destroying SIP dialog 'fdd4b955-128c3446-900b562@SIPserverIP' Method: OPTIONS
[2022-09-30 12:57:05] VERBOSE[3269] chan_sip.c: 
<--- SIP read from UDP:SIPserverIP:5060 --->
INVITE sip:[email protected]:5160 SIP/2.0
Record-Route: <sip:SIPserverIP;r2=on;lr=on;did=1c5.d573>
Record-Route: <sip:SIPserverIP2;r2=on;lr=on;did=1c5.d573>
Call-ID: 0cc9644e381f69e9a2fe754eb680e30e@anotherSIPip
CSeq: 1 INVITE
From: "callingNumber" <sip:callingNumber@anotherSIPip>;tag=1664535395694
To: <sip:90728959826@SIPserverIP2:5060>
Via: SIP/2.0/UDP SIPserverIP;branch=z9hG4bK8f59.1c7256cd7859cd02325fc73f9cb897fd.0
Via: SIP/2.0/UDP anotherSIPip:5060;rport=5060;branch=z9hG4bK-313130-06b0f86b97fcedbcef3f8e187c7c9883
Max-Forwards: 69
Contact: <sip:90728959826@anotherSIPip:5060;alias=anotherSIPip~5060~1>
Allow: ACK,CANCEL,BYE,INFO
Content-Type: application/sdp
Content-Length: 241

v=0
o=Sonus_UAC 5243 30799 IN IP4 SIPserverIP2
s=SIP Media Capabilities
c=IN IP4 SIPserverIP2
t=0 0
m=audio 15012 RTP/AVP 8 96
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
a=ptime:20
a=sendrecv
a=rtcp:15013
<------------->
[2022-09-30 12:57:05] VERBOSE[3269] chan_sip.c: --- (14 headers 12 lines) ---
[2022-09-30 12:57:05] VERBOSE[3269] chan_sip.c: Sending to SIPserverIP:5060 (NAT)
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] chan_sip.c: Sending to SIPserverIP:5060 (NAT)
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] chan_sip.c: Using INVITE request as basis request - 0cc9644e381f69e9a2fe754eb680e30e@anotherSIPip
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] chan_sip.c: Found peer 'SIPserverUserNAME' for 'callingNumber' from SIPserverIP:5060
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] netsock2.c: Using SIP RTP TOS bits 184
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] netsock2.c: Using SIP RTP CoS mark 5
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] chan_sip.c: Got SDP version 30799 and unique parts [Sonus_UAC 5243 IN IP4 SIPserverIP2]
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] chan_sip.c: Found RTP audio format 8
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] chan_sip.c: Found RTP audio format 96
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] chan_sip.c: Found audio description format PCMA for ID 8
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] chan_sip.c: Found audio description format telephone-event for ID 96
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] chan_sip.c: Capabilities: us - (ulaw|alaw|g722), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw)
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] chan_sip.c: Peer audio RTP is at port SIPserverIP2:15012
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] chan_sip.c: Looking for 90728959826 in from-trunk (domain 172.16.0.158)
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] sip/route.c: sip_route_dump: route/path hop: <sip:SIPserverIP;r2=on;lr=on;did=1c5.d573>
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] sip/route.c: sip_route_dump: route/path hop: <sip:SIPserverIP2;r2=on;lr=on;did=1c5.d573>
[2022-09-30 12:57:05] VERBOSE[3269][C-00000005] chan_sip.c: 
<--- Transmitting (NAT) to SIPserverIP:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP SIPserverIP;branch=z9hG4bK8f59.1c7256cd7859cd02325fc73f9cb897fd.0;received=SIPserverIP;rport=5060
Via: SIP/2.0/UDP anotherSIPip:5060;rport=5060;branch=z9hG4bK-313130-06b0f86b97fcedbcef3f8e187c7c9883
Record-Route: <sip:SIPserverIP;r2=on;lr=on;did=1c5.d573>
Record-Route: <sip:SIPserverIP2;r2=on;lr=on;did=1c5.d573>
From: "callingNumber" <sip:callingNumber@anotherSIPip>;tag=1664535395694
To: <sip:90728959826@SIPserverIP2:5060>
Call-ID: 0cc9644e381f69e9a2fe754eb680e30e@anotherSIPip
CSeq: 1 INVITE
Server: FPBX-16.0.21.21(13.38.3)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5160>
Content-Length: 0


<------------>
[2022-09-30 12:57:05] SECURITY[3296] res_security_log.c: SecurityEvent="SuccessfulAuth",EventTV="2022-09-30T12:57:05.464+0200",Severity="Informational",Service="SIP",EventVersion="1",AccountID="90728959826",SessionID="0x7fa9d00138d8",LocalAddress="IPV4/UDP/172.16.0.158/5160",RemoteAddress="IPV4/UDP/SIPserverIP/5060",UsingPassword="0"
[2022-09-30 12:57:05] VERBOSE[7699][C-00000005] pbx.c: Executing [90728959826@from-trunk:1] Set("SIP/SIPserverUserNAME-00000007", "__FROM_DID=90728959826") in new stack
[2022-09-30 12:57:05] VERBOSE[7699][C-00000005] pbx.c: Executing [90728959826@from-trunk:2] NoOp("SIP/SIPserverUserNAME-00000007", "Received an unknown call with DID set to 90728959826") in new stack
[2022-09-30 12:57:05] VERBOSE[7699][C-00000005] pbx.c: Executing [90728959826@from-trunk:3] Goto("SIP/SIPserverUserNAME-00000007", "s,a2") in new stack
[2022-09-30 12:57:05] VERBOSE[7699][C-00000005] pbx_builtins.c: Goto (from-trunk,s,2)
[2022-09-30 12:57:05] VERBOSE[7699][C-00000005] pbx.c: Executing [s@from-trunk:2] Answer("SIP/SIPserverUserNAME-00000007", "") in new stack
[2022-09-30 12:57:05] VERBOSE[7699][C-00000005] chan_sip.c: Audio is at 12658
[2022-09-30 12:57:05] VERBOSE[7699][C-00000005] chan_sip.c: Adding codec alaw to SDP
[2022-09-30 12:57:05] VERBOSE[7699][C-00000005] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[2022-09-30 12:57:05] VERBOSE[7699][C-00000005] chan_sip.c: 
<--- Reliably Transmitting (NAT) to SIPserverIP:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP SIPserverIP;branch=z9hG4bK8f59.1c7256cd7859cd02325fc73f9cb897fd.0;received=SIPserverIP;rport=5060
Via: SIP/2.0/UDP anotherSIPip:5060;rport=5060;branch=z9hG4bK-313130-06b0f86b97fcedbcef3f8e187c7c9883
Record-Route: <sip:SIPserverIP;r2=on;lr=on;did=1c5.d573>
Record-Route: <sip:SIPserverIP2;r2=on;lr=on;did=1c5.d573>
From: "callingNumber" <sip:callingNumber@anotherSIPip>;tag=1664535395694
To: <sip:90728959826@SIPserverIP2:5060>;tag=as334fca4e
Call-ID: 0cc9644e381f69e9a2fe754eb680e30e@anotherSIPip
CSeq: 1 INVITE
Server: FPBX-16.0.21.21(13.38.3)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5160>
Content-Type: application/sdp
Content-Length: 249

v=0
o=root 1712940630 1712940630 IN IP4 172.16.0.158
s=Asterisk PBX 13.38.3
c=IN IP4 172.16.0.158
t=0 0
m=audio 12658 RTP/AVP 8 96
a=rtpmap:8 PCMA/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

<------------>
[2022-09-30 12:57:05] VERBOSE[3269] chan_sip.c: 
<--- SIP read from UDP:SIPserverIP:5060 --->
ACK sip:[email protected]:5160 SIP/2.0
Call-ID: 0cc9644e381f69e9a2fe754eb680e30e@anotherSIPip
CSeq: 1 ACK
Via: SIP/2.0/UDP SIPserverIP;branch=z9hG4bK8f59.33f18e9674cb1679a0e8fb569b8b318d.0
Via: SIP/2.0/UDP anotherSIPip:5060;rport=5060;branch=z9hG4bK-313130-1a6a76e02e2af8d02daa23aaba4580d2
From: "callingNumber" <sip:callingNumber@anotherSIPip>;tag=1664535395694
To: <sip:90728959826@SIPserverIP2:5060>;tag=as334fca4e
Max-Forwards: 69
Content-Length: 0

<------------->
[2022-09-30 12:57:05] VERBOSE[3269] chan_sip.c: --- (9 headers 0 lines) ---
[2022-09-30 12:57:05] VERBOSE[7699][C-00000005] pbx.c: Executing [s@from-trunk:3] Log("SIP/SIPserverUserNAME-00000007", "WARNING,Friendly Scanner from SIPserverIP;branch=z9hG4bK8f59.1c7256cd7859cd02325fc73f9cb897fd.0") in new stack
[2022-09-30 12:57:05] WARNING[7699][C-00000005] Ext. s: Friendly Scanner from SIPserverIP;branch=z9hG4bK8f59.1c7256cd7859cd02325fc73f9cb897fd.0
[2022-09-30 12:57:05] VERBOSE[7699][C-00000005] pbx.c: Executing [s@from-trunk:4] Wait("SIP/SIPserverUserNAME-00000007", "2") in new stack
[2022-09-30 12:57:07] VERBOSE[7699][C-00000005] pbx.c: Executing [s@from-trunk:5] Playback("SIP/SIPserverUserNAME-00000007", "ss-noservice") in new stack
[2022-09-30 12:57:07] VERBOSE[7699][C-00000005] file.c: <SIP/SIPserverUserNAME-00000007> Playing 'ss-noservice.alaw' (language 'en')
^C

david55 · September 30, 2022, 11:17am

Nothing gets called in this log.

There is no user name in the incoming request.

This has failed because it is addressed to DID 90728959826, but you have no incoming route that accepts that DID.

ogghi · September 30, 2022, 11:26am

That’s the thing. This 90728959826 does not exist, it’s rather the SIP server user name!

david55 · September 30, 2022, 11:47am

If you are registering, you have the wrong value in the register string for the contact user name. Otherwise the problem lies with the provider.

If registering, this is Trunks Module - User Guide - PBX GUI - Documentation in the GUI.

ogghi · September 30, 2022, 12:07pm

That looks all correct to me, and ist just a copy (with adapted values of course) from the working trunk also registered with peoplefone

(I removed the SIP password…)

david55 · September 30, 2022, 1:08pm

Your register string (the part after the /), is telling the provider to send calls to
which you say is not the DID you have configured. That part of the string must be the required DID, that you have set on the incoming route.

ogghi · October 3, 2022, 6:03am

Thanks!

This has been solved by setting the correct DID in incoming route.

Still I don’t know why the DID is configured with a different scheme in the other trunk config (same provider)… The new one is just the number (044…, where 044 is a local Swiss prefix) whereas the other trunk has 4144… with the 41 added for Switzerland

But as long as all works it’s good!

system · October 10, 2022, 6:03am

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