Direct SIP calls is not working, getting missed after ending calls on the remote side

[palark]

Hello!
Direct SIP calls are not working, getting missed instantly after ending calls on the remote side.
Tried V20 and V20 beta. Also, we don't see the calls in the call log.
All internal calls working and external calls from providers to the ring groups working OK

 

[NicholasP_3CX]

Please ensure you have the Allow Direct SIP Calling option active on the system

 

[palark]

Thanks. I am absolutely sure that direct calls are on and SIP IDs are present in user options. We do see a call on the remote side and see the call in the logs of the 3cx, but no call on the endpoint device, iPhone, or softphone. Also, immediately after the call, we get the missed call notification.

 

[palark]

Any help here?

 

[NicholasP_3CX]

Dialling internally, the SIP ID would be sufficient. Dialling from outside of the system, you would need to have the SIPID@FQDN to do the dialling.

Could you give us a bit more information to work on?

Who is doing the dialling? To where? Give us a scenario. When you say Remote side. Where is that device? Is it an extension? Is it an external caller?

 

[palark]

Thanks for asking! Sorry for the lack of details.
I'm doing the test call from the self-hosted Asterisk, and dealing for example to extension 102, using the [email protected] or 102@[3cx IP address] to dial. The call is started by an extension on that Asterisk.

Immediately after the call I get:
You missed a call:
From:
To: "102" - "Name" "Surname"
Received: "Monday, April 8, 2024 1:09:13PM"
Ringing: "00:30"

 

[NicholasP_3CX]

It will have to be the FQDN that's used, not the IP address.

Check the information on this document https://www.3cx.com/blog/voip-howto/direct-sip/ which contains all the information. It is a bit out of date as far as screenshots may be concerned, but its information is still valid.

If this machine is in the same network check the network configurations in the above document as well, especially the DNS settings part.

 

[palark]

Thanks, yep, I saw this manual and we've already checked everything. The behavior doesn't change if we use the FQDN.

Maybe pbx logs will help?

#tail -f /var/lib/3cxpbx/Data/Logs/3CXMediaServer.2024-04-08.135026.log

#Date: 2024/04/10
14:17:32.526|7fedf1ffb6c0| Info|MSEndPoint.cpp(918): 1:[email protected]:5482: SDP address is forced for the EXTERNAL connection -[IP]
14:17:32.526|7fedf1ffb6c0|Trace|MSEndPoint.cpp(951): 6:[email protected]:5482: a try(1) to open sockets on External(9012,9013)
14:17:32.527|7fedf1ffb6c0|Trace|MSEndPoint.cpp(971): 3:[email protected]:5482: RTP bind address [IP]:9012
14:17:32.527|7fedf1ffb6c0|Trace|MSEndPoint.cpp(980): 3:[email protected]:5482: RTCP bind address [IP]:9013
14:17:32.527|7fedf1ffb6c0|Trace|MediaServer.cpp(242): 7:/Sources/Projects/Common/VoIPFileEngine/IMMFileStreamReader.cpp(144) /var/lib/3cxpbx/Instance1/Data/Ivr/Prompts/onhold.wav taken from the cache
14:17:32.527|7fedfdffb6c0|Trace|RTPReceiver.cpp(161): 5:RTPReceiver[0]:RTP receiver is added for [email protected]:5482(C:7.1) on socket (28)
14:17:32.527|7fedfdffb6c0|Trace|RTPReceiver.cpp(161): 5:RTPReceiver[0]:RTCP receiver is added for [email protected]:5482(C:7.1) on socket (29)
14:17:32.528|7fedf1ffb6c0|Trace|MediaServer.cpp(1026): 3:EndPoint created: (destination=78.94.76.109)
EndPoint: ID=[email protected]:5482(EXTERNAL)
LOGID=C:7.1 Status: MSEP_EXTERNAL FORCE_MEDIA_PROXY
RTP:[IP]:9012
RTCP:[IP]:9013
STUN RTP:<none>
STUN RTCP:<none>
Coder:
NOT SET
101:telephony-event/8000
102:telephony-event/48000
Party ptime:20
Party RTP:<none>
Party RTCP:<none>
Decoders:
<empty>

14:17:32.528|7fedf1ffb6c0|Trace|MediaServer.cpp(1544): 4:EP [email protected]:5482 joined to call [email protected]:5482
14:17:32.528|7fedf1ffb6c0|Trace|MediaServer.cpp(1553): 4:starting send on new call [email protected]:5482
14:17:32.528|7fedf1ffb6c0|Trace|MediaServer.cpp(1116): 3:Set Party EP:C:7.1 SDP:v=0
o=- 3921740252 3921740252 IN IP4 78.94.76.109
s=pjmedia
b=AS:117
t=0 0
a=X-nat:0
m=audio 4000 RTP/AVP 96 9 8 0 101 102
c=IN IP4 78.94.76.109
b=TIAS:96000
a=rtcp:4001 IN IP4 78.94.76.109
a=sendrecv
a=rtpmap:96 opus/48000/2
a=fmtp:96 useinbandfec=1
a=rtpmap:9 G722/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/48000
a=fmtp:101 0-16
a=rtpmap:102 telephone-event/8000
a=fmtp:102 0-16
a=ssrc:953281730 cname:5789527a7885f47b

14:17:32.529|7fedf1ffb6c0|Trace|MSEndPoint.cpp(5101): 3:New [email protected]:5482 SILENCE
14:17:32.529|7fedf1ffb6c0|Trace|MSEndPoint.cpp(2609): 10artyAddrRTP_ is set to [router]:4000
14:17:32.529|7fedf1ffb6c0|Trace|MSEndPoint.cpp(2622): 10artyAddrRTCP_ is set to [router]:4001
14:17:32.529|7fedf1ffb6c0| Info|MSEndPoint.cpp(2670): 11:[MS211000] C:7.1: [router]:4000 offers telephone-event/8000 and telephone-event/48000. In-Band DTMF tone detection is turned off for this call segment.
Distribution of telephone-events will be performed according to the base clock of the current audio decoder/endcoder
14:17:32.532|7fedf1ffb6c0| Info|MSEndPoint.cpp(3039): 10:[MS210000] C:7.1:Offer received. RTP connection: 78.94.76.109:4000(4001)
14:17:32.549|7fedfffff6c0|Trace|MSEndPoint.h(531): 5:C:7.1: set encoder to 96 opus/48000/16000
14:17:48.186|7fedf1ffb6c0|Trace|MSEndPoint.h(1042): 4:RACETRACKER: EP:[email protected]:5482(0x7fedd8000c40) added for C:[email protected]:5482RemovedFromCalls(1) RemovedEP(1)
14:17:48.187|7fedf1ffb6c0|Trace|MediaServer.cpp(1591): 4:EndPoint [email protected]:5482 removed from call [email protected]:5482
14:17:48.187|7fedf37fe6c0| Warn|RTPReceiver.cpp(453): 5:MediaProxy:VRTP receiver for [email protected]:5482(C:7.1) has no assigned socket
14:17:48.187|7fedf37fe6c0| Warn|RTPReceiver.cpp(453): 5:MediaProxy:VRTCP receiver for [email protected]:5482(C:7.1) has no assigned socket
14:17:48.187|7fedf37fe6c0| Warn|RTPReceiver.cpp(453): 5:MediaProxy:T38 receiver for [email protected]:5482(C:7.1) has no assigned socket
14:17:48.187|7fedf37fe6c0| Warn|RTPReceiver.cpp(453): 5:MediaProxy:T38_ receiver for [email protected]:5482(C:7.1) has no assigned socket
14:17:48.187|7fedf1ffb6c0|Trace|MediaServer.cpp(1320): 9:references to EndPoint [email protected]:5482 were removed
14:17:48.190|7fedfffff6c0|Trace|MSEndPoint.h(949): 4:RACETRACKER: EP:0x7fedd8000c40 references were removed for call C:[email protected]:5482
14:17:48.190|7fedfffff6c0|Trace|MSEndPoint.h(960): 4:RACETRACKER: references to C:[email protected]:5482 were removed. RemovedFromCalls(0) RemovedEP(0)
14:17:48.192|7fedf1ffb6c0|Trace|MediaServer.cpp(1725): 4:references to call [email protected]:5482 were removed
14:17:48.249|7fedfdffb6c0|Trace|RTPReceiver.cpp(165): 5:RTPReceiver[0]:RTP receiver was removed for [email protected]:5482(C:7.1) on socket (28)
14:17:48.250|7fedfdffb6c0|Trace|RTPReceiver.cpp(165): 5:RTPReceiver[0]:RTCP receiver was removed for [email protected]:5482(C:7.1) on socket (29)
14:17:48.250|7fedfdffb6c0|Trace|MSEndPoint.cpp(1066): 0:EndPoint [email protected]:5482 destroyed: freed pair 9012, 9013 in External
14:17:48.250|7fedfdffb6c0|Trace|MSEndPoint.cpp(1067): 0:EndPoint [email protected]:5482 destroyed statistics:
Begin send:0
LastSent:0
TotalSent:0
MaxSendInterval:0
MinSendInterval:0
AvgSendInterval:0
SendDeviation:0
MaxBurst:0
AvgBurst:0
NumBurst:0
Last recv:0
TotalRecv:0
MaxRecvInterval:0
MinRecvInterval:0
AvgRecvInterval:0
ReceiveDeviation:0

14:17:53.199|7fedfffff6c0|Trace|MSCallConf.cpp(168): 0:Call: [email protected]:5482 destroyed

 

[NicholasP_3CX]

Woah!

TMI and not relevant. It's only the media server logs there. Nothing about the call.

OK, step back.

1. Check that the option for Direct SIP calling is active. Visually check it.
2. Check in the user's options that the SIP ID is set to 102 if that is what is used to dial in the direct SIP URL as SIP ID
3. Check that this SIP ID has not been assigned anywhere else! There is no verification check for this field
4. Verify that the PBX's SIP port is set to 5060. If that has been changed the SIP URL to dial would be SIP_ID@FQDN:SIP_PORT
5. What device is being dialled? IP Phone? 3CX App? 3CX Mobile App?
6. Create a capture of the incoming call
7. Check with another user just in case it might be something on this particular user which is not working.

What you would need to look out for in the capture is the communication between the 3CX Server and the 3CX Endpoint being dialled and if any errors are shown between these 2 devices on that call leg. Also check if the PBX is sending an error back to the remote side.

 

[palark]

Woah!

TMI and not relevant. It's only the media server logs there. Nothing about the call.

OK, step back.

1. Check that the option for Direct SIP calling is active. Visually check it.
2. Check in the user's options that the SIP ID is set to 102 if that is what is used to dial in the direct SIP URL as SIP ID
3. Check that this SIP ID has not been assigned anywhere else! There is no verification check for this field
4. Verify that the PBX's SIP port is set to 5060. If that has been changed the SIP URL to dial would be SIP_ID@FQDN:SIP_PORT
5. What device is being dialled? IP Phone? 3CX App? 3CX Mobile App?
6. Create a capture of the incoming call
7. Check with another user just in case it might be something on this particular user which is not working.

What you would need to look out for in the capture is the communication between the 3CX Server and the 3CX Endpoint being dialled and if any errors are shown between these 2 devices on that call leg. Also check if the PBX is sending an error back to the remote side.

1. Yep, it's on
2. Yes, it's set exactly like that
3. Only two SIP IDs are assigned for two user
4. Standard port is used
5. One of the local extensions is used on the 3CX Mobile app on IPhone, and the second is the 3CX Mobile app on the Android.
6. By meaning capture, you are meaning network capture and sequential analysis of pcap in Wireshark?
7. I'm checking two extensions, yes.

In Wireshark I don't see any errors, just these normal packets:
No. Time Source Destination Protocol Length Info
55 4.137106 7x.xx.xx.xx 5x.xxx.xx.xxx SIP/SDP 1122 Request: INVITE sip:[email protected] |
58 4.217732 5x.xx.xx.xx 7x.xxx.xx.xxx SIP 363 Status: 100 Trying |
61 4.418347 5x.xx.xx.xx 7x.xxx.xx.xxx SIP 473 Status: 180 Ringing |
... some TLS and app data
279 18.961570 5x.xx.xx.xx 7x.xxx.xx.xxx SIP 421 Request: CANCEL sip:[email protected] |
281 19.062300 5x.xx.xx.xx 7x.xxx.xx.xxx SIP 468 Status: 200 OK (CANCEL) |
282 19.062353 5x.xx.xx.xx 7x.xxx.xx.xxx SIP 435 Status: 487 Request Terminated |
283 19.083375 7x.xx.xx.xx 5x.xxx.xx.xxx SIP 401 Request: ACK sip:[email protected] |

 

[palark]

Hi! Any suggestions?