Toggle sidebar Toggle sidebar

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

Status
Not open for further replies.

NetAssure1234

Bronze Partner
Basic Certified
Joined
May 11, 2015
Messages
18
Reaction score
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,
 
I would check the 3CX Activity Log to see at what point the delay is occurring. Go from there.
 
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.
 
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.
 
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.
 
  • Like
Reactions: nb
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
 
The 3CX Activity Log would be more useful, at least for me. Wireshark doesn't show what is happening inside the PBX.
 
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:[email protected]: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 [email protected]: BYE sip:[email protected]:5060 SIP/2.0 Via: SIP/2.0/ ;branch=z9hG4bK-524287-1---354f2330d43f3e46;rport Max-Forwards: 70 Contact: <sip:[email protected]:5060> To: "M'lee"<sip:[email protected]:5060>;tag=2373425256 From: <sip:[email protected]:5060>;tag=b172c428 Call-ID: [email protected] 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 [email protected]: BYE sip:[email protected]:5060 SIP/2.0 Via: SIP/2.0/ ;branch=z9hG4bK-524287-1---887d283ff21edd11;rport Max-Forwards: 70 Contact: <sip:[email protected]:5060> To: "M'lee"<sip:[email protected]:5060>;tag=2373425256 From: <sip:[email protected]:5060>;tag=b172c428 Call-ID: [email protected] 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:[email protected]: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:[email protected]: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:[email protected]: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 [email protected]: ACK sip:[email protected]:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.181.107:5060;branch=z9hG4bK3657157992 Max-Forwards: 70 Contact: <sip:[email protected]:5060> To: <sip:[email protected]:5060>;tag=b172c428 From: "M'lee" <sip:[email protected]:5060>;tag=2373425256 Call-ID: [email protected] CSeq: 2 ACK Proxy-Authorization: Digest username="1300", realm="3CXPhoneSystem", nonce="414d535c0fba12de30:29e71063f50b97603358028781389325", uri="sip:[email protected]: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:[email protected]: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:[email protected]: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 [email protected]: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.181.107:5060;branch=z9hG4bK740594524 Contact: <sip:[email protected]:5060> To: <sip:[email protected]:5060>;tag=b172c428 From: "M'lee"<sip:[email protected]:5060>;tag=2373425256 Call-ID: [email protected] 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 [email protected]: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.181.107:5060;branch=z9hG4bK740594524 Contact: <sip:[email protected]:5060> To: <sip:[email protected]:5060>;tag=b172c428 From: "M'lee"<sip:[email protected]:5060>;tag=2373425256 Call-ID: [email protected] 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:[email protected]: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 [email protected]: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.181.107:5060;branch=z9hG4bK740594524 Contact: <sip:[email protected]:5060> To: <sip:[email protected]:5060>;tag=b172c428 From: "M'lee"<sip:[email protected]:5060>;tag=2373425256 Call-ID: [email protected] 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:[email protected]:5060, Call(C:738)
09/01/2017 8:50:55 AM - [CM503025]: Call(C:738): Calling T:Line:10000>>1111111111@[Dev:sip:[email protected]: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:[email protected]:5060]
09/01/2017 8:50:54 AM - [CM503027]: Call(C:738): From: Extn:1300 ("M'lee" <sip:[email protected]:5060>) to T:Line:10000>>11111111111@[Dev:sip:[email protected]: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:[email protected]: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:[email protected]: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 [email protected]: INVITE sip:[email protected]:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.181.107:5060;branch=z9hG4bK740594524 Max-Forwards: 70 Contact: <sip:[email protected]:5060> To: <sip:[email protected]:5060> From: "M'lee"<sip:[email protected]:5060>;tag=2373425256 Call-ID: [email protected] 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:[email protected]: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:[email protected]: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
 
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 ..

NetAssure1234 said:
09/01/2017 8:51:18 AM - L:738.1[Extn:1300]: Terminating targets, reason: SIP ;cause=200 ;text="Call completed elsewhere"
Click to expand...

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.
 
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.
 
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
 
So, what difference is there in the logs? Same set, same destination number.
 
yes
 
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?
 
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.
 
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
 
Status
Not open for further replies.

Latest Posts

Forum statistics

Threads
111,873
Messages
589,501
Members
164,722
Latest member
Arnel
3CX Logo Footer Copyright © Sitemap Privacy
Top Bottom