Ending call on one phone disconnects another call

Discussion in '3CX Phone System - General' started by 757performance, Jun 2, 2016.

Thread Status:
Not open for further replies.
  1. 757performance

    Joined:
    Jun 2, 2016
    Messages:
    4
    Likes Received:
    0
    Hi! I'm running a single WellTech 2540 gateway with a current up-to-date 3CX install. I never noticed it before, but from time to time a user will report after a lengthy phone call, if another user gets a call and hangs up, their line disconnects to dead air. After some time datalogging in Verbose, I've found the following out:

    - At the precise moment a call is disconnected, the 3CX server still believes the call is ongoing. Timestamps agree with this. The user can hang up and 3CX gets a BYE from the Cisco handset.
    - I haven't been able to verify this, but it seems this is more problematic on longer phone calls. I do not believe we have firewall issues since the gateway is inside our LAN.
    - No other issues to report, everything is standard configuration via 3CX config files. Just this annoying thing!

    Here is a log, my notes are in bold. Any ideas or help is appreciated!

    01-Jun-2016 16:23:14.626 Leg L:776.1[Line:90001<<2523010352] is terminated: Cause: BYE from PBX
    01-Jun-2016 16:23:14.626 [CM503008]: Call(C:776): Call is terminated
    01-Jun-2016 16:23:14.625 Leg L:776.3[Extn] is terminated: Cause: BYE from 192.168.1.11:5060
    Hangup by user on 101, BYE is received by 3CX and call drops off the server monitor
    01-Jun-2016 16:22:56.861 Currently active calls - 1: [776]
    01-Jun-2016 16:22:56.861 Currently active calls - 1: [776]
    01-Jun-2016 16:22:43.817 Leg L:777.1[Line:90002<<anonymous] is terminated: Cause: BYE from PBX
    01-Jun-2016 16:22:43.817 [CM503008]: Call(C:777): Call is terminated
    01-Jun-2016 16:22:43.817 Leg L:777.3[Extn] is terminated: Cause: BYE from 192.168.1.16:5060
    hangup by user on 102, causing 101 to instantly go to dead air after the BYE
    01-Jun-2016 16:22:26.851 Currently active calls - 3: [776,777,778]
    01-Jun-2016 16:21:56.843 Currently active calls - 2: [776,777]
    01-Jun-2016 16:21:24.836 Currently active calls - 2: [776,777]
    01-Jun-2016 16:20:54.828 Currently active calls - 2: [776,777]
    01-Jun-2016 16:20:22.819 Currently active calls - 2: [776,777]
    01-Jun-2016 16:19:52.812 Currently active calls - 2: [776,777]
    01-Jun-2016 16:19:20.806 Currently active calls - 2: [776,777]
    01-Jun-2016 16:18:48.798 Currently active calls - 2: [776,777]
    01-Jun-2016 16:18:18.792 Currently active calls - 2: [776,777]
    01-Jun-2016 16:17:47.085 Leg L:777.2[Ivr] is terminated: Cause: BYE from 127.0.0.1:5483
    01-Jun-2016 16:17:46.883 [CM503007]: Call(C:777): Extn:102 has joined, contact <sip:102@192.168.1.16:5060>
    01-Jun-2016 16:17:46.882 L:777.3[Extn] has joined to L:777.1[Line:90002<<anonymous]
    01-Jun-2016 16:17:46.882 NAT/ALG check:L:777.3[Extn] RESPONSE 200 on 'INVITE' - basic check passed. No information for extended checks
    01-Jun-2016 16:17:46.783 Currently active calls - 2: [776,777]
    01-Jun-2016 16:17:43.337 [CM503025]: Call(C:777): Calling T:RingAll:800@[Dev:sip:102@192.168.1.16:5060] for L:777.1[Line:90002<<anonymous]
    01-Jun-2016 16:17:43.335 [CM503027]: Call(C:777): From: Line:90002<<anonymous ("7574994653" <sip:anonymous@192.168.1.26:5060>) to T:RingAll:800@[Dev:sip:102@192.168.1.16:5060]
    01-Jun-2016 16:17:43.335 [CM503004]: Call(C:777): Route 1: from L:777.1[Line:90002<<anonymous] to T:RingAll:800@[Dev:sip:102@192.168.1.16:5060]
    01-Jun-2016 16:17:43.335 L:777.1[Line:90002<<anonymous] target's endpoint Extn:101 is Busy
    Call is routed to 102 only since 101 is on line with Brent
    01-Jun-2016 16:17:43.335 [CM505002]: Gateway:[WellTech2540] Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [4PORT_GW] PBX contact: [sip:90002@192.168.1.26:5060]
    01-Jun-2016 16:17:43.133 NAT/ALG check:L:777.2[Ivr] REQUEST 'INVITE' - basic check passed. No information for extended checks
    01-Jun-2016 16:17:37.401 [MS211000] C:777.1: 192.168.1.5:16545 is delivering DTMF using RTP payload (RFC2833). In-Band DTMF tone detection is disabled for this call segment.
    01-Jun-2016 16:17:28.641 [CM503007]: Call(C:777): Ivr:801 has joined, contact <sip:801@127.0.0.1:5483>
    01-Jun-2016 16:17:28.641 [CM503007]: Call(C:777): Line:90002<<anonymous has joined, contact <sip:90002@192.168.1.5:8080>
    01-Jun-2016 16:17:28.640 L:777.2[Ivr] has joined to L:777.1[Line:90002<<anonymous]
    01-Jun-2016 16:17:28.640 NAT/ALG check:L:777.2[Ivr] RESPONSE 200 on 'INVITE' - basic check passed. No information for extended checks
    01-Jun-2016 16:17:28.491 [CM503025]: Call(C:777): Calling T:Ivr:801@[Dev:sip:801@127.0.0.1:5483;rinstance=5c3142e4c60cc177] for L:777.1[Line:90002<<anonymous]
    01-Jun-2016 16:17:28.441 [CM503027]: Call(C:777): From: Line:90002<<anonymous ("7574994653" <sip:anonymous@192.168.1.26:5060>) to T:Ivr:801@[Dev:sip:801@127.0.0.1:5483;rinstance=5c3142e4c60cc177]
    01-Jun-2016 16:17:28.441 [CM503004]: Call(C:777): Route 1: from L:777.1[Line:90002<<anonymous] to T:Ivr:801@[Dev:sip:801@127.0.0.1:5483;rinstance=5c3142e4c60cc177]
    01-Jun-2016 16:17:28.441 [CM505002]: Gateway:[WellTech2540] Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [4PORT_GW] PBX contact: [sip:90002@192.168.1.26:5060]
    01-Jun-2016 16:17:28.441 [CM503001]: Call(C:777): Incoming call from Line:90002<<anonymous to <sip:801@192.168.1.26:5060>
    01-Jun-2016 16:17:28.441 Line limit check: Current # of calls for line Lc:90002(@WellTech2540[<sip:90002@192.168.1.5:8080>]) is 1; limit is 1
    01-Jun-2016 16:17:28.441 NAT/ALG check:L:777.1[Line:90002<<anonymous] REQUEST 'INVITE' - basic check passed. No information for extended checks
    Line 2 is calling in, beginning of dropped call.....?
    01-Jun-2016 16:17:28.438 [CM503012]: Inbound specific hours w/o holidays rule (unnamed) for 90002 forwards to DN:801
    01-Jun-2016 16:17:28.161 [CM102001]: Authentication failed for AuthFail Recv Req INVITE from 192.168.1.5:8080 tid=-e44-37bc83-12d8ceaf Call-ID=761dc0-501a8c0-1f90-55022-e44-3be74212-e44:
    INVITE sip:90002@192.168.1.26:5060 SIP/2.0
    Via: SIP/2.0/UDP 192.168.1.5:8080;rport=8080;branch=z9hG4bK-e44-37bc83-12d8ceaf
    Max-Forwards: 70
    Contact: <sip:90001@192.168.1.5:8080>
    To: <sip:90002@192.168.1.26:5060>
    From: "7574994653"<sip:anonymous@192.168.1.5:8080>;tag=755198-501a8c0-1f90-55022-e44-55c75e58-e44
    Call-ID: 761dc0-501a8c0-1f90-55022-e44-3be74212-e44
    CSeq: 2 INVITE
    Content-Type: application/sdp
    Proxy-Authorization: Digest username="90001",realm="3CXPhoneSystem",nonce="414d535c0d5fd3d895:dd0acd519ab8a6c1c4c4a49724fadcc5",uri="sip:90002@192.168.1.26:5060",response="ee58f1be2d885f8d202edb3fd66567e0",algorithm=MD5
    Supported: replaces
    User-Agent: 4PORT_GW
    Content-Length: 269

    v=0
    o=90001 22 22 IN IP4 192.168.1.5
    s=CTIPHONE
    c=IN IP4 192.168.1.5
    t=0 0
    m=audio 16545 RTP/AVP 8 0 4 18 101
    a=rtpmap:8 PCMA/8000
    a=ptime:20
    a=rtpmap:0 PCMU/8000
    a=rtpmap:4 G723/8000
    a=rtpmap:18 G729/8000
    a=fmtp:101 0-11
    a=rtpmap:101 telephone-event/8000
    ; Reason: Credentials don't match, check that authorization-ID and password match the ones in extension settings
    Big data dump, need to investiage this section
    01-Jun-2016 16:17:24.599 Leg L:776.2[Ivr] is terminated: Cause: BYE from 127.0.0.1:5483
    01-Jun-2016 16:17:24.511 Leg L:776.4[Extn] is terminated: Cause: 487 Request Terminated/INVITE from 192.168.1.16:5060
    01-Jun-2016 16:17:24.511 [CM503003]: Call(C:776): Call to <sip:102@192.168.1.26:5060> has failed; Cause: 487 Request Terminated/INVITE from 192.168.1.16:5060
    01-Jun-2016 16:17:24.398 [CM503007]: Call(C:776): Extn:101 has joined, contact <sip:101@192.168.1.11:5060>
    01-Jun-2016 16:17:24.397 L:776.3[Extn] has joined to L:776.1[Line:90001<<2523010352]
    01-Jun-2016 16:17:24.397 NAT/ALG check:L:776.3[Extn] RESPONSE 200 on 'INVITE' - basic check passed. No information for extended checks
    user picks up 101
    01-Jun-2016 16:17:22.531 [CM503025]: Call(C:776): Calling T:RingAll:800@[Dev:sip:101@192.168.1.11:5060,Dev:sip:102@192.168.1.16:5060] for L:776.1[Line:90001<<2523010352]
    01-Jun-2016 16:17:22.530 [CM503025]: Call(C:776): Calling T:RingAll:800@[Dev:sip:101@192.168.1.11:5060,Dev:sip:102@192.168.1.16:5060] for L:776.1[Line:90001<<2523010352]
    01-Jun-2016 16:17:22.478 [CM503027]: Call(C:776): From: Line:90001<<2523010352 ("7574562277" <sip:2523010352@192.168.1.26:5060>) to T:RingAll:800@[Dev:sip:101@192.168.1.11:5060,Dev:sip:102@192.168.1.16:5060]
    PBX ringing 101, 102
    01-Jun-2016 16:17:22.478 [CM503004]: Call(C:776): Route 1: from L:776.1[Line:90001<<2523010352] to T:RingAll:800@[Dev:sip:101@192.168.1.11:5060,Dev:sip:102@192.168.1.16:5060]
    Call routed to front call group
    01-Jun-2016 16:17:22.477 [CM505002]: Gateway:[WellTech2540] Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [4PORT_GW] PBX contact: [sip:90001@192.168.1.26:5060]
    01-Jun-2016 16:17:22.276 NAT/ALG check:L:776.2[Ivr] REQUEST 'INVITE' - basic check passed. No information for extended checks
    01-Jun-2016 16:17:16.777 Currently active calls - 1: [776]
    01-Jun-2016 16:17:16.623 [MS211000] C:776.1: 192.168.1.5:16408 is delivering DTMF using RTP payload (RFC2833). In-Band DTMF tone detection is disabled for this call segment.
    01-Jun-2016 16:17:00.351 [CM503007]: Call(C:776): Ivr:801 has joined, contact <sip:801@127.0.0.1:5483>
    01-Jun-2016 16:17:00.351 [CM503007]: Call(C:776): Line:90001<<2523010352 has joined, contact <sip:90001@192.168.1.5:8080>
    01-Jun-2016 16:17:00.350 L:776.2[Ivr] has joined to L:776.1[Line:90001<<2523010352]
    Call passes into voice attendant
    01-Jun-2016 16:17:00.350 NAT/ALG check:L:776.2[Ivr] RESPONSE 200 on 'INVITE' - basic check passed. No information for extended checks
    VOIP GW initiates call to PBX
     
  2. leejor

    leejor Well-Known Member

    Joined:
    Jan 22, 2008
    Messages:
    10,360
    Likes Received:
    226
    The only thing that stands out as a bit odd, is the port number of the two trunks involved...

    I'm not familiar with the WellTech gateways but is 8080 normally used, and if so, just the one port number for all trunks?
     
  3. 757performance

    Joined:
    Jun 2, 2016
    Messages:
    4
    Likes Received:
    0
    I'm pretty new to VOIP in general since everything here was 20 years old until recently, but in the gateway's VOIP settings, I've got the following:

    SIP Local Port: 8080
    In the manual it says.. "SIP Local Port: The SIP local service port (default is 8080)"

    It kind of makes sense, that if I've got two calls using the exact same port one termination would terminate audio on the other and give me the problems I'm having. There is no option in that menu to define per-trunk ports. In the gateway's SIP trunk menu, both Proxy & Outbound Server ports are set to 5060.
     
  4. leejor

    leejor Well-Known Member

    Joined:
    Jan 22, 2008
    Messages:
    10,360
    Likes Received:
    226
    If 5060 is used in the 3CX trunk settings for that gateway, then that is what the gateway must also use as it s local port. You should be able to change either end but they must match.
     
  5. 757performance

    Joined:
    Jun 2, 2016
    Messages:
    4
    Likes Received:
    0
    I changed the SIP Local Port to 5060 and 3CX's VOIP Gateway Port to 5060 from 8080. We'll see what happens now that all ports match...
     
  6. 757performance

    Joined:
    Jun 2, 2016
    Messages:
    4
    Likes Received:
    0
    Well, no such luck. Happened to me on a call that was about a minute and a half in the moment my co-worker hung up next to me. Only the following was on the server log...

    06-Jun-2016 09:20:04.308 Leg L:1163.1[Extn] is terminated: Cause: BYE from 192.168.1.22:5060
    I hung up after making sure the call was dead, nothing useful follows
    06-Jun-2016 09:20:00.318 Currently active calls - 1: [1163]
    At this moment, my audio goes dead, 3CX still thinks there's an ongoing call.
    06-Jun-2016 09:19:41.905 Leg L:1162.1[Line:90001<<deleted customer#] is terminated: Cause: BYE from PBX
    06-Jun-2016 09:19:41.905 [CM503008]: Call(C:1162): Call is terminated
    06-Jun-2016 09:19:41.905 Leg L:1162.3[Extn] is terminated: Cause: BYE from 192.168.1.11:5060
    06-Jun-2016 09:19:30.310 Currently active calls - 2: [1162,1163]

    I suppose since I'm already in verbose I should start thinking of setting up WireShark on the server to sniff out VOIP traffic?
     
  7. leejor

    leejor Well-Known Member

    Joined:
    Jan 22, 2008
    Messages:
    10,360
    Likes Received:
    226
    Wireshark would provide you with all of the SIP messages but may still not explain why the gateway is dropping the call. You may need to somehow extract logs (Syslog?) from the gateway for information on why it is dropping the trunks it is. My suspicion is that there is a misconfiguration where trunk information (ports?) have been duplicated so that the disconnect message is affecting the wrong, or more than one trunk.

    Did you ever try starting from scratch, re-setting and "re-constructing" all of the trunks in both 3CX and the gateway?
     
  8. NickD_3CX

    NickD_3CX Support Team
    Staff Member 3CX Support

    Joined:
    Jun 2, 2014
    Messages:
    1,251
    Likes Received:
    62
    Welltech gateways, by default in the GW Wizard the port is 8080 and it should not be a problem, I agree with leejor though, to see exactly what SIP messages are being exchanged between the server, the GW and the Cisco phone, capturing a problematic call with Wireshark should tell you exactly what happened as the logs viewer can sometimes be a bit misleading when trying to figure out the SIP messages that have been sent and received.
     
Thread Status:
Not open for further replies.