- Joined
- Oct 24, 2007
- Messages
- 44
- Reaction score
- 0
I'm experiencing an issue in which 3CX reports a dropped registration while both the registrar (VOIP provider) report the system to be registered as well as all normal functions of the system remain working.
However, 3CX never recuperates from this false status indication; meaning, even after the scheduled hourly re-registration the status remains 'unregistered' even though for all intends and purposes the system is registered.
Here is the log entry from the 3CX Server Status page:
23:35:43.982 ClientRegs:nRequestRetry [CM113008] Registration attempt for Ln:10000@Callcentric is scheduled in 120 sec.
From this message forward 3CX will report as follows on the Line Status page (and in the Call Assistant):
10000 Line No: 1777xxxxxxx
Status: Not registered
Baffling is also the fact that, while gateway setting require registration for inbound and outbound calls, the indicated registration status does not prevent any calls from being made or received.
Here is the log (System Trace) just prior to the indicated loss of registration:
23:33:32.468|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=315d0e39fa5a863e cseq=REGISTER [email protected]:15060 / 1643 from(wire)
23:33:32.468|ClientRegistration.cxx(327)|Trace5|Resip|>>:Clearing service route ([])
23:33:38.484|TuSelector.cxx(70)|Trace5|Resip|>>:Stats message
23:33:39.530|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:[email protected]
23:33:39.609|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=351244361a4f4570 cseq=REGISTER [email protected]:15060 / 1860 from(wire)
23:33:39.609|ClientRegistration.cxx(327)|Trace5|Resip|>>:Clearing service route ([])
23:34:11.124|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:[email protected]
23:34:11.280|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=de0ddf5dfe739710 cseq=REGISTER [email protected]:15060 / 555 from(wire)
23:34:11.280|ClientRegistration.cxx(327)|Trace5|Resip|>>:Clearing service route ([])
23:34:32.827|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:[email protected]
23:34:32.952|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=5263ee56a91be32e cseq=REGISTER [email protected]:15060 / 1644 from(wire)
23:34:32.952|ClientRegistration.cxx(327)|Trace5|Resip|>>:Clearing service route ([])
23:34:38.530|TuSelector.cxx(70)|Trace5|Resip|>>:Stats message
23:34:39.873|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:[email protected]
23:34:39.998|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 407 tid=30552e43e0062d6c cseq=REGISTER / 1861 from(wire)
23:34:40.577|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=0b218a67f9454a06 cseq=REGISTER [email protected]:15060 / 1862 from(wire)
23:34:40.577|ClientRegistration.cxx(327)|Trace5|Resip|>>:Clearing service route ([])
23:34:40.592|.\Endpoint.cpp(91)|Trace5|Endpoint|Endpoint::findSource:No Remote-Party-ID header found
23:34:40.639|.\Endpoint.cpp(111)|Trace5|Endpoint|Endpoint::findSource:Lines Is here
23:34:40.639|.\Endpoint.cpp(126)|Trace5|Endpoint|Endpoint::findSource:Only one lines is here
23:34:40.639|.\Endpoint.cpp(132)|Trace5|Endpoint|Endpoint::findSource:Settings for caller is found: CfgExtLine:10000
23:34:40.639|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipReq: NOTIFY [email protected]:15060 tid=-324c6178053327b7465473d4e2bd8ec0 cseq=NOTIFY [email protected]:5060 / 1 from(wire)
23:35:11.467|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:[email protected]
23:35:11.639|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 407 tid=7c1d12120c395d76 cseq=REGISTER / 556 from(wire)
23:35:11.873|.\Endpoint.cpp(91)|Trace5|Endpoint|Endpoint::findSource:No Remote-Party-ID header found
23:35:11.920|.\Endpoint.cpp(111)|Trace5|Endpoint|Endpoint::findSource:Lines Is here
23:35:11.920|.\Endpoint.cpp(126)|Trace5|Endpoint|Endpoint::findSource:Only one lines is here
23:35:11.920|.\Endpoint.cpp(132)|Trace5|Endpoint|Endpoint::findSource:Settings for caller is found: CfgExtLine:10000
23:35:11.920|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipReq: NOTIFY [email protected]:15060 tid=-a1efd1f1e983a115985900be2d973163 cseq=NOTIFY [email protected]:5060 / 1 from(wire)
23:35:26.888|.\CAHandler.cpp(252)|Trace5||CAHandler::setStatus:[CM102005] CA request setStatus(dn=200, status=0)
23:35:26.888|.\CAHandler.cpp(252)|Trace5||CAHandler::setStatus:[CM102005] CA request setStatus(dn=201, status=0)
23:35:26.888|.\CAHandler.cpp(252)|Trace5||CAHandler::setStatus:[CM102005] CA request setStatus(dn=300, status=2)
23:35:26.888|.\CAHandler.cpp(252)|Trace5||CAHandler::setStatus:[CM102005] CA request setStatus(dn=501, status=0)
23:35:26.888|.\CAHandler.cpp(252)|Trace5||CAHandler::setStatus:[CM102005] CA request setStatus(dn=502, status=0)
23:35:26.888|.\CAHandler.cpp(252)|Trace5||CAHandler::setStatus:[CM102005] CA request setStatus(dn=530, status=0)
23:35:33.201|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:[email protected]
23:35:33.326|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 407 tid=f543de23fd6e202b cseq=REGISTER / 1645 from(wire)
23:35:33.529|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=f52815433027ac34 cseq=REGISTER [email protected]:15060 / 1646 from(wire)
23:35:33.529|ClientRegistration.cxx(327)|Trace5|Resip|>>:Clearing service route ([])
23:35:33.545|.\Endpoint.cpp(91)|Trace5|Endpoint|Endpoint::findSource:No Remote-Party-ID header found
23:35:33.592|.\Endpoint.cpp(111)|Trace5|Endpoint|Endpoint::findSource:Lines Is here
23:35:33.592|.\Endpoint.cpp(126)|Trace5|Endpoint|Endpoint::findSource:Only one lines is here
23:35:33.592|.\Endpoint.cpp(132)|Trace5|Endpoint|Endpoint::findSource:Settings for caller is found: CfgExtLine:10000
23:35:33.592|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipReq: NOTIFY [email protected]:15060 tid=-e486decfc1aa58c6b2af6ee8abcf14c9 cseq=NOTIFY [email protected]:5060 / 1 from(wire)
23:35:38.451|TuSelector.cxx(70)|Trace5|Resip|>>:Stats message
23:35:40.857|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:[email protected]
23:35:40.998|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=194e970eee11c10f cseq=REGISTER [email protected]:15060 / 1863 from(wire)
23:35:40.998|ClientRegistration.cxx(327)|Trace5|Resip|>>:Clearing service route ([])
23:35:43.982|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 408 tid=4b28b8064f4b3104 cseq=REGISTER / 557 from(wire)
23:35:43.982|.\Registrar.cpp(460)|Trace5|Registrar|ClientRegs:nRequestRetry:Reg. request-retry: h=708; code=408
23:35:43.982|.\Registrar.cpp(469)|Trace5|Registrar|ClientRegs:nRequestRetry:ADS: hReg=708; attempt=0
23:35:43.982|.\CallEvents.cpp(78)|Trace5||FireStatusEvent:Fire event: Undefined; DN 10000
23:35:43.982|.\Registrar.cpp(477)|Log2|Registrar|ClientRegs:nRequestRetry:[CM113008] Registration attempt for Ln:10000@Callcentric is scheduled in 120 sec.
Manually re-registering fixes this issue.
NMN
P.S.: For those having read me previous posts relating to registration loss, those issues were finally traced down to a compound equipment failure (one Linksys WRV200 router, whose firmware has a [now] known bug, dropping ALL SIP traffic after about 6-8 hours and one faulty Netgear FS105 switch with a thermal issue). Ever since 3CX has only failed registration once in a 48 hr. period and has shown the behavior described above 3 times.
However, 3CX never recuperates from this false status indication; meaning, even after the scheduled hourly re-registration the status remains 'unregistered' even though for all intends and purposes the system is registered.
Here is the log entry from the 3CX Server Status page:
23:35:43.982 ClientRegs:nRequestRetry [CM113008] Registration attempt for Ln:10000@Callcentric is scheduled in 120 sec.
From this message forward 3CX will report as follows on the Line Status page (and in the Call Assistant):
10000 Line No: 1777xxxxxxx
Status: Not registered
Baffling is also the fact that, while gateway setting require registration for inbound and outbound calls, the indicated registration status does not prevent any calls from being made or received.
Here is the log (System Trace) just prior to the indicated loss of registration:
23:33:32.468|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=315d0e39fa5a863e cseq=REGISTER [email protected]:15060 / 1643 from(wire)
23:33:32.468|ClientRegistration.cxx(327)|Trace5|Resip|>>:Clearing service route ([])
23:33:38.484|TuSelector.cxx(70)|Trace5|Resip|>>:Stats message
23:33:39.530|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:[email protected]
23:33:39.609|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=351244361a4f4570 cseq=REGISTER [email protected]:15060 / 1860 from(wire)
23:33:39.609|ClientRegistration.cxx(327)|Trace5|Resip|>>:Clearing service route ([])
23:34:11.124|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:[email protected]
23:34:11.280|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=de0ddf5dfe739710 cseq=REGISTER [email protected]:15060 / 555 from(wire)
23:34:11.280|ClientRegistration.cxx(327)|Trace5|Resip|>>:Clearing service route ([])
23:34:32.827|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:[email protected]
23:34:32.952|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=5263ee56a91be32e cseq=REGISTER [email protected]:15060 / 1644 from(wire)
23:34:32.952|ClientRegistration.cxx(327)|Trace5|Resip|>>:Clearing service route ([])
23:34:38.530|TuSelector.cxx(70)|Trace5|Resip|>>:Stats message
23:34:39.873|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:[email protected]
23:34:39.998|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 407 tid=30552e43e0062d6c cseq=REGISTER / 1861 from(wire)
23:34:40.577|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=0b218a67f9454a06 cseq=REGISTER [email protected]:15060 / 1862 from(wire)
23:34:40.577|ClientRegistration.cxx(327)|Trace5|Resip|>>:Clearing service route ([])
23:34:40.592|.\Endpoint.cpp(91)|Trace5|Endpoint|Endpoint::findSource:No Remote-Party-ID header found
23:34:40.639|.\Endpoint.cpp(111)|Trace5|Endpoint|Endpoint::findSource:Lines Is here
23:34:40.639|.\Endpoint.cpp(126)|Trace5|Endpoint|Endpoint::findSource:Only one lines is here
23:34:40.639|.\Endpoint.cpp(132)|Trace5|Endpoint|Endpoint::findSource:Settings for caller is found: CfgExtLine:10000
23:34:40.639|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipReq: NOTIFY [email protected]:15060 tid=-324c6178053327b7465473d4e2bd8ec0 cseq=NOTIFY [email protected]:5060 / 1 from(wire)
23:35:11.467|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:[email protected]
23:35:11.639|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 407 tid=7c1d12120c395d76 cseq=REGISTER / 556 from(wire)
23:35:11.873|.\Endpoint.cpp(91)|Trace5|Endpoint|Endpoint::findSource:No Remote-Party-ID header found
23:35:11.920|.\Endpoint.cpp(111)|Trace5|Endpoint|Endpoint::findSource:Lines Is here
23:35:11.920|.\Endpoint.cpp(126)|Trace5|Endpoint|Endpoint::findSource:Only one lines is here
23:35:11.920|.\Endpoint.cpp(132)|Trace5|Endpoint|Endpoint::findSource:Settings for caller is found: CfgExtLine:10000
23:35:11.920|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipReq: NOTIFY [email protected]:15060 tid=-a1efd1f1e983a115985900be2d973163 cseq=NOTIFY [email protected]:5060 / 1 from(wire)
23:35:26.888|.\CAHandler.cpp(252)|Trace5||CAHandler::setStatus:[CM102005] CA request setStatus(dn=200, status=0)
23:35:26.888|.\CAHandler.cpp(252)|Trace5||CAHandler::setStatus:[CM102005] CA request setStatus(dn=201, status=0)
23:35:26.888|.\CAHandler.cpp(252)|Trace5||CAHandler::setStatus:[CM102005] CA request setStatus(dn=300, status=2)
23:35:26.888|.\CAHandler.cpp(252)|Trace5||CAHandler::setStatus:[CM102005] CA request setStatus(dn=501, status=0)
23:35:26.888|.\CAHandler.cpp(252)|Trace5||CAHandler::setStatus:[CM102005] CA request setStatus(dn=502, status=0)
23:35:26.888|.\CAHandler.cpp(252)|Trace5||CAHandler::setStatus:[CM102005] CA request setStatus(dn=530, status=0)
23:35:33.201|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:[email protected]
23:35:33.326|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 407 tid=f543de23fd6e202b cseq=REGISTER / 1645 from(wire)
23:35:33.529|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=f52815433027ac34 cseq=REGISTER [email protected]:15060 / 1646 from(wire)
23:35:33.529|ClientRegistration.cxx(327)|Trace5|Resip|>>:Clearing service route ([])
23:35:33.545|.\Endpoint.cpp(91)|Trace5|Endpoint|Endpoint::findSource:No Remote-Party-ID header found
23:35:33.592|.\Endpoint.cpp(111)|Trace5|Endpoint|Endpoint::findSource:Lines Is here
23:35:33.592|.\Endpoint.cpp(126)|Trace5|Endpoint|Endpoint::findSource:Only one lines is here
23:35:33.592|.\Endpoint.cpp(132)|Trace5|Endpoint|Endpoint::findSource:Settings for caller is found: CfgExtLine:10000
23:35:33.592|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipReq: NOTIFY [email protected]:15060 tid=-e486decfc1aa58c6b2af6ee8abcf14c9 cseq=NOTIFY [email protected]:5060 / 1 from(wire)
23:35:38.451|TuSelector.cxx(70)|Trace5|Resip|>>:Stats message
23:35:40.857|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:[email protected]
23:35:40.998|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=194e970eee11c10f cseq=REGISTER [email protected]:15060 / 1863 from(wire)
23:35:40.998|ClientRegistration.cxx(327)|Trace5|Resip|>>:Clearing service route ([])
23:35:43.982|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 408 tid=4b28b8064f4b3104 cseq=REGISTER / 557 from(wire)
23:35:43.982|.\Registrar.cpp(460)|Trace5|Registrar|ClientRegs:nRequestRetry:Reg. request-retry: h=708; code=408
23:35:43.982|.\Registrar.cpp(469)|Trace5|Registrar|ClientRegs:nRequestRetry:ADS: hReg=708; attempt=0
23:35:43.982|.\CallEvents.cpp(78)|Trace5||FireStatusEvent:Fire event: Undefined; DN 10000
23:35:43.982|.\Registrar.cpp(477)|Log2|Registrar|ClientRegs:nRequestRetry:[CM113008] Registration attempt for Ln:10000@Callcentric is scheduled in 120 sec.
Manually re-registering fixes this issue.
NMN
P.S.: For those having read me previous posts relating to registration loss, those issues were finally traced down to a compound equipment failure (one Linksys WRV200 router, whose firmware has a [now] known bug, dropping ALL SIP traffic after about 6-8 hours and one faulty Netgear FS105 switch with a thermal issue). Ever since 3CX has only failed registration once in a 48 hr. period and has shown the behavior described above 3 times.