Slow dialing process

[mark_fad]

Hi,

I have recently installed 3CX Phone system Version 5.1.4510.0 on a Windows XP virtual machine. The VOIP provider that i cannect to is MyNetFone. I also have a Linksys SPA 3102 Gateway which has 1 PSTN line that connects to the 3CX system. I have added 4 extensions, 1 PSTN line and 2 VOIP lines one just dials out and the other can dial out and includes a DID. All seems to be working well i.e calls to extensions, inbound calls through PSTN line and outbound calls through PSTN and VOIP. The only problem is that when making calls out through the VOIP line it takes a long time to connect the call..ie from when you dial the call to when you hear a ringing tone. The time taken is anywhere from 50 seconds to over 1.5 minutes. This is a call log that shows the time taken when the call is made to when it is answered.

From what i can understand from the logs is that i tries to use both VOIP lines to make the call. One seems to timeout then the other one connects. Could someone please give me an idea based on the log where i am going wrong.

14:25:23.888 Call::Terminate [CM503008]: Call(14): Call is terminated
14:25:23.878 Call::Terminate [CM503008]: Call(14): Call is terminated
14:24:23.351 CallLeg:nConfirmed Session 144 of leg C:14.1 is confirmed
14:24:23.131 CallCtrl:nLegConnected [CM503007]: Call(14): Device joined: sip:[email protected]:5060
14:24:23.121 CallCtrl:nLegConnected [CM503007]: Call(14): Device joined: sip:[email protected]:47008;rinstance=b021b59b7f0d53a4
14:24:23.121 MediaServerReporting::SetRemoteParty [MS210001] C:14.3:Answer received. RTP connection: 125.213.160.80:12074(12075)
14:24:23.121 CallLeg::setRemoteSdp Remote SDP is set for legC:14.3
14:24:17.533 MediaServerReporting::SetRemoteParty [MS210003] C:14.1:Answer provided. Connection(transcoding mode):192.168.60.8:7040(7041)
14:24:17.533 MediaServerReporting::SetRemoteParty [MS210001] C:14.3:Answer received. RTP connection: 125.213.160.80:12074(12075)
14:24:17.533 CallLeg::setRemoteSdp Remote SDP is set for legC:14.3
14:24:17.533 Line:rintEndpointInfo [CM505003]: Provider:[MyNetFone2] Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [ENSR2.5.4] Transport: [sip:192.168.60.8:5060]
14:24:17.533 CallCtrl:nAnsweredCall [CM503002]: Call(14): Alerting sip:[email protected]:5060
14:23:27.020 MediaServerReporting::SetRemoteParty [MS210002] C:14.3:Offer provided. Connection(transcoding mode): 60.241.19.219:9004(9005)
14:23:26.770 CallLeg:nFailure [CM503003]: Call(14): Call to sip:<PhoneNumber>@sip00.mynetfone.com.au:5060 has failed; Cause: 408 Request Timeout; internal
14:22:54.514 CallCtrl:nSelectRouteReq [CM503004]: Call(14): Calling: VoIPline:10002@[Dev:sip:[email protected]:5060]
14:22:54.504 MediaServerReporting::SetRemoteParty [MS210004] C:14.2:Offer provided. Connection(proxy mode): 60.241.19.219:9002(9003)
14:22:54.243 CallCtrl:nSelectRouteReq [CM503004]: Call(14): Calling: VoIPline:10001@[Dev:sip:[email protected]:5060]
14:22:54.233 CallCtrl:nSelectRouteReq [CM503010]: Making route(s) to "<PhoneNumber>"[sip:<PhoneNumber>@192.168.60.8]
14:22:54.233 MediaServerReporting::SetRemoteParty [MS210000] C:14.1:Offer received. RTP connection: 192.168.60.70:65114(65115)
14:22:54.233 CallLeg::setRemoteSdp Remote SDP is set for legC:14.1
14:22:54.233 Extension:rintEndpointInfo [CM505001]: Ext.104: Device info: Device Identified: [Man: Counterpath;Mod: X-Lite;Rev: General] Capabilities:[reinvite, no-replaces, unable-no-sdp, recvonly] UserAgent: [X-Lite release 1011s stamp 41150] Transport: [sip:192.168.60.8:5060]
14:22:54.223 CallCtrl:nIncomingCall [CM503001]: Call(14): Incoming call from Ext.104 to "<PhoneNumber>"[sip:<PhoneNumber>@192.168.60.8]

Regards,

Mark

 

[h2009]

Can i suggest that you test another provider, and see if the same issue still occurs?

 

[mark_fad]

The strange thing is i also have another 3CX box running 3CX V3 with the exact same setting and connecting to MyNetFone . When dialing out on a VOIP line on the V3 box it connects straight away.

 

[h2009]

Maybe you have a firewall issue, or if the second pc is a better spec, then that could also be a reason.
Could you list the spec of the machines, and how they are setup. (ip's static or dchp)?

 

[archie]

You have delay because first attempt is made using account with number 09155833 which doesn't respond. And than second attempt with number 09155832 was successful. But it took about 30 secs to find out that first account doesn;t resond.

 

[mark_fad]

Hi Archie,

Thank you for your response. I tried to do some more tests to determine what the problem could be.

Test 1
Set the SIP account settings of my x-lite softphone to the account settings that seem to be the one not connecting in the 3CX system and made some calls. The calls were connected everytime within 5 seconds of dialing.

Test 2
Deleted the voip line and recreated it. Changed the outbound rule to only go through the problem VOIP line. This is the log file of the test

09:59:07.252 Call::Terminate [CM503008]: Call(7): Call is terminated
09:59:07.222 Call::RouteFailed [CM503014]: Call(7): Attempt to reach "0400251600"[sip:[email protected]] failed. Reason: No Answer
09:59:07.222 CallLeg:nFailure [CM503003]: Call(7): Call to sip:[email protected]:5060 has failed; Cause: 408 Request Timeout; internal
09:58:34.786 MediaServerReporting::SetRemoteParty [MS210002] C:7.2:Offer provided. Connection(transcoding mode): 60.241.19.219:9010(9011)
09:58:34.525 CallCtrl:nSelectRouteReq [CM503004]: Call(7): Calling: VoIPline:10001@[Dev:sip:[email protected]:5060]
09:58:34.505 CallCtrl:nSelectRouteReq [CM503010]: Making route(s) to "0400251600"[sip:[email protected]]
09:58:34.505 MediaServerReporting::SetRemoteParty [MS210000] C:7.1:Offer received. RTP connection: 192.168.60.68:63574(63575)
09:58:34.505 CallLeg::setRemoteSdp Remote SDP is set for legC:7.1
09:58:34.505 Extension:rintEndpointInfo [CM505001]: Ext.100: Device info: Device Identified: [Man: Counterpath;Mod: X-Lite;Rev: General] Capabilities:[reinvite, no-replaces, unable-no-sdp, recvonly] UserAgent: [X-Lite release 1011s stamp 41150] Transport: [sip:192.168.60.8:5060]
09:58:34.495 CallCtrl:nIncomingCall [CM503001]: Call(7): Incoming call from Ext.100 to "0400251600"[sip:[email protected]]

Test 3
Only dial out through the VOIP line that connects

10:03:48.877 Call::Terminate [CM503008]: Call(8): Call is terminated
10:03:35.548 MediaServerReporting::SetRemoteParty [MS210003] C:8.1:Answer provided. Connection(transcoding mode):192.168.60.8:7090(7091)
10:03:35.538 MediaServerReporting::SetRemoteParty [MS210001] C:8.2:Answer received. RTP connection: 125.213.160.79:15434(15435)
10:03:35.538 CallLeg::setRemoteSdp Remote SDP is set for legC:8.2
10:03:35.538 Line:rintEndpointInfo [CM505003]: Provider:[MyNetFone2] Device info: Device Not Identified: User Agent not matched; Capabilities:[reinvite, replaces, able-no-sdp, recvonly] UserAgent: [ENSR2.5.4] Transport: [sip:192.168.60.8:5060]
10:03:35.538 CallCtrl:nAnsweredCall [CM503002]: Call(8): Alerting sip:[email protected]:5060
10:02:46.908 MediaServerReporting::SetRemoteParty [MS210002] C:8.2:Offer provided. Connection(transcoding mode): 60.241.19.219:9012(9013)
10:02:46.668 CallCtrl:nSelectRouteReq [CM503004]: Call(8): Calling: VoIPline:10002@[Dev:sip:[email protected]:5060]
10:02:46.658 CallCtrl:nSelectRouteReq [CM503010]: Making route(s) to "0400251600"[sip:[email protected]]
10:02:46.658 MediaServerReporting::SetRemoteParty [MS210000] C:8.1:Offer received. RTP connection: 192.168.60.68:50544(50545)
10:02:46.658 CallLeg::setRemoteSdp Remote SDP is set for legC:8.1
10:02:46.658 Extension:rintEndpointInfo [CM505001]: Ext.100: Device info: Device Identified: [Man: Counterpath;Mod: X-Lite;Rev: General] Capabilities:[reinvite, no-replaces, unable-no-sdp, recvonly] UserAgent: [X-Lite release 1011s stamp 41150] Transport: [sip:192.168.60.8:5060]
10:02:46.648 CallCtrl:nIncomingCall [CM503001]: Call(8): Incoming call from Ext.100 to "0400251600"[sip:[email protected]]
10:02:46.658 Extension:rintEndpointInfo [CM505001]: Ext.100: Device info: Device Identified: [Man: Counterpath;Mod: X-Lite;Rev: General] Capabilities:[reinvite, no-replaces, unable-no-sdp, recvonly] UserAgent: [X-Lite release 1011s stamp 41150] Transport: [sip:192.168.60.8:5060]
10:02:46.648 CallCtrl:nIncomingCall [CM503001]: Call(8): Incoming call from Ext.100 to "0400251600"[sip:[email protected]]

The results seem inconsistent. Some times i get a No Answer error and sometime it connects after about 50 seconds of waiting. However when dialing out directly from the softphone to the VOIP provider with either account the call is connected within seconds. I would like to try and solve this problem as i would like to keep using 3CX but if it is going to be inconsistant in connecting and when it does connect takes around 50 seconds to do so then i may have to revert back to an older version or another system.

Any more help would be appreciated. Also let me know if you need more information in regards to the setup that maybe useful in troubleshooting the problem.

Mark

 

[archie]

I think it would be useful if you sniff packets for third case and see if there's delay in answer from provider. If there's - just send them a capture and ask for explanations. If the delay is on our side - send us the capture and logs.

 

[mark_fad]

Hi Archie,

I have attached a log of packets while trying to make a call. From what i can make out there seems to be 2 delays. One between packet 116 - 212 and another between packet 215 - 259. I'm not very sure what it is meant to be doing inbetween those packets but their delay seems to total the time between making the call and getting a ringing tone. I hope this helps in finding the issue.

Regards,

Mark

 

[archie]

Problem is in DNS. Your text doesn't have DNS requests/responses expanded so I'm not 100% sure, but it seems that DNS query for SRV record _sip._udp.sip00.mynetfone.com.au has not been timely answered (Packet 124). You can fix it by putting resolved IPort of one of their proxy into Outbound Proxy field of provider's settings in 3CX.

 

[wisecomputers]

If for some reson that does not fix it, it is your router. change that out, and I think it may work just fine.

 

[mark_fad]

Changing the proxy server from a name to an IP did not fix the problem.

The router i am using is a Linksys WRT54G v3. Not sure if changing that would fix the problem as version 3 of 3CX works fine with no delay and setting up soft phones to connect directly to the VOIP provider also dial out instantly.

Mark

 

[nitup]

V3 doesn't use DNS SRV records if i'm not mistaken.

 

[mark_fad]

We do not seem to have any problems resolving names with our current DNS setup when using other applications eg. Internet Explorer, RDP Client, FTP clients, etc. I am waiting on some information back from MyNetFone in regards to the setup of the VOIP lines using 3CX. Will post any findings.

 

[mark_fad]

Response from MyNetFone is as follows...

"Apart form checking whether your VOIP line is registering correctly and
checking your VOIP details there is not much I can do to support your
3CX system.

Currently I can see your 3CX MNF VOIP line online and registering
correctly, I can't see anything wrong at this end.

I suggest contacting the 3CX team for further support, as it is outside
our area of expertise."

Not all that much help.

Mark

 

[mark_fad]

I have captured another set of network packets from our 3CX machine. This time i did not filter out the packets so hopefully it may shed some more light. I made a phone call and it still took around 50 seconds from dialing the number to the other end ringing. Not sure where else to look as MyNetFone have said they can not help me to resolve this issue as they think it is a 3CX problem. Could it be a problem with the ISP? We do not seem to have any other problems in browsing the web or resolving names....

Thanks to anyone that can assist in solving this issue.

Mark