Extension keeps disconnecting

I’m running FreePBX’s last version with 2 extensions, both Sangoma phones (one 705 and one 305). As you can see from the below, it seems that one of the extension only connects for a short time (<1 min) before it gets disconnected. This happens about every 8 minutes.

image

The extension that fails is 110

Asterisks Logs are not very helpful:

 [2020-03-08 23:06:52] VERBOSE[10300] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56012 is now Reachable. RTT: 100.087 msec
[2020-03-08 23:07:55] VERBOSE[6092] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56012 is now Unreachable. RTT: 0.000 msec
[2020-03-08 23:14:23] VERBOSE[25486] res_pjsip_registrar.c: Added contact 'sip:[email protected]:56013' to AOR '110' with expiration of 900 seconds
[2020-03-08 23:14:23] VERBOSE[25486] res_pjsip_registrar.c: Removed contact 'sip:[email protected]:56012' from AOR '110' due to remove existing
[2020-03-08 23:14:23] VERBOSE[10300] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56012 has been deleted
[2020-03-08 23:14:23] VERBOSE[10300] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56013 is now Reachable. RTT: 57.302 msec
[2020-03-08 23:15:26] VERBOSE[25486] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56013 is now Unreachable. RTT: 0.000 msec
[2020-03-08 23:21:53] VERBOSE[25486] res_pjsip_registrar.c: Added contact 'sip:[email protected]:56014' to AOR '110' with expiration of 900 seconds
[2020-03-08 23:21:53] VERBOSE[25486] res_pjsip_registrar.c: Removed contact 'sip:[email protected]:56013' from AOR '110' due to remove existing
[2020-03-08 23:21:53] VERBOSE[6092] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56013 has been deleted
[2020-03-08 23:21:54] VERBOSE[6092] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56014 is now Reachable. RTT: 68.774 msec
[2020-03-08 23:22:56] VERBOSE[25486] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56014 is now Unreachable. RTT: 0.000 msec
[2020-03-08 23:29:24] VERBOSE[6092] res_pjsip_registrar.c: Added contact 'sip:[email protected]:56015' to AOR '110' with expiration of 900 seconds
[2020-03-08 23:29:24] VERBOSE[6092] res_pjsip_registrar.c: Removed contact 'sip:[email protected]:56014' from AOR '110' due to remove existing
[2020-03-08 23:29:24] VERBOSE[10300] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56014 has been deleted
[2020-03-08 23:29:24] VERBOSE[10300] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56015 is now Reachable. RTT: 68.072 msec
[2020-03-08 23:30:27] VERBOSE[6092] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56015 is now Unreachable. RTT: 0.000 msec

The phone’s IP address shows as H3G mobile data. Is that correct? If so, is the working extension behind the same 4G router and on the same LAN?

It appears that the NAT association is being lost between registrations, not surprising since the interval is ~450 seconds (the phone reregisters after half of the 900 second expiry). But what is surprising is that the very first qualify fails, only 60 seconds after registration.

As a test, try changing Qualify Frequency for the extension from 60 to 20. If that doesn’t help, post a new log.

Another thing that may help is changing Maximum Expiration from 7200 to 90. If no luck, post a log of that, too.

1 Like

The working extension is on another network, behind a different firewall (not a 3G/4G router).

I changed the Quality Frequency from 60 to 20 as suggested and have the same logs:

[2020-03-10 23:28:49] VERBOSE[30251] res_pjsip_registrar.c: Added contact 'sip:[email protected]:56005' to AOR '110' with expiration of 900 seconds
[2020-03-10 23:28:49] VERBOSE[30251] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Reachable
[2020-03-10 23:28:49] VERBOSE[30251] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56005 is now Reachable. RTT: 108.152 msec
[2020-03-10 23:28:57] NOTICE[30251] res_pjsip/pjsip_distributor.c: Request 'INVITE' from '&lt;sip:90807000799964113:[email protected]&gt;' failed for '62.210.70.138:64685' (callid: 389953981-1738523665-1075388594) - No matching endpoint found
[2020-03-10 23:29:32] VERBOSE[30251] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Unreachable
[2020-03-10 23:29:32] VERBOSE[30251] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56005 is now Unreachable. RTT: 0.000 msec
[2020-03-10 23:29:40] VERBOSE[30251] res_pjsip_registrar.c: Added contact 'sip:[email protected]:56006' to AOR '110' with expiration of 900 seconds
[2020-03-10 23:29:40] VERBOSE[30251] res_pjsip_registrar.c: Removed contact 'sip:[email protected]:56005' from AOR '110' due to remove existing
[2020-03-10 23:29:40] VERBOSE[15366] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56005 has been deleted
[2020-03-10 23:29:40] VERBOSE[30251] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Reachable
[2020-03-10 23:29:40] VERBOSE[30251] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:56006 is now Reachable. RTT: 85.655 msec

I also changed the Maximum Expiration:

[2020-03-11 16:03:12] VERBOSE[6540] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Unreachable
[2020-03-11 16:03:12] VERBOSE[6540] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11128 is now Unreachable. RTT: 0.000 msec
[2020-03-11 16:03:15] VERBOSE[24774] res_pjsip_registrar.c: Added contact 'sip:[email protected]:11129' to AOR '110' with expiration of 90 seconds
[2020-03-11 16:03:15] VERBOSE[24774] res_pjsip_registrar.c: Removed contact 'sip:[email protected]:11128' from AOR '110' due to remove existing
[2020-03-11 16:03:15] VERBOSE[28967] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11128 has been deleted
[2020-03-11 16:03:15] VERBOSE[28967] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Reachable
[2020-03-11 16:03:15] VERBOSE[28967] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11129 is now Reachable. RTT: 75.675 msec
[2020-03-11 16:03:58] VERBOSE[6540] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Unreachable
[2020-03-11 16:03:58] VERBOSE[6540] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11129 is now Unreachable. RTT: 0.000 msec
[2020-03-11 16:04:01] VERBOSE[24774] res_pjsip_registrar.c: Added contact 'sip:[email protected]:11130' to AOR '110' with expiration of 90 seconds
[2020-03-11 16:04:01] VERBOSE[24774] res_pjsip_registrar.c: Removed contact 'sip:[email protected]:11129' from AOR '110' due to remove existing
[2020-03-11 16:04:01] VERBOSE[28967] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11129 has been deleted
[2020-03-11 16:04:01] VERBOSE[28967] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Reachable
[2020-03-11 16:04:01] VERBOSE[28967] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11130 is now Reachable. RTT: 67.589 msec
[2020-03-11 16:04:44] VERBOSE[6540] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Unreachable
[2020-03-11 16:04:44] VERBOSE[6540] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11130 is now Unreachable. RTT: 0.000 msec
[2020-03-11 16:04:47] VERBOSE[28967] res_pjsip_registrar.c: Added contact 'sip:[email protected]:11131' to AOR '110' with expiration of 90 seconds
[2020-03-11 16:04:47] VERBOSE[28967] res_pjsip_registrar.c: Removed contact 'sip:[email protected]:11130' from AOR '110' due to remove existing
[2020-03-11 16:04:47] VERBOSE[6540] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11130 has been deleted
[2020-03-11 16:04:47] VERBOSE[1375] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Reachable
[2020-03-11 16:04:47] VERBOSE[1375] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11131 is now Reachable. RTT: 65.815 msec
[2020-03-11 16:05:30] VERBOSE[6540] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Unreachable
[2020-03-11 16:05:30] VERBOSE[6540] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11131 is now Unreachable. RTT: 0.000 msec
[2020-03-11 16:05:33] VERBOSE[1375] res_pjsip_registrar.c: Added contact 'sip:[email protected]:11133' to AOR '110' with expiration of 90 seconds
[2020-03-11 16:05:33] VERBOSE[1375] res_pjsip_registrar.c: Removed contact 'sip:[email protected]:11131' from AOR '110' due to remove existing
[2020-03-11 16:05:33] VERBOSE[1375] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11131 has been deleted
[2020-03-11 16:05:33] VERBOSE[28967] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Reachable
[2020-03-11 16:05:33] VERBOSE[28967] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11133 is now Reachable. RTT: 73.034 msec
[2020-03-11 16:06:16] VERBOSE[1375] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Unreachable
[2020-03-11 16:06:16] VERBOSE[1375] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11133 is now Unreachable. RTT: 0.000 msec
[2020-03-11 16:06:19] VERBOSE[28967] res_pjsip_registrar.c: Added contact 'sip:[email protected]:11134' to AOR '110' with expiration of 90 seconds
[2020-03-11 16:06:19] VERBOSE[28967] res_pjsip_registrar.c: Removed contact 'sip:[email protected]:11133' from AOR '110' due to remove existing
[2020-03-11 16:06:19] VERBOSE[6540] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11133 has been deleted
[2020-03-11 16:06:19] VERBOSE[1375] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Reachable
[2020-03-11 16:06:19] VERBOSE[1375] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11134 is now Reachable. RTT: 78.716 msec
[2020-03-11 16:07:02] VERBOSE[28967] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Unreachable
[2020-03-11 16:07:02] VERBOSE[28967] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11134 is now Unreachable. RTT: 0.000 msec
[2020-03-11 16:07:05] VERBOSE[6540] res_pjsip_registrar.c: Added contact 'sip:[email protected]:11135' to AOR '110' with expiration of 90 seconds
[2020-03-11 16:07:05] VERBOSE[6540] res_pjsip_registrar.c: Removed contact 'sip:[email protected]:11134' from AOR '110' due to remove existing
[2020-03-11 16:07:05] VERBOSE[1375] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11134 has been deleted
[2020-03-11 16:07:05] VERBOSE[1375] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Reachable
[2020-03-11 16:07:05] VERBOSE[1375] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11135 is now Reachable. RTT: 66.941 msec
[2020-03-11 16:07:48] VERBOSE[24774] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Unreachable
[2020-03-11 16:07:48] VERBOSE[24774] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11135 is now Unreachable. RTT: 0.000 msec
[2020-03-11 16:07:51] VERBOSE[1375] res_pjsip_registrar.c: Added contact 'sip:[email protected]:11136' to AOR '110' with expiration of 90 seconds
[2020-03-11 16:07:51] VERBOSE[1375] res_pjsip_registrar.c: Removed contact 'sip:[email protected]:11135' from AOR '110' due to remove existing
[2020-03-11 16:07:51] VERBOSE[28967] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11135 has been deleted
[2020-03-11 16:07:51] VERBOSE[1375] res_pjsip/pjsip_configuration.c: Endpoint 110 is now Reachable
[2020-03-11 16:07:51] VERBOSE[1375] res_pjsip/pjsip_options.c: Contact 110/sip:[email protected]:11136 is now Reachable. RTT: 85.281 msec

I’m puzzled why the frequent qualify did not help. After registration at 23:28:49, there was presumably a qualify (OPTIONS) sent at about 23:29:09 that did get a response, but the NAT association apparently timed out anyhow and the next qualify at ~ 23:29:29 got no response and it was marked unreachable at 23:29:32. I’m guessing that the NAT timeout is ~30 seconds.

Possibly, getting the phone to register every 20 seconds will help, IMO not likely but it’s easy to try. Set Minimum Expiration to 20 and Maximum Expiration to 40.

If no luck, back out those changes and try keep-alive on the phone. See
http://www.surevoip.co.uk/support/wiki/howtos:setup:sangoma_s_series
the section “Set SIP keep-alive”. Set it to 20. If you are using the Endpoint Manager or another autoprovision method, do it there, as any changes you make manually on the make on the phone will get overwritten. Sorry that this is vague, but I have no experience with these phones.

If that also doesn’t work, there may be a setting in the 4G router that will help. Failing that, I’m pretty much out of ideas. Conceivably a VPN connection or a different router model would work.

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.