Hello,
We are having random issues with the Sangoma S705 model only. We have tried swapping them for other S705 phones and the issue persists. What happens is it starts ringing in a strange way where one ring starts and interrupts the previous ring, and it is not possible to answer the phone. We also have the report of the same phones locking up and becoming unresponsive. We also have Sangoma S500/S505 and the issue is not happening with those phones.
Here is a video taken of the strange ringing: https://www.youtube.com/watch?v=hF4tslaEI-I
Is there any advice? This issue is a big problem for us.
Here is the log of one of the phones during one of the strange ringing incidents.
[09-23 08:54:38 52:ff:c5] init_ehs_mode
[09-23 08:55:22 52:ff:c5] SIP: aid 0, cid 0, tid 4649, did 0, REQUEST: OPTIONS, Event: 27
[09-23 08:55:22 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:55:22 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:55:55 52:ff:c5] NTP: NTP Server1 IP: 206.188.112.166
[09-23 08:55:55 52:ff:c5] NTP: GetNtpTime from 206.188.112.166 OK, 1632405354 seconds
[09-23 08:55:55 52:ff:c5]
Set time [1632405354] seconds to linux
[09-23 08:55:55 52:ff:c5] NTP: Adjust Time Thru Zone, DST is Manually Enable
[09-23 08:55:55 52:ff:c5] NTP: AdjustTimeZone, 875004954 seconds
[09-23 08:56:19 52:ff:c5] Open /dev/ttyS0
[09-23 08:56:19 52:ff:c5] Baudrate is 2400
[09-23 08:56:19 52:ff:c5] init_ehs_mode
[09-23 08:56:20 52:ff:c5] SIP: sip_nict_init, no route, req_uri->host:port is 10.160.10.2:5060
[09-23 08:56:20 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:56:20 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:56:20 52:ff:c5] SIP: aid 0, cid 0, tid 0, did 0, REQUEST: REGISTER, Event: 2
[09-23 08:56:20 52:ff:c5] SIP: aid 0, cid 0, tid 0, did 0, RESPONSE: 401 Unauthorized, Registration failed!, Event: 2
[09-23 08:56:20 52:ff:c5] SIP: find_authentication_info, aid 0, username: 7115, realm: “asterisk”
[09-23 08:56:20 52:ff:c5] SIP: find_auth_info, aid 0, username: 7115, account match
[09-23 08:56:20 52:ff:c5] SIP: sip_nict_init, no route, req_uri->host:port is 10.160.10.2:5060
[09-23 08:56:20 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:56:20 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:56:20 52:ff:c5] update registration interval(according to 200OK-900s) to 900s
[09-23 08:56:20 52:ff:c5] update expires(according to contact) to 899
[09-23 08:56:20 52:ff:c5] SIP: aid 0, cid 0, tid 0, did 0, REQUEST: REGISTER, Event: 1
[09-23 08:56:20 52:ff:c5] SIP: aid 0, cid 0, tid 0, did 0, RESPONSE: 200 OK, User is successfully registred!, Event: 1
[09-23 08:56:20 52:ff:c5] SIP: aid 0, Fail to get User-Agent header
[09-23 08:56:20 52:ff:c5] SIP: aid 0, expires: 900(900)
[09-23 08:56:20 52:ff:c5] SIP: aid 0, expires: 900(900)
[09-23 08:56:20 52:ff:c5] CFG: Blf sub need delay, num=13
[09-23 08:56:20 52:ff:c5] CALL: State=0x60, Event=0x31d, Chn=0
[09-23 08:56:20 52:ff:c5] CallCtl: SendEvent2Lcm: aid 0, Line: 0, event 0x8d4
[09-23 08:56:20 52:ff:c5] GUI: Receive Call Register Success!
[09-23 08:56:20 52:ff:c5] GUI:DEBUGINFO:UpdateRegisterStatus hWnd is not Desktop,File:phone.c------Line:1533
[09-23 08:56:20 52:ff:c5] SIP: aid 0, cid 0, tid 4652, did 0, REQUEST: NOTIFY, Event: 27
[09-23 08:56:20 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:56:20 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:56:22 52:ff:c5] SIP: aid 0, cid 0, tid 4653, did 0, REQUEST: OPTIONS, Event: 27
[09-23 08:56:22 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:56:22 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:56:24 52:ff:c5] TaskCheckMemoryInfo:509######TotalFreeMem = 35212KB, TotalUsefulMem=15856KB#######
[09-23 08:57:22 52:ff:c5] SIP: aid 0, cid 0, tid 4654, did 0, REQUEST: OPTIONS, Event: 27
[09-23 08:57:22 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:57:22 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:00 52:ff:c5] Open /dev/ttyS0
[09-23 08:58:00 52:ff:c5] Baudrate is 2400
[09-23 08:58:00 52:ff:c5] init_ehs_mode
[09-23 08:58:22 52:ff:c5] SIP: aid 0, cid 0, tid 4655, did 0, REQUEST: OPTIONS, Event: 27
[09-23 08:58:22 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:58:22 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:26 52:ff:c5] TaskCheckMemoryInfo:509######TotalFreeMem = 35188KB, TotalUsefulMem=15832KB#######
[09-23 08:58:38 52:ff:c5] SIP REFRESH####Alive Time=271######js->s_reg_period=300############
[09-23 08:58:38 52:ff:c5] SIP: sip_nict_init, no route, req_uri->host:port is 10.160.10.2:5060
[09-23 08:58:38 52:ff:c5] SIP REFRESH Action####Alive Time=271######js->s_reg_period=300############
[09-23 08:58:38 52:ff:c5] SIP: sip_nict_init, no route, req_uri->host:port is 10.160.10.2:5060
[09-23 08:58:38 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:58:38 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:38 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:38 52:ff:c5] SIP: aid 0, cid 0, tid 4656, did 16, REQUEST: SUBSCRIBE, Event: 41
[09-23 08:58:38 52:ff:c5] SIP: aid 0, cid 0, tid 4656, did 16, RESPONSE: 500 Unhandled by dialog usages, 5xx received for SUBSCRIBE!, Event: 41
[09-23 08:58:38 52:ff:c5] SIP: Event SIP_SUBSCRIPTION_SERVERFAILURE
[09-23 08:58:38 52:ff:c5] SIP: aid 0, Dsskey 16, Subscribe Response Status 500, freemem=35188 kb
[09-23 08:58:38 52:ff:c5] SIP: aid 0, cid 0, tid 4657, did 14, REQUEST: SUBSCRIBE, Event: 38
[09-23 08:58:38 52:ff:c5] SIP: aid 0, cid 0, tid 4657, did 14, RESPONSE: 200 OK, 2xx received for SUBSCRIBE, free memory=35188 kb!, Event: 38
[09-23 08:58:38 52:ff:c5] SIP: Event SIP_SUBSCRIPTION_ANSWERED
[09-23 08:58:38 52:ff:c5] SIP: aid 0, Dsskey 11, Subscribe Response Status 200, freemem=35188 kb
[09-23 08:58:38 52:ff:c5] SIP: aid 0, cid 0, tid 4658, did 14, REQUEST: NOTIFY, Event: 43
[09-23 08:58:38 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:38 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:58:39 52:ff:c5] SIP REFRESH####Alive Time=271######js->s_reg_period=300############
[09-23 08:58:39 52:ff:c5] SIP: sip_nict_init, no route, req_uri->host:port is 10.160.10.2:5060
[09-23 08:58:39 52:ff:c5] SIP REFRESH Action####Alive Time=271######js->s_reg_period=300############
[09-23 08:58:39 52:ff:c5] SIP: sip_nict_init, no route, req_uri->host:port is 10.160.10.2:5060
[09-23 08:58:39 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:58:39 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:39 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:39 52:ff:c5] SIP: aid 0, cid 0, tid 4659, did 12, REQUEST: SUBSCRIBE, Event: 38
[09-23 08:58:39 52:ff:c5] SIP: aid 0, cid 0, tid 4659, did 12, RESPONSE: 200 OK, 2xx received for SUBSCRIBE, free memory=35192 kb!, Event: 38
[09-23 08:58:39 52:ff:c5] SIP: Event SIP_SUBSCRIPTION_ANSWERED
[09-23 08:58:39 52:ff:c5] SIP: aid 0, Dsskey 10, Subscribe Response Status 200, freemem=35192 kb
[09-23 08:58:39 52:ff:c5] SIP: aid 0, cid 0, tid 4661, did 12, REQUEST: NOTIFY, Event: 43
[09-23 08:58:39 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:39 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:58:39 52:ff:c5] SIP: aid 0, cid 0, tid 4660, did 10, REQUEST: SUBSCRIBE, Event: 38
[09-23 08:58:39 52:ff:c5] SIP: aid 0, cid 0, tid 4660, did 10, RESPONSE: 200 OK, 2xx received for SUBSCRIBE, free memory=35192 kb!, Event: 38
[09-23 08:58:39 52:ff:c5] SIP: Event SIP_SUBSCRIPTION_ANSWERED
[09-23 08:58:39 52:ff:c5] SIP: aid 0, Dsskey 8, Subscribe Response Status 200, freemem=35192 kb
[09-23 08:58:39 52:ff:c5] SIP: aid 0, cid 0, tid 4662, did 10, REQUEST: NOTIFY, Event: 43
[09-23 08:58:39 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:39 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:58:40 52:ff:c5] SIP REFRESH####Alive Time=271######js->s_reg_period=300############
[09-23 08:58:40 52:ff:c5] SIP: sip_nict_init, no route, req_uri->host:port is 10.160.10.2:5060
[09-23 08:58:40 52:ff:c5] SIP REFRESH Action####Alive Time=271######js->s_reg_period=300############
[09-23 08:58:40 52:ff:c5] SIP: sip_nict_init, no route, req_uri->host:port is 10.160.10.2:5060
[09-23 08:58:40 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:58:40 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:40 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:40 52:ff:c5] SIP: aid 0, cid 0, tid 4663, did 9, REQUEST: SUBSCRIBE, Event: 38
[09-23 08:58:40 52:ff:c5] SIP: aid 0, cid 0, tid 4663, did 9, RESPONSE: 200 OK, 2xx received for SUBSCRIBE, free memory=35180 kb!, Event: 38
[09-23 08:58:40 52:ff:c5] SIP: Event SIP_SUBSCRIPTION_ANSWERED
[09-23 08:58:40 52:ff:c5] SIP: aid 0, Dsskey 7, Subscribe Response Status 200, freemem=35180 kb
[09-23 08:58:40 52:ff:c5] SIP: aid 0, cid 0, tid 4665, did 9, REQUEST: NOTIFY, Event: 43
[09-23 08:58:40 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:40 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:58:40 52:ff:c5] SIP: aid 0, cid 0, tid 4664, did 6, REQUEST: SUBSCRIBE, Event: 38
[09-23 08:58:40 52:ff:c5] SIP: aid 0, cid 0, tid 4664, did 6, RESPONSE: 200 OK, 2xx received for SUBSCRIBE, free memory=35180 kb!, Event: 38
[09-23 08:58:40 52:ff:c5] SIP: Event SIP_SUBSCRIPTION_ANSWERED
[09-23 08:58:40 52:ff:c5] SIP: aid 0, Dsskey 6, Subscribe Response Status 200, freemem=35180 kb
[09-23 08:58:40 52:ff:c5] SIP: aid 0, cid 0, tid 4666, did 6, REQUEST: NOTIFY, Event: 43
[09-23 08:58:40 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:40 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:58:41 52:ff:c5] SIP REFRESH####Alive Time=271######js->s_reg_period=300############
[09-23 08:58:41 52:ff:c5] SIP: sip_nict_init, no route, req_uri->host:port is 10.160.10.2:5060
[09-23 08:58:41 52:ff:c5] SIP REFRESH Action####Alive Time=271######js->s_reg_period=300############
[09-23 08:58:41 52:ff:c5] SIP: sip_nict_init, no route, req_uri->host:port is 10.160.10.2:5060
[09-23 08:58:41 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:58:41 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:41 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:41 52:ff:c5] SIP: aid 0, cid 0, tid 4667, did 4, REQUEST: SUBSCRIBE, Event: 38
[09-23 08:58:41 52:ff:c5] SIP: aid 0, cid 0, tid 4667, did 4, RESPONSE: 200 OK, 2xx received for SUBSCRIBE, free memory=35184 kb!, Event: 38
[09-23 08:58:41 52:ff:c5] SIP: Event SIP_SUBSCRIPTION_ANSWERED
[09-23 08:58:41 52:ff:c5] SIP: aid 0, Dsskey 4, Subscribe Response Status 200, freemem=35184 kb
[09-23 08:58:41 52:ff:c5] SIP: aid 0, cid 0, tid 4668, did 2, REQUEST: SUBSCRIBE, Event: 41
[09-23 08:58:41 52:ff:c5] SIP: aid 0, cid 0, tid 4668, did 2, RESPONSE: 500 Unhandled by dialog usages, 5xx received for SUBSCRIBE!, Event: 41
[09-23 08:58:41 52:ff:c5] SIP: Event SIP_SUBSCRIPTION_SERVERFAILURE
[09-23 08:58:41 52:ff:c5] SIP: aid 0, Dsskey 3, Subscribe Response Status 500, freemem=35184 kb
[09-23 08:58:41 52:ff:c5] SIP: aid 0, cid 0, tid 4669, did 4, REQUEST: NOTIFY, Event: 43
[09-23 08:58:41 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:58:41 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:59:22 52:ff:c5] SIP: aid 0, cid 0, tid 4670, did 0, REQUEST: OPTIONS, Event: 27
[09-23 08:59:22 52:ff:c5] cb_udp_snd_message:655===>>>SIP messages send to 10.160.10.2:5060
[09-23 08:59:22 52:ff:c5] ##SIPPro Recv event 0x1010####
[09-23 08:59:40 52:ff:c5] Open /dev/ttyS0
[09-23 08:59:40 52:ff:c5] Baudrate is 2400
[09-23 08:59:40 52:ff:c5] init_ehs_mode