Toggle sidebar Toggle sidebar

Outgoing Calls takes minutes to connect

Status
Not open for further replies.

Anthony Antonacci

Joined
May 30, 2018
Messages
8
Reaction score
0
Hi Guys, i am very new to 3CX.

I got the system running real fast, Softphones and android apps work, everybody can call each other and incoming calls from my VoIP provider work great. but calls going out or slow to react.

I dial the number, it takes a few minutes before the softphone starts ringing, then it takes about 4-5minutes of ringing before the phone on the other side rings. once the call is established i get voice and all.

here are logs but i'm not sure it will help...
Code: 
05/31/2018 11:54:01 AM - [CM504002]: Endpoint Extn:501: a contact is unregistered. Contact(s): [sip:[email protected]:50900 / 501,sip:[email protected]:5488 / 501]
05/31/2018 11:54:01 AM - Settings of Extn:501 has been updated
05/31/2018 11:53:55 AM - Currently active calls [none]
05/31/2018 11:53:54 AM - Leg L:3.2[Line:10000>>1234567890] is terminated: Cause: BYE from local
05/31/2018 11:53:54 AM - [CM503008]: Call(C:3): Call is terminated
05/31/2018 11:53:54 AM - Leg L:3.1[Extn:501] is terminated: Cause: BYE from 10.10.1.47:50900
05/31/2018 11:53:42 AM - [CM503007]: Call(C:3): Line:10000>>1234567890 has joined, contact <sip:[email protected]:5060>
05/31/2018 11:53:42 AM - [CM503007]: Call(C:3): Extn:501 has joined, contact <sip:[email protected]:50900>
05/31/2018 11:53:42 AM - L:3.2[Line:10000>>1234567890] has joined to L:3.1[Extn:501]
05/31/2018 11:53:25 AM - Currently active calls - 1: [3]
05/31/2018 11:53:17 AM - [CM504001]: Endpoint Extn:509: new contact is registered. Contact(s): [sip:[email protected]:20356 / 509,sip:[email protected]:5488 / 509]
05/31/2018 11:53:16 AM - [CM504002]: Endpoint Extn:509: a contact is unregistered. Contact(s): [sip:[email protected]:5488 / 509]
05/31/2018 11:53:15 AM - [CM504001]: Endpoint Extn:501: new contact is registered. Contact(s): [sip:[email protected]:50900 / 501,sip:[email protected]:5488 / 501,sip:[email protected]:5060 / 501]
05/31/2018 11:53:15 AM - Settings of Extn:501 has been updated
05/31/2018 11:53:15 AM - [CM504002]: Endpoint Extn:501: a contact is unregistered. Contact(s): [sip:[email protected]:50900 / 501,sip:[email protected]:5488 / 501]
05/31/2018 11:53:15 AM - Settings of Extn:501 has been updated
05/31/2018 11:53:14 AM - [CM102001]: Authentication failed for AuthFail Recv Req SUBSCRIBE from 72.143.212.141:27200 tid=Pj35wPlTuEXUVx0WJno5orDYQNkMFjH.Dx Call-ID=NOLazfeWhfRcIdkKICSIg8EPa3NsKnGk:
SUBSCRIBE sip:[email protected] SIP/2.0
Via: SIP/2.0/UDP 192.0.0.4:35746;rport=27200;branch=z9hG4bKPj35wPlTuEXUVx0WJno5orDYQNkMFjH.Dx;received=72.143.212.141
Max-Forwards: 70
Contact: "An A" <sip:[email protected]:5060;inst="0a3141d9";rinstance=1-ku.5fjfgroclltlgelpqsj3rwx2npx8o>
To: "An A" <sip:[email protected]>
From: "An A" <sip:[email protected]>;tag=Uk-UtsZJeq7Z6VUw8qQ1ZqAQPuAgyRwk
Call-ID: NOLazfeWhfRcIdkKICSIg8EPa3NsKnGk
CSeq: 11928 SUBSCRIBE
Expires: 0
Accept: application/simple-message-summary
Proxy-Authorization: Digest username="dfsckhx",realm="3CXPhoneSystem",nonce="414d535c1120ab6a29:9cdf1f61b66f8c9ab3da3bd8215a1e97",uri="sip:[email protected]",response="36f8955de8016096fe83134a5e8eb074",algorithm=MD5
Supported: replaces, 100rel, timer, norefersub
Event: message-summary
Allow-Events: presence, message-summary, refer
Content-Length: 0
; Reason: Credentials don't match, check that authorization-ID and password match the ones in extension settings
05/31/2018 11:53:14 AM - Endpoint Extn:501: the request from external source 72.143.212.141:27200/UDP fk=836is blocked. Reason: the extension is configured to block external registrations.
05/31/2018 11:53:14 AM - [CM504001]: Endpoint Extn:501: new contact is registered. Contact(s): [sip:[email protected]:50900 / 501,sip:[email protected]:5488 / 501,sip:[email protected]:5060 / 501]
05/31/2018 11:53:14 AM - Settings of Extn:501 has been updated
05/31/2018 11:52:55 AM - Currently active calls - 1: [3]
05/31/2018 11:52:25 AM - Currently active calls - 1: [3]
05/31/2018 11:51:55 AM - Currently active calls - 1: [3]
05/31/2018 11:51:25 AM - Currently active calls - 1: [3]
05/31/2018 11:51:10 AM - [CM505003]: Provider:[ACC000] Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [] PBX contact: [sip:[email protected]:5060]
05/31/2018 11:51:10 AM - [CM503002]: Call(C:3): Alerting Line:10000>>1234567890 by contact <sip:[email protected]:5060>
05/31/2018 11:50:55 AM - Currently active calls - 1: [3]
05/31/2018 11:50:25 AM - Currently active calls - 1: [3]
05/31/2018 11:50:10 AM - [CM503025]: Call(C:3): Calling T:Line:10000>>1234567890@[Dev:sip:[email protected]:5060] for L:3.1[Extn:501]
05/31/2018 11:50:10 AM - [CM503027]: Call(C:3): From: Extn:501 ("An A" <sip:[email protected]:5060>)  to  T:Line:10000>>1234567890@[Dev:sip:[email protected]:5060]
05/31/2018 11:50:10 AM - [CM503004]: Call(C:3): Route 1: from L:3.1[Extn:501] to T:Line:10000>>1234567890@[Dev:sip:[email protected]:5060]
05/31/2018 11:50:10 AM - Line limit check: Current # of calls for line Lc:10000(@ACC000[<sip:[email protected]:5060>]) is 0; limit is 10
05/31/2018 11:50:10 AM - Call(C:3): Call from Extn:501 to 1234567890 matches outbound rule 'All'
05/31/2018 11:50:10 AM - [Flow] Call(C:3): has built target endpoint: Out#:>>Rule{All}>>1234567890 for call from L:3.1[Extn:501]
05/31/2018 11:50:10 AM - [Flow] Target endpoint for 1234567890 is Out#:>>Rule{All}>>1234567890
05/31/2018 11:50:10 AM - [CM503010]: Call(C:3): Making route(s) from Extn:501 to <sip:[email protected]:5060>
05/31/2018 11:50:10 AM - [CM505001]: Endpoint Extn:501: Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [3CXPhone for Windows 15.5.10795.4] PBX contact: [sip:[email protected]:5060]
05/31/2018 11:50:10 AM - [CM500002]: Call(C:3): Info on incoming INVITE from Extn:501:
Invite-IN Recv Req INVITE from 10.10.1.47:49771 tid=Pj5a96ce4369814f8688fd34a75ae6035f Call-ID=efe03492878b43f38eea161e2b547117:
INVITE sip:[email protected];tag3cx=4950f859672e496b8e9d05a53c0a4f81 SIP/2.0
Via: SIP/2.0/TCP 10.10.1.47:49771;rport=49771;branch=z9hG4bKPj5a96ce4369814f8688fd34a75ae6035f;alias
Max-Forwards: 70
Contact: <sip:[email protected]:50900;rinstance=0-4e593d2a5f734ef5a17f05fa10e2b4e2;ob>
To: <sip:[email protected];tag3cx=4950f859672e496b8e9d05a53c0a4f81>
From: "An A"<sip:[email protected]>;tag=4ae4edba2fc34805a7c362f920cb0b12
Call-ID: efe03492878b43f38eea161e2b547117
CSeq: 4883 INVITE
Session-Expires: 1800
Min-SE: 90
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Content-Type: application/sdp
Proxy-Authorization: Digest username="dfsckhx",realm="3CXPhoneSystem",nonce="414d535c1120aab284:d08bcba8deb2bf50c8e988517eb89178",uri="sip:[email protected];tag3cx=4950f859672e496b8e9d05a53c0a4f81",response="c9517872c9bdb602f085f53dc7726d60",algorithm=MD5
Supported: replaces, 100rel, timer, norefersub
User-Agent: 3CXPhone for Windows 15.5.10795.4
Content-Length: 418
v=0
o=- 3736756253 3736756253 IN IP4 10.10.1.47
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 42044 RTP/AVP 3 18 0 8 9 96
c=IN IP4 10.10.1.47
b=TIAS:64000
b=AS:84
a=rtcp:42045
a=sendrecv
a=rtpmap:3 GSM/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
m=video 0 RTP/AVP 31
c=IN IP4 127.0.0.1
05/31/2018 11:50:10 AM - [CM503001]: Call(C:3): Incoming call from Extn:501 to <sip:[email protected]:5060>
 
I had that same exact issue last Friday and it was resolved by rebooting the server. Planned to investigate if it persisted but it hasn't happened again.
 
I had not tried that! (i know, when in doubt, reboot)
Anyhow i rebooted but issue is still there. i'm going to test the trunk on my asterisk server to see if its a trunk issue...
 
Looks like the call is passed to voip.ms with no delay, then it happens.

If, after you try a reboot, you still have the delay issue, you might consider contacting voip.ms to see if they can tell you why it is happening. It might be the particular server you are passing through, or a trunk setting, that need to be changed. If this happens every time then they should be able to pinpoint what is going on.

Does this seem to happen on all calls, or calls to particular numbers...certain mobiles?
 
I configured the Trunk on my Asterisk server and it works instant.
Maybe
So looks like the issue is really in my 3CX configuration. i will scour forums about 3cx + voip.ms configs...

I also installed Wireshark to try to figure out where the delay is coming from, but its not helping too much ...
 
Anthony Antonacci said:
I also installed Wireshark to try to figure out where the delay is coming from, but its not helping too much ...
Click to expand...
This actually would be useful. "...not helping too much..." what did you see? Personal advice, check for the DNS resolution as well in wireshark. I have see multiple cases where it a server is configured with an old/invalid DNS server and the software can't resolve the registrar address for 15-20 seconds...
(If in doubt, set Google DNS as Primary and restart all 3CX Services)

I would be interested though to hear what you saw in the capture in general.
 
So i installed the Sottphone directly on the Server.... outbound call connects in 8 seconds!

So I guess my issue is between the SoftPhone and the Server. Would have never guessed since internal calls are instant and work fine. (even calls through Android app over LTE work great.
 
Anthony Antonacci said:
So I guess my issue is between the SoftPhone and the Server.
Click to expand...

That delay should be apparent in the logs if you make note of what time you dialled the last digit, or hit send.
 
Here are logs from the moment i initiate the call until i hang up.
You can clearly see there is a delay with not much happening between...
what is really weird, in most my test i always get a exact 1 minute interval between the "dial button press" and when the line starts ringing on the softphone. it then takes 3 minutes of ringing before the remote phone starts ringings

I have a weird message saying my provider is not identified... not sure what to do with that.

06/15/2018 4:49:34 PM - [CM503008]: Call(C:6): Call is terminated
06/15/2018 4:49:34 PM - Leg L:6.2[Line:10000>>5141111111] is terminated: Cause: BYE from 192.175.96.69:5060
06/15/2018 4:49:22 PM - [CM503007]: Call(C:6): Line:10000>>5141111111 has joined, contact <sip:[email protected]:5060>
06/15/2018 4:49:22 PM - [CM503007]: Call(C:6): Extn:501 has joined, contact <sip:[email protected]:60767>
06/15/2018 4:49:22 PM - L:6.2[Line:10000>>5141111111] has joined to L:6.1[Extn:501]
06/15/2018 4:47:39 PM - Currently active calls - 1: [6]
06/15/2018 4:47:09 PM - Currently active calls - 1: [6]
06/15/2018 4:46:39 PM - Currently active calls - 1: [6]
06/15/2018 4:46:35 PM - [CM505003]: Provider:[222222] Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [] PBX contact: [sip:[email protected]:5060]
06/15/2018 4:46:35 PM - [CM503002]: Call(C:6): Alerting Line:10000>>5141111111 by contact <sip:[email protected]:5060>
06/15/2018 4:46:09 PM - Currently active calls - 1: [6]
06/15/2018 4:45:39 PM - Currently active calls - 1: [6]
06/15/2018 4:45:35 PM - [CM503025]: Call(C:6): Calling T:Line:10000>>5141111111@[Dev:sip:[email protected]:5060] for L:6.1[Extn:501]
06/15/2018 4:45:35 PM - [CM503027]: Call(C:6): From: Extn:501 ("Anthony Antonacci" <sip:[email protected]:5060>) to T:Line:10000>>5141111111@[Dev:sip:[email protected]:5060]
06/15/2018 4:45:35 PM - [CM503004]: Call(C:6): Route 1: from L:6.1[Extn:501] to T:Line:10000>>5141111111@[Dev:sip:[email protected]:5060]
06/15/2018 4:45:35 PM - Line limit check: Current # of calls for line Lc:10000(@222222[<sip:[email protected]:5060>]) is 0; limit is 10
06/15/2018 4:45:35 PM - Call(C:6): Call from Extn:501 to 5141111111 matches outbound rule 'All'
06/15/2018 4:45:35 PM - [Flow] Call(C:6): has built target endpoint: Out#:>>Rule{All}>>5141111111 for call from L:6.1[Extn:501]
06/15/2018 4:45:35 PM - [Flow] Target endpoint for 5141111111 is Out#:>>Rule{All}>>5141111111
06/15/2018 4:45:35 PM - [CM503010]: Call(C:6): Making route(s) from Extn:501 to <sip:[email protected]:5060>
06/15/2018 4:45:35 PM - [CM505001]: Endpoint Extn:501: Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [3CXPhone for Windows 15.5.10795.4] PBX contact: [sip:[email protected]:5060]
06/15/2018 4:45:35 PM - [CM500002]: Call(C:6): Info on incoming INVITE from Extn:501:
Invite-IN Recv Req INVITE from 10.10.1.47:50774 tid=Pjc7c8a87518fe4364a0ab6ee4f1e4d3b8 Call-ID=42d980e21f2046d0a69deb2835be05c0:
INVITE sip:[email protected];tag3cx=7cf08d4f59824443be639b66ccb6ebeb SIP/2.0
Via: SIP/2.0/TCP 10.10.97.13:50774;rport=50774;branch=z9hG4bKPjc7c8a87518fe4364a0ab6ee4f1e4d3b8;received=10.10.1.47;alias
Max-Forwards: 70
Contact: <sip:[email protected]:60767;rinstance=0-31299aef7e634a48945d2f484d33a917;ob>
To: <sip:[email protected];tag3cx=7cf08d4f59824443be639b66ccb6ebeb>
From: "Anthony Antonacci"<sip:[email protected]>;tag=bdd9411bbe0646c790d65f4c8f821fe9
Call-ID: 42d980e21f2046d0a69deb2835be05c0
CSeq: 12264 INVITE
Session-Expires: 1800
Min-SE: 90
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Content-Type: application/sdp
Proxy-Authorization: Digest username="dfsckhx",realm="3CXPhoneSystem",nonce="414d535c1134b66f16:a3705f0d74c157a9ec8d057884be6e9e",uri="sip:[email protected];tag3cx=7cf08d4f59824443be639b66ccb6ebeb",response="8a089d6133c409acbb0e62a69b06b1d1",algorithm=MD5
Supported: replaces, 100rel, timer, norefersub
User-Agent: 3CXPhone for Windows 15.5.10795.4
Content-Length: 418
v=0
o=- 3738069998 3738069998 IN IP4 10.10.1.47
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 42008 RTP/AVP 3 18 0 8 9 96
c=IN IP4 10.10.1.47
b=TIAS:64000
b=AS:84
a=rtcp:42009
a=sendrecv
a=rtpmap:3 GSM/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-15
m=video 0 RTP/AVP 31
c=IN IP4 127.0.0.1
06/15/2018 4:45:35 PM - [CM503001]: Call(C:6): Incoming call from Extn:501 to <sip:[email protected]:5060>
 
I had similar issue some time ago, try using IP address instead of FQDN
 
in the sip trunk configs? Just changed it, no difference...
Any logging in 3CX softphones? (as I mentioned call goes out almost instant on softphone installed on server) - I checked softphone configs, IP is listed. (except for out of office configs)
Also disabled firewall on server....
 
Have you tried using any other Voip.ms server? Did you ever try changing your DNS server as suggested earlier?
 
No change with google DNS.
I moved away from the "voip.ms" hypothesis since locally installed softphone works ok (7 secs)
i could move the server to another Host that has a NIC connected to another trunk we are using but if the issues is between softphone and server what would that change? (I guess it would really eliminate any chances)
 
When i said server, I meant the montreal5.voip.ms server. I know they usually have several to choose from in the larger cities.
 
ah yes ok, didn't think of that. great idea, just tried it, same issue...
Maybe il try to configure a Real SIP phone and see it it will make a difference...
 
Have you contacted Voip.ms for assistance? From the logs, the delay would seem to happen after you send the call to them. There may something in your trunk settings that they do not like, but, eventually do put the call through, it seems. Obviously it should not take a full minute to get an Alert back from them. I assume that you are trying this with various numbers and that the destination number is not the culprit. I know that if I place calls to certain mobile provider numbers, using Voip.ms, it can take 30 or 40 seconds, to get ring back. I'm assuming that is the fault of the particular mobile operator, as all landline numbers ring immediately.
 
  • Like
Reactions: NickD_3CX
Status
Not open for further replies.

Latest Posts

Forum statistics

Threads
111,885
Messages
589,547
Members
164,746
Latest member
Bastion Advisory
3CX Logo Footer Copyright © Sitemap Privacy
Top Bottom