Registration reported lost, but is it?

Discussion in '3CX Phone System - General' started by NMN, Oct 27, 2007.

  1. NMN

    NMN

    Joined:
    Oct 24, 2007
    Messages:
    44
    Likes Received:
    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::eek: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 contact=1777xxxxxxx@68.230.xx.xxx: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:1777xxxxxxx@callcentric.com
    23:33:39.609|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=351244361a4f4570 cseq=REGISTER contact=1777xxxxxxx@68.230.xx.xxx: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:1777xxxxxxx@callcentric.com
    23:34:11.280|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=de0ddf5dfe739710 cseq=REGISTER contact=1777xxxxxxx@68.230.xx.xxx: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:1777xxxxxxx@callcentric.com
    23:34:32.952|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=5263ee56a91be32e cseq=REGISTER contact=1777xxxxxxx@68.230.xx.xxx: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:1777xxxxxxx@callcentric.com
    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 contact=1777xxxxxxx@68.230.xx.xxx: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 1777xxxxxxx@68.230.xx.xxx:15060 tid=-324c6178053327b7465473d4e2bd8ec0 cseq=NOTIFY contact=86f1b2b36fdd44bb8827a54386066215@204.11.192.23:5060 / 1 from(wire)
    23:35:11.467|ClientRegistration.cxx(234)|Trace5|Resip|>>:requesting refresh of ClientRegistration sip:1777xxxxxxx@callcentric.com
    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 1777xxxxxxx@68.230.xx.xxx:15060 tid=-a1efd1f1e983a115985900be2d973163 cseq=NOTIFY contact=86f1b2b36fdd44bb8827a54386066215@204.11.192.23: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:1777xxxxxxx@callcentric.com
    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 contact=1777xxxxxxx@68.230.xx.xxx: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 1777xxxxxxx@68.230.xx.xxx:15060 tid=-e486decfc1aa58c6b2af6ee8abcf14c9 cseq=NOTIFY contact=86f1b2b36fdd44bb8827a54386066215@204.11.192.23: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:1777xxxxxxx@callcentric.com
    23:35:40.998|DialogUsageManager.cxx(1190)|Trace5|Resip|>>:Got: SipResp: 200 tid=194e970eee11c10f cseq=REGISTER contact=1777xxxxxxx@68.230.xx.xxx: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::eek:nRequestRetry:Reg. request-retry: h=708; code=408
    23:35:43.982|.\Registrar.cpp(469)|Trace5|Registrar|ClientRegs::eek: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::eek: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.
     
  2. NMN

    NMN

    Joined:
    Oct 24, 2007
    Messages:
    44
    Likes Received:
    0
    Just some additional info ...

    there is never, in the logs anyway, an actual registration failure reported.
    The only indications of registration issues are the stated status on the Line Status page and in the Call Assitant.

    NMN
     
  3. miraportuga

    miraportuga Member

    Joined:
    Aug 7, 2007
    Messages:
    297
    Likes Received:
    0
    Try to change the registration timeout time on that line... and see if it makes any diference....

    Cheers
     
  4. NMN

    NMN

    Joined:
    Oct 24, 2007
    Messages:
    44
    Likes Received:
    0
    I assume you mean to shorten it ... ?

    NMN
     
  5. miraportuga

    miraportuga Member

    Joined:
    Aug 7, 2007
    Messages:
    297
    Likes Received:
    0
    well, i would say try both ways... to see if it changes anything on that problem.... :|
     
  6. NMN

    NMN

    Joined:
    Oct 24, 2007
    Messages:
    44
    Likes Received:
    0
    OK ... For now I have shortened it to 1800s.
    I will report back within the next 24 hrs.

    NMN
     
  7. Ralph

    Ralph Member

    Joined:
    Jun 28, 2007
    Messages:
    417
    Likes Received:
    0
    Having similar issue

    I have a similar issue with 3CX reporting dropped lines to the VoIP and yet the lines remain operational. When this happens the only way I have been able to turn them green again is by manually registering.
     
  8. NMN

    NMN

    Joined:
    Oct 24, 2007
    Messages:
    44
    Likes Received:
    0
    Hm ... at 1800 sec. I have now no false registration loss report, but 3 actual registration losses in 24 hrs. ... not exactly desirable.

    Both times the error reported was "reason= not found", for which I would sill like a positive explanation, if possible: What is 'not found' when this error is reported? The domain (registrar), the username ... ? Under exactly which circumstance will 3CX report 'not found' in a failed registration?

    NMN
     
  9. NMN

    NMN

    Joined:
    Oct 24, 2007
    Messages:
    44
    Likes Received:
    0
    After another 24 hrs., even with the now lengthened timeout of 2400 s the false registration lost indication has reappeared.

    There is s.t. else going on internally, that creates this disconnect between actual and perceived status in 3CX.

    NMN
     
  10. Ralph

    Ralph Member

    Joined:
    Jun 28, 2007
    Messages:
    417
    Likes Received:
    0
    Good morning

    Good morning,

    For me the issue doesn't happen frequently, maybe once per month. When it does happen, it occurs with both of the VoIP providers that we use. BroadVoice and Vitelity.
     
  11. Ralph

    Ralph Member

    Joined:
    Jun 28, 2007
    Messages:
    417
    Likes Received:
    0
    Do you have QOS enabled on your network?

    Good morning again :D

    Since it appears that communication might be lost or degraded between your 3CX server and the VoIP provider resulting in a false report.

    Do you have Quality of Service(QOS) enabled on your network? My thinking is that if you have some other traffic that has a higher priority or takes up all your bandwidth (ie an offsite backup) it might interfer with your connection to your VoIP provider resulting in a false report.

    Enabling QOS and asigning your VoIP traffic a high priority might solve this if your don't already have it enabled.
     
  12. NMN

    NMN

    Joined:
    Oct 24, 2007
    Messages:
    44
    Likes Received:
    0
    Thanks Ralph.

    I will cautiously say, that this seems to have done the trick.

    After having set the router's port-based QOS for the 3CX server to 'high' I have not experienced any registration loss or false report thereof. I ran a test with a high-throughput application running at 2Mbps/80connections for a few hours and still experienced no new incidents.

    On a side note: (Linksys') QOS does nothing for line quality with high volume applications running, unless you actually throttle their ports separately.

    Again, thanks for your help!

    NMN
     
  13. Ralph

    Ralph Member

    Joined:
    Jun 28, 2007
    Messages:
    417
    Likes Received:
    0
    You are welcome

    You are welcome :D

    Take care,
     

Share This Page