Dismiss Notice
We would like to remind you that we’re updating our login process for all 3CX forums whereby you will be able to login with the same credentials you use for the Partner or Customer Portal. Click here to read more.

After upgrading to 15 it takes 10 - 20 seconds to initiate call

Discussion in '3CX Phone System - General' started by NetAssure1234, Aug 31, 2017.

Thread Status:
Not open for further replies.
  1. NetAssure1234

    Joined:
    May 11, 2015
    Messages:
    14
    Likes Received:
    0
    We just upgraded to the latest version (as well as yealink software for T48G) it now takes 15 seconds for a call to go through to ringing even if hitting the #Send key. Any ideas would be appreciated.
    Thanks,
     
  2. leejor

    leejor Well-Known Member

    Joined:
    Jan 22, 2008
    Messages:
    11,113
    Likes Received:
    329
    I would check the 3CX Activity Log to see at what point the delay is occurring. Go from there.
     
  3. nb

    nb Support Team
    Staff Member 3CX Support

    Joined:
    Jun 7, 2007
    Messages:
    2,153
    Likes Received:
    172
    The phone is slow?
    What do you do exactly?
    Press numbers, wait 15 sec, then ringing?
    Press numbers press send, 15 seconds then remote phone rings?
    If you press send the call should go immediately. if it does not, and there is this delay, it might also be a cpu usage on the machine itself. YOu need to identify if the phone is wasting this 15 seconds or not.
     
    Stop hovering to collapse... Click to collapse... Hover to expand... Click to expand...
  4. nb

    nb Support Team
    Staff Member 3CX Support

    Joined:
    Jun 7, 2007
    Messages:
    2,153
    Likes Received:
    172
    Agreed - but I am also thinking that the delay is coming locally from the phone. There are these call timers.. Could be the factory shipped something wrong.
    Lets reset the phone also to be sure and reprovision it again.
     
    Stop hovering to collapse... Click to collapse... Hover to expand... Click to expand...
  5. leejor

    leejor Well-Known Member

    Joined:
    Jan 22, 2008
    Messages:
    11,113
    Likes Received:
    329
    Everything is speculation until you check the logs. The type of trunking used, was not even mentioned. For all we know it could be a gateway issue. The logs will show how long it takes to pass through the PBX and be "handed off" to a provider or gateway.
     
    nb likes this.
  6. NetAssure1234

    Joined:
    May 11, 2015
    Messages:
    14
    Likes Received:
    0
    ok, here is a wireshark file from a call that took 30 seconds to connect. This installation has been live for a year. same problems with dialing internal numbers as well. live dialpad is set to initiate call after 2 seconds. i had to change extension to txt to get it to upload. thanks for your help
     
  7. leejor

    leejor Well-Known Member

    Joined:
    Jan 22, 2008
    Messages:
    11,113
    Likes Received:
    329
    The 3CX Activity Log would be more useful, at least for me. Wireshark doesn't show what is happening inside the PBX.
     
  8. NetAssure1234

    Joined:
    May 11, 2015
    Messages:
    14
    Likes Received:
    0
    09/01/2017 8:51:32 AM - Stop call record for leg L:738.1[Extn:1300]
    09/01/2017 8:51:32 AM - Removing leg L:738.1[Extn:1300]
    09/01/2017 8:51:32 AM - L:738.1[Extn:1300]: Terminating targets, reason: SIP ;cause=200 ;text="User hangup"
    09/01/2017 8:51:32 AM - Leg L:738.1[Extn:1300] is terminated: Cause: BYE from local
    09/01/2017 8:51:32 AM - Call(C:738), Extn:1300 on entry: DlgInfo(738-1259/Terminated / I)
    09/01/2017 8:51:32 AM - Notify dialog-info: Extn:1300: sip:1300@192.168.181.107:5060, Call(C:738)
    09/01/2017 8:51:32 AM - L:738.1[Extn:1300] got Terminated Send Req BYE from 0.0.0.0:0 tid=354f2330d43f3e46 Call-ID=0_2722057096@192.168.181.107: BYE sip:1300@192.168.181.107:5060 SIP/2.0 Via: SIP/2.0/ ;branch=z9hG4bK-524287-1---354f2330d43f3e46;rport Max-Forwards: 70 Contact: <sip:1111111111@192.168.181.240:5060> To: "M'lee"<sip:1300@192.168.181.240:5060>;tag=2373425256 From: <sip:1111111111@192.168.181.240:5060>;tag=b172c428 Call-ID: 0_2722057096@192.168.181.107 CSeq: 2 BYE User-Agent: 3CXPhoneSystem 15.5.3849.1 (3392) Content-Length: 0
    09/01/2017 8:51:32 AM - L:738.1[Extn:1300] Sending: OnSendReq Send Req BYE from 0.0.0.0:0 tid=887d283ff21edd11 Call-ID=0_2722057096@192.168.181.107: BYE sip:1300@192.168.181.107:5060 SIP/2.0 Via: SIP/2.0/ ;branch=z9hG4bK-524287-1---887d283ff21edd11;rport Max-Forwards: 70 Contact: <sip:1111111111@192.168.181.240:5060> To: "M'lee"<sip:1300@192.168.181.240:5060>;tag=2373425256 From: <sip:1111111111@192.168.181.240:5060>;tag=b172c428 Call-ID: 0_2722057096@192.168.181.107 CSeq: 2 BYE Content-Length: 0
    09/01/2017 8:51:32 AM - Call(C:738), Extn:1300 on entry: DlgInfo(738-1259/Terminated / I)
    09/01/2017 8:51:32 AM - Notify dialog-info: Extn:1300: sip:1300@192.168.181.107:5060, Call(C:738)
    09/01/2017 8:51:32 AM - L:738.1[Extn:1300]: Terminating targets, reason: SIP ;cause=200 ;text="Call terminated on user request"
    09/01/2017 8:51:32 AM - Call(C:738), Extn:1300 on exit: DlgInfo(738-1259/Terminated / I)
    09/01/2017 8:51:32 AM - Call(C:738), Extn:1300 on entry: DlgInfo(738-1259/Confirmed / I)
    09/01/2017 8:51:32 AM - Notify dialog-info: Extn:1300: sip:1300@192.168.181.107:5060, Call(C:738)
    09/01/2017 8:51:18 AM - Leg L:738.1[Extn:1300]: session is confirmed
    09/01/2017 8:51:18 AM - Call(C:738), Extn:1300 on entry: DlgInfo(738-1259/Confirmed / I)
    09/01/2017 8:51:18 AM - Notify dialog-info: Extn:1300: sip:1300@192.168.181.107:5060, Call(C:738)
    09/01/2017 8:51:18 AM - L:738.1[Extn:1300] got Confirmed Recv Req ACK from 192.168.181.107:5060 tid=3657157992 Call-ID=0_2722057096@192.168.181.107: ACK sip:1111111111@192.168.181.240:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.181.107:5060;branch=z9hG4bK3657157992 Max-Forwards: 70 Contact: <sip:1300@192.168.181.107:5060> To: <sip:1111111111@192.168.181.240:5060>;tag=b172c428 From: "M'lee" <sip:1300@192.168.181.240:5060>;tag=2373425256 Call-ID: 0_2722057096@192.168.181.107 CSeq: 2 ACK Proxy-Authorization: Digest username="1300", realm="3CXPhoneSystem", nonce="414d535c0fba12de30:29e71063f50b97603358028781389325", uri="sip:8182928144@192.168.181.240:5060", response="fb0ad7454ab7914ae847d551dde70fa6", algorithm=MD5 User-Agent: Yealink SIP-T48G 35.81.0.25 Content-Length: 0
    09/01/2017 8:51:18 AM - [CM503007]: Call(C:738): Extn:1300 has joined, contact <sip:1300@192.168.181.107:5060>
    09/01/2017 8:51:18 AM - Call(C:738), Extn:1300 on entry: DlgInfo(738-1259/Confirmed / I)
    09/01/2017 8:51:18 AM - Notify dialog-info: Extn:1300: sip:1300@192.168.181.107:5060, Call(C:738)
    09/01/2017 8:51:18 AM - Session 1503766 of leg L:738.1[Extn:1300] is connected
    09/01/2017 8:51:18 AM - L:738.1[Extn:1300] got Connected.UAS Send 200/INVITE from 0.0.0.0:0 tid=740594524 Call-ID=0_2722057096@192.168.181.107: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.181.107:5060;branch=z9hG4bK740594524 Contact: <sip:1111111111@192.168.181.240:5060> To: <sip:1111111111@192.168.181.240:5060>;tag=b172c428 From: "M'lee"<sip:1300@192.168.181.240:5060>;tag=2373425256 Call-ID: 0_2722057096@192.168.181.107 CSeq: 2 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE, UPDATE Content-Type: application/sdp Supported: replaces, timer User-Agent: 3CXPhoneSystem 15.5.3849.1 (3392) Content-Length: 325 v=0 o=3cxPS 250131513344 233102639105 IN IP4 192.168.181.240 s=3cxPS Audio call c=IN IP4 192.168.181.240 t=0 0 m=audio 7248 RTP/AVP 0 8 9 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv
    09/01/2017 8:51:18 AM - L:738.1[Extn:1300] Sending: OnSendResp Send 200/INVITE from 0.0.0.0:0 tid=740594524 Call-ID=0_2722057096@192.168.181.107: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.181.107:5060;branch=z9hG4bK740594524 Contact: <sip:1111111111@192.168.181.240:5060> To: <sip:1111111111@192.168.181.240:5060>;tag=b172c428 From: "M'lee"<sip:1300@192.168.181.240:5060>;tag=2373425256 Call-ID: 0_2722057096@192.168.181.107 CSeq: 2 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REGISTER, SUBSCRIBE, NOTIFY, REFER, INFO, MESSAGE, UPDATE Content-Type: application/sdp Supported: replaces, timer Content-Length: 325 v=0 o=3cxPS 250131513344 233102639105 IN IP4 192.168.181.240 s=3cxPS Audio call c=IN IP4 192.168.181.240 t=0 0 m=audio 7248 RTP/AVP 0 8 9 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv
    09/01/2017 8:51:18 AM - Call(C:738), Extn:1300 on exit: DlgInfo(738-1259/Confirmed / I)
    09/01/2017 8:51:18 AM - Call(C:738), Extn:1300 on entry: DlgInfo(738-1259/Early / I)
    09/01/2017 8:51:18 AM - Notify dialog-info: Extn:1300: sip:1300@192.168.181.107:5060, Call(C:738)
    09/01/2017 8:51:18 AM - L:738.1[Extn:1300]: Terminating targets, reason: SIP ;cause=200 ;text="Call completed elsewhere"
    09/01/2017 8:51:18 AM - L:738.2[Line:10000>>1111111111] has joined to L:738.1[Extn:1300]
    09/01/2017 8:51:15 AM - L:738.1[Extn:1300] Sending: OnSendResp Send 180/INVITE from 0.0.0.0:0 tid=740594524 Call-ID=0_2722057096@192.168.181.107: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.181.107:5060;branch=z9hG4bK740594524 Contact: <sip:1111111111@192.168.181.240:5060> To: <sip:1111111111@192.168.181.240:5060>;tag=b172c428 From: "M'lee"<sip:1300@192.168.181.240:5060>;tag=2373425256 Call-ID: 0_2722057096@192.168.181.107 CSeq: 2 INVITE Content-Length: 0
    09/01/2017 8:51:15 AM - Call(C:738), Extn:1300 on exit: DlgInfo(738-1259/Early / I)
    09/01/2017 8:51:15 AM - Call(C:738), Extn:1300 on entry: DlgInfo(738-1259/Initial / I)
    09/01/2017 8:51:15 AM - Notify dialog-info: Extn:1300: sip:1300@192.168.181.107:5060, Call(C:738)
    09/01/2017 8:50:55 AM - [CM503025]: Call(C:738): Calling T:Line:10000>>1111111111@[Dev:sip:22222222222@22222222222.sipservice.appiaservices.com:5060] for L:738.1[Extn:1300]
    09/01/2017 8:50:54 AM - [Flow] Call(C:738): making call from L:738.1[Extn:1300] to T:Line:10000>>1111111111@[Dev:sip:22222222222@22222222222.sipservice.appiaservices.com:5060]
    09/01/2017 8:50:54 AM - [CM503027]: Call(C:738): From: Extn:1300 ("M'lee" <sip:1300@192.168.181.240:5060>) to T:Line:10000>>11111111111@[Dev:sip:22222222222@22222222222.sipservice.appiaservices.com:5060]
    09/01/2017 8:50:54 AM - [CM503004]: Call(C:738): Route 1: from L:738.1[Extn:1300] to T:Line:10000>>1111111111@[Dev:sip:22222222222@22222222222.sipservice.appiaservices.com:5060]
    09/01/2017 8:50:54 AM - Call(C:738): Call from Extn:1300 to 8182928144 matches outbound rule 'Rule for Appia'
    09/01/2017 8:50:54 AM - [Flow] Call(C:738): has built target endpoint: Out#:>>Rule{Rule for Appia}>>1111111111for call from L:738.1[Extn:1300]
    09/01/2017 8:50:54 AM - [CM503010]: Call(C:738): Making route(s) from Extn:1300 to <sip:1111111111@192.168.181.240:5060>
    09/01/2017 8:50:54 AM - Remote SDP is set for leg L:738.1[Extn:1300]
    09/01/2017 8:50:54 AM - [CM500002]: Call(C:738): Info on incoming INVITE from Extn:1300: Invite-IN Recv Req INVITE from 192.168.181.107:5060 tid=740594524 Call-ID=0_2722057096@192.168.181.107: INVITE sip:111111111@192.168.181.240:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.181.107:5060;branch=z9hG4bK740594524 Max-Forwards: 70 Contact: <sip:1300@192.168.181.107:5060> To: <sip:8182928144@192.168.181.240:5060> From: "M'lee"<sip:1300@192.168.181.240:5060>;tag=2373425256 Call-ID: 0_2722057096@192.168.181.107 CSeq: 2 INVITE Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE Content-Type: application/sdp Proxy-Authorization: Digest username="1300",realm="3CXPhoneSystem",nonce="414d535c0fba12de30:29e71063f50b97603358028781389325",uri="sip:11111111111@192.168.181.240:5060",response="fb0ad7454ab7914ae847d551dde70fa6",algorithm=MD5 Supported: replaces User-Agent: Yealink SIP-T48G 35.81.0.25 Allow-Events: talk, hold, conference, refer, check-sync Content-Length: 311 v=0 o=- 20002 20002 IN IP4 192.168.181.107 s=SDP data c=IN IP4 192.168.181.107 t=0 0 m=audio 7366 RTP/AVP 0 8 9 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 a=sendrecv a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15
    09/01/2017 8:50:54 AM - [CM503001]: Call(C:738): Incoming call from Extn:1300 to <sip:1111111111@192.168.181.240:5060>
    09/01/2017 8:50:54 AM - Leg L:738.1[Extn:1300] has external party ID {}
    09/01/2017 8:50:54 AM - NAT/ALG check:L:738.1[Extn:1300] REQUEST 'INVITE' - basic check passed. No information for extended checks
     
  9. leejor

    leejor Well-Known Member

    Joined:
    Jan 22, 2008
    Messages:
    11,113
    Likes Received:
    329
    I can see a 20 second delay between 8:50:54 and 8:51:15, which Isn't really explained. The line I fine puzzling is ..

    This begs the question...was there more than one call to begin with? It seems that one was terminated, yet (at least) one continued. There are still Invites beyond this message.
     
  10. NetAssure1234

    Joined:
    May 11, 2015
    Messages:
    14
    Likes Received:
    0
    here is another interesting tidbit. A user tested three phones. the first time they call a number the delay before ringing is about 20 seconds. if they call the number again from the same phone it immediately rings through.
     
  11. NetAssure1234

    Joined:
    May 11, 2015
    Messages:
    14
    Likes Received:
    0
    phones were reboot and reprovisioned and also, the phone call delay is also for internal calls. thanks for all the help. maybe i should just go back to version 14 which worked fine
     
  12. leejor

    leejor Well-Known Member

    Joined:
    Jan 22, 2008
    Messages:
    11,113
    Likes Received:
    329
    So, what difference is there in the logs? Same set, same destination number.
     
  13. NetAssure1234

    Joined:
    May 11, 2015
    Messages:
    14
    Likes Received:
    0
  14. NetAssure1234

    Joined:
    May 11, 2015
    Messages:
    14
    Likes Received:
    0
    perhaps this is the issue: when i first installed v15 it hung up and would not complete the install. So i had to reboot. uninstall. reinstall 14 and then install 15 a second time. perhaps this is what's going on. If i uninstall 15 then how do i manually remove all items in the registry? if i do that i can start clean from the start. Seem logical?
     
  15. leejor

    leejor Well-Known Member

    Joined:
    Jan 22, 2008
    Messages:
    11,113
    Likes Received:
    329
    That could very well be the issue. Without a "clean" install, you may have corruption. There used to be an uninstall checker that could be run after you have removed an old version. As it stands now, it is possible you could have "remnants" of both version 14 and 15 after removing. Don't know if you have used Regedit before (I assume you are running Windows). It allows you to search and edit the registry.

    It also allows you to completely screw up (kill) your operating system if not used with caution.

    You may want to consider creating a clone of your hard drive, or a re-storable image, so you have something to go back to in the worst case scenario. Macrium Reflect has a free version for non commercial use.

    If you do uninstall 3CX again, you could do a search for "3CX". Then delete all references. Be sure that you have any 3CX back-ups safely stored OFF the machine. I would then try a re-install of 14, as restoring any back-up of 15, at this point, may just re-introduce the issue.

    Be sure that all necessary updates are done to the machine before the install.
     
  16. YiannisH_3CX

    YiannisH_3CX Support Team
    Staff Member 3CX Support

    Joined:
    May 10, 2016
    Messages:
    7,400
    Likes Received:
    535
    Please do not post wireshark captures and logs that contains sensitive information.
    If you believe there might be some corruption in the system then the first step would be to re-install the system on a stable OS.
    Looking at the wireshark capture i can see the delay but i cannot tell where the delay is coming from as the capture was made on the phone and not the PBX so i cannot see the response from the Provider.
    With that in mind please proceed with re-installing the system and if the issue persists we can take it from there
     
Thread Status:
Not open for further replies.