Internal call doesn't end when the callee rejects it

[davide.bonavita]

Hello there,
strange behaviour here. Please see this pretty standard setup:



When I try to call this 1228 extension from another extension (0000 in my test) and 1228 rejects the calls, it keeps ringing for 20 seconds on the 0000 leg instead of going to the voicemail right away. It eventually reaches te voicemail.
If I change the settings from "Forward to Voicemail" to "End Call", after 20 seconds 0000 hears "the extensions cannot be reached, contact the administrator" instead of a busy tone
The correct behaviour should be going to the voicemail or hearing the busy tone as soon as 1228 rejects the call.

This is the activity related to this test

27/07/2021 12:11:47 - Leg L:47.4[VMail:6666] is terminated: Cause: BYE from local
27/07/2021 12:11:47 - [CM503008]: Call(C:47): Call is terminated
27/07/2021 12:11:47 - Leg L:47.1[Extn:0000] is terminated: Cause: BYE from local
27/07/2021 12:11:39 - Leg L:47.3[Extn:1228] is terminated: Cause: 487 Request Terminated/INVITE from 127.0.0.1:5063
27/07/2021 12:11:39 - [CM503003]: Call(C:47): Call to <sip:[email protected]:0> has failed; Cause: 487 Request Terminated/INVITE from 127.0.0.1:5063
27/07/2021 12:11:39 - [CM503007]: Call(C:47): VMail:6666 has joined, contact <sip:[email protected]:5483/UDP>
27/07/2021 12:11:39 - [CM503007]: Call(C:47): Extn:0000 has joined, contact <sip:[email protected]:5063/UDP>
27/07/2021 12:11:39 - L:47.4[VMail:6666] has joined to L:47.1[Extn:0000]
27/07/2021 12:11:39 - [CM505001]: Endpoint VMail:6666: Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [3CX Voice Mail Menu] PBX contact: [sip:[email protected]:5060]
27/07/2021 12:11:39 - [CM503002]: Call(C:47): Alerting VMail:6666 by contact <sip:[email protected]:5483/UDP>
27/07/2021 12:11:39 - [CM503025]: Call(C:47): Calling T:VMail:6666@[Dev:sip:[email protected]:5483;rinstance=2516a20ee6b52cf3] for L:47.1[Extn:0000]
27/07/2021 12:11:39 - [CM503005]: Call(C:47): Forwarding: T:VMail:6666@[Dev:sip:[email protected]:5483;rinstance=2516a20ee6b52cf3]
27/07/2021 12:11:39 - L:47.1[Extn:0000] forwards call from Extn:1228 to VMail:6666 based on rule Fwd[Available/NoAnsw]
27/07/2021 12:11:39 - [Flow] Target endpoint for 1228 is VMail:6666
27/07/2021 12:11:39 - L:47.1[Extn:0000] failed to reach Extn:1228, reason No Answer
27/07/2021 12:11:22 - Leg L:47.2[Extn:1228] is terminated: Cause: 487 Request Terminated/INVITE from 127.0.0.1:5063
27/07/2021 12:11:22 - [CM503003]: Call(C:47): Call to <sip:[email protected]:0> has failed; Cause: 487 Request Terminated/INVITE from 127.0.0.1:5063
27/07/2021 12:11:19 - [CM505001]: Endpoint Extn:1228: Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [3CX WebRTC proxy] PBX contact: [sip:[email protected]:5060]
27/07/2021 12:11:19 - [CM503002]: Call(C:47): Alerting Extn:1228 by contact <sip:[email protected]:5063/UDP>
27/07/2021 12:11:19 - [CM505001]: Endpoint Extn:1228: Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [3CX WebRTC proxy] PBX contact: [sip:[email protected]:5060]
27/07/2021 12:11:19 - [CM503002]: Call(C:47): Alerting Extn:1228 by contact <sip:[email protected]:5063/UDP>
27/07/2021 12:11:19 - [CM503025]: Call(C:47): Calling T:Extn:1228@[Dev:sip:[email protected]:5063;rinstance=4e4df35e9ff8fafe,Dev:sip:[email protected]:5063;rinstance=55502c488b29cc04] for L:47.1[Extn:0000]
27/07/2021 12:11:19 - [CM503025]: Call(C:47): Calling T:Extn:1228@[Dev:sip:[email protected]:5063;rinstance=4e4df35e9ff8fafe,Dev:sip:[email protected]:5063;rinstance=55502c488b29cc04] for L:47.1[Extn:0000]
27/07/2021 12:11:19 - [CM503027]: Call(C:47): From: Extn:0000 ("Test, Test" <sip:[email protected]:0>) to T:Extn:1228@[Dev:sip:[email protected]:5063;rinstance=4e4df35e9ff8fafe,Dev:sip:[email protected]:5063;rinstance=55502c488b29cc04]
27/07/2021 12:11:19 - [CM503004]: Call(C:47): Route 1: from L:47.1[Extn:0000] to T:Extn:1228@[Dev:sip:[email protected]:5063;rinstance=4e4df35e9ff8fafe,Dev:sip:[email protected]:5063;rinstance=55502c488b29cc04]
27/07/2021 12:11:19 - [Flow] Call(C:47): has built target endpoint: Extn:1228 for call from L:47.1[Extn:0000]
27/07/2021 12:11:19 - [Flow] Target endpoint for 1228 is Extn:1228
27/07/2021 12:11:19 - [CM503010]: Call(C:47): Making route(s) from Extn:0000 to <sip:[email protected]:5060/UDP>
27/07/2021 12:11:19 - [CM505001]: Endpoint Extn:0000: Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [3CX WebRTC proxy] PBX contact: [sip:[email protected]:5060]
27/07/2021 12:11:19 - [CM500002]: Call(C:47): Info on incoming INVITE from Extn:0000: Invite-IN Recv Req INVITE from 127.0.0.1:5063 tid=bced3e15c3c0347d Call-ID=udnUinpoq6TvmUUnYzMFQQ..: INVITE sip:[email protected]:5060 SIP/2.0 Via: SIP/2.0/UDP 127.0.0.1:5063;branch=z9hG4bK-524287-1---bced3e15c3c0347d;rport=5063 Max-Forwards: 70 Contact: <sip:[email protected]:5063;rinstance=b0abccd669f433e2> To: <sip:[email protected]:5060> From: "Test, Test"<sip:[email protected]>;tag=cbf7a661 Call-ID: udnUinpoq6TvmUUnYzMFQQ.. CSeq: 2 INVITE Subject: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE Content-Type: application/sdp Proxy-Authorization: Digest username="e1zBej1gZM",realm="3CXPhoneSystem",nonce="414d535960ffe9d796:bb420e867935e60d381d7dc966459e8f",uri="sip:[email protected]:5060",response="71e12827f44630a035df08d00fa4f5a0",algorithm=MD5 Supported: replaces User-Agent: 3CX WebRTC proxy Content-Length: 595 v=0 o=3cxVCE 2104888542 18446744072536200553 IN IP4 127.0.0.1 s=3cxVCE Audio Call c=IN IP4 127.0.0.1 t=0 0 m=audio 8694 RTP/AVP 111 103 104 9 0 8 106 105 13 110 112 113 126 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10;useinbandfec=1 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:110 telephone-event/48000 a=rtpmap:112 telephone-event/32000 a=rtpmap:113 telephone-event/16000 a=rtpmap:126 telephone-event/8000 a=ptime:20 a=sendrecv
27/07/2021 12:11:19 - [CM503001]: Call(C:47): Incoming call from Extn:0000 to <sip:[email protected]:5060>

 

[VasilisV_3CX]

Hi @davide.bonavita,

What version is the PBX? Can you provide more information? https://www.3cx.com/community/threads/information-to-provide-when-requesting-help.67558/

When doing this test, have you logged the extension in to anything other than the Web Client, for example the Windows Client or Mobile App etc? If extension 1228 is logged in, disconnect the IP phone, wait for at least 2 minutes and only use the webclient for your testing.

Can you provide the exact IP phone model, firmware and if you're using custom templates?

 

[davide.bonavita]

Hi Vasilis, the PBX version is in my signature. 1228 is logged in the Chrome extension, 0000 is calling through the web browser client itself . They are not logged anywhere else.
Both extensions are registered on my computer, 1228 in a normal Chrome tab, 0000 in an incognito tab

I've tried using the web browser client for both extensions, same behaviour

 

[VasilisV_3CX]

Hi @davide.bonavita,

Can you register one extension on your mobile client and have the other running on the web client, then try again and test (so only 1 web client running on the PC)?

 

[davide.bonavita]

Hi @VasilisV_3CX :
from 1228 (Chrome Extensions) to 0000 (Android App): OK
from 0000 (Android App) to 1228 (Chrome Extension): test failed.

I've tried restarting the chrome browser (killing everything from the task manager) and disconnecting all the active VPNs, but nothing really changes
I have a network traffic dump, if it can help

 

[VasilisV_3CX]

Hi @davide.bonavita,

If it's not too much of a hassle, could you uninstall the VPN and reboot the machine, test again and let me know if it happens again from the android app to chrome extension?

 

[davide.bonavita]

Sure thing, just give me some minute

 

[davide.bonavita]

I'm afraid nothing changed

 

[VasilisV_3CX]

Hi @davide.bonavita

I've still not been able to replicate this, try as I may.

If you create an entirely new extension and log in to the web client then activate the browser extension and do the call again, does it still ring for 20 seconds when declined? Note well that the extension should only be logged in to the Web Client and have the browser extension active.