Unable to find user the sip trunk is registered on.

Status
Not open for further replies.

slazer2au

New Member
Feb 17, 2020
7
0
1
34
I have been trying to work this one out for a few days and I am not getting anywhere.

We have a sip trunk from our FusionPBX to a Anynode SBC for Microsoft Teams calling. Fusion does not have a problem with calls destined for Teams. The SBC is saying it has correctly registered to Fusion and the SBC is showing up on the registrations page and outbound calls is working for all but one user.

The single user on teams who is unable to call out from their teams client is getting a [CALL_REJECTED] from FusionPBX.
I am stumped with this one as 3 other users are working perfectly while this one user isn't.

The oddest thing I find is this message

2020-02-26 12:07:46.391218 [WARNING] sofia_reg.c:2935 Can't find user [2142439989@cts.polyfone.com.au] from 202.153.68.55
You must define a domain called 'cts.polyfone.com.au' in your directory and add a user with the id="2142439989" attribute
and you must configure your device to use the proper domain in it's authentication credentials.

Both the domain and user account are on Fusion as the SBC registered and other users are working.

Fusion log of the failed call is below. I have also attached the Anynode trace if it helps, although you will have to get the analyzer from Anynode

2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.371176 [NOTICE] switch_channel.c:1104 New Channel sofia/public/0755609559@202.153.68.55:5062 [2dcafc92-0f52-4c03-8617-635b9d52e447]
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.371176 [DEBUG] switch_core_state_machine.c:584 (sofia/public/0755609559@202.153.68.55:5062) Running State Change CS_NEW (Cur 7 Tot 811815)
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.371176 [DEBUG] sofia.c:10092 sofia/public/0755609559@202.153.68.55:5062 receiving invite from 202.153.68.55:5062 version: 1.8.5 -6-31281a0bf1 64bit
2020-02-26 12:07:46.371176 [DEBUG] sofia.c:10263 IP 202.153.68.55 Rejected by acl "domains". Falling back to Digest auth.
2020-02-26 12:07:46.371176 [WARNING] sofia_reg.c:1798 SIP auth challenge (INVITE) on sofia profile 'public' for [0417008664@cts.polyfone.com.au] from ip 202.153.68.55
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.371176 [DEBUG] switch_core_state_machine.c:603 (sofia/public/0755609559@202.153.68.55:5062) State NEW
2020-02-26 12:07:46.371176 [DEBUG] sofia.c:2413 detaching session 2dcafc92-0f52-4c03-8617-635b9d52e447
2020-02-26 12:07:46.371176 [DEBUG] sofia.c:2522 Re-attaching to session 2dcafc92-0f52-4c03-8617-635b9d52e447
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.391218 [DEBUG] sofia.c:10092 sofia/public/0755609559@202.153.68.55:5062 receiving invite from 202.153.68.55:5062 version: 1.8.5 -6-31281a0bf1 64bit
2020-02-26 12:07:46.391218 [DEBUG] sofia.c:10263 IP 202.153.68.55 Rejected by acl "domains". Falling back to Digest auth.
2020-02-26 12:07:46.391218 [WARNING] sofia_reg.c:2935 Can't find user [2142439989@cts.polyfone.com.au] from 202.153.68.55
You must define a domain called 'cts.polyfone.com.au' in your directory and add a user with the id="2142439989" attribute
and you must configure your device to use the proper domain in it's authentication credentials.
2020-02-26 12:07:46.391218 [WARNING] sofia_reg.c:1743 SIP auth failure (INVITE) on sofia profile 'public' for [0417008664@cts.polyfone.com.au] from ip 202.153.68.55
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.391218 [NOTICE] sofia.c:2411 Hangup sofia/public/0755609559@202.153.68.55:5062 [CS_NEW] [CALL_REJECTED]
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] sofia.c:1529 Channel is already hungup.
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:584 (sofia/public/0755609559@202.153.68.55:5062) Running State Change CS_HANGUP (Cur 7 Tot 811815)
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:847 (sofia/public/0755609559@202.153.68.55:5062) Callstate Change DOWN -> HANGUP
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:849 (sofia/public/0755609559@202.153.68.55:5062) State HANGUP
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] mod_sofia.c:449 Channel sofia/public/0755609559@202.153.68.55:5062 hanging up, cause: CALL_REJECTED
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:60 sofia/public/0755609559@202.153.68.55:5062 Standard HANGUP, cause: CALL_REJECTED
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:849 (sofia/public/0755609559@202.153.68.55:5062) State HANGUP going to sleep
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:619 (sofia/public/0755609559@202.153.68.55:5062) State Change CS_HANGUP -> CS_REPORTING
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:584 (sofia/public/0755609559@202.153.68.55:5062) Running State Change CS_REPORTING (Cur 7 Tot 811815)
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:935 (sofia/public/0755609559@202.153.68.55:5062) State REPORTING
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:174 sofia/public/0755609559@202.153.68.55:5062 Standard REPORTING, cause: CALL_REJECTED
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:935 (sofia/public/0755609559@202.153.68.55:5062) State REPORTING going to sleep
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:610 (sofia/public/0755609559@202.153.68.55:5062) State Change CS_REPORTING -> CS_DESTROY
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_session.c:1715 Session 811815 (sofia/public/0755609559@202.153.68.55:5062) Locked, Waiting on external entities
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [NOTICE] switch_core_session.c:1733 Session 811815 (sofia/public/0755609559@202.153.68.55:5062) Ended
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [NOTICE] switch_core_session.c:1737 Close Channel sofia/public/0755609559@202.153.68.55:5062 [CS_DESTROY]
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:738 (sofia/public/0755609559@202.153.68.55:5062) Running State Change CS_DESTROY (Cur 6 Tot 811815)
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:748 (sofia/public/0755609559@202.153.68.55:5062) State DESTROY
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] mod_sofia.c:354 sofia/public/0755609559@202.153.68.55:5062 SOFIA DESTROY
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:181 sofia/public/0755609559@202.153.68.55:5062 Standard DESTROY
2dcafc92-0f52-4c03-8617-635b9d52e447 2020-02-26 12:07:46.411187 [DEBUG] switch_core_state_machine.c:748 (sofia/public/0755609559@202.153.68.55:5062) State DESTROY going to sleep
 

Attachments

  • trace_anynode_anynode-3-20-11_20200226130812.zip
    801.3 KB · Views: 4

DigitalDaz

Administrator
Staff member
Sep 29, 2016
3,038
556
113
Back in the day, I don't know if its changed now but a number of that length was too long for an extension, extensions were 2-7 digits long and the dialplan would not behave as expected if they were outside that range.
 

DigitalDaz

Administrator
Staff member
Sep 29, 2016
3,038
556
113
Get the capture into a standard wireshark capture and I'll take a look.
 

slazer2au

New Member
Feb 17, 2020
7
0
1
34
Hi Daz

I have attached the pcap of a failed call. I am super confused as to why only one user using this trunk is having a problem, the other 3 have no issue.

Suppose it is just good luck it is my number and not the bosses. :D
 

Attachments

  • 20200227-teams.zip
    2 KB · Views: 2

DigitalDaz

Administrator
Staff member
Sep 29, 2016
3,038
556
113
Well, its telling you the user is not valid and its definitely rejecting as if its a username password problem.

I would definitely try lowering the lengths of the extensions.

Another thing I can possibly see here is that your are using udp and that packet could be getting fragmented due to size so use TCP instead.

I'm more thinking of the extension length because it is saying can't find user.

Are you seeing your phone correctly registered?
 

ad5ou

Active Member
Jun 12, 2018
884
195
43
I have tons of 10 digit extensions, and several 11 digit extensions that work just fine.
 

slazer2au

New Member
Feb 17, 2020
7
0
1
34
Hi Das

I have 3 other users using the same trunk. It is only when my desktop or mobile MS Teams client calls Fusion has the issue.
I have attached another sip trace today with the first call which worked. Then a call which didn't work. Both came from the same SBC using the same trunk details.

I do see the SBC registering in Fusion correctly and calls are working both ways for all other users.
 

Attachments

  • 20200228-Teams.zip
    3.4 KB · Views: 1

slazer2au

New Member
Feb 17, 2020
7
0
1
34
As a bit of a test I changed the number I allocated to the broken user in teams and the outbound calling is working.
Not sure why that worked, they all come in under the same SIP trunk.

If anyone hits the same issue, change the Teams OnPremLineURI number to a different inbound number.
 
Status
Not open for further replies.