[Spce-user] Troubleshooting an asterisk server that keeps losing registration.

Kalen Krueger kalen at npinfo.com
Sat Nov 1 12:09:32 EDT 2014


I see that it's getting blocked via 403 for too many "Consecutive Authentication Failure", but I'm not sure why.



In going through the logs seems that the asterisk box updates its registration every 60 seconds or so, and then for some reason it decides to do so five times within two seconds, with an OPTIONS stuck in there as well.   And out of the 5 REGISTER attempts I’m seeing it got four “S=401 – Unauthorized”, and one “S=200 – OK”… then the block.



Thoughts?



Oct 31 12:55:15 softswitch lb[3936]: NOTICE: <script>: New request - M=REGISTER R=sip:swphone.cloud.com F=sip:5232580006 at swphone.cloud.com T=sip:5232580006 at swphone.cloud.com IP=udp:126.121.32.231:1250 ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:15 softswitch lb[3936]: NOTICE: <script>: Relaying request, du='sip:127.0.0.1:5062', fs='udp:127.0.0.1:5060' - R=sip:swphone.cloud.com ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:15 softswitch lb[3942]: NOTICE: <script>: Reply from Inbound - S=100 - Trying M=REGISTER IP=udp:127.0.0.1:5062 ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:15 softswitch lb[3942]: NOTICE: <script>: Sending reply, fs='udp:126.121.32.156:5060' - ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:15 softswitch lb[3945]: NOTICE: <script>: Reply from Inbound - S=401 - Unauthorized M=REGISTER IP=udp:127.0.0.1:5062 ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:15 softswitch lb[3945]: NOTICE: <script>: Sending reply, fs='udp:126.121.32.156:5060' - ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:15 softswitch lb[3944]: NOTICE: <script>: New request - M=OPTIONS R=sip:5232580006 at 126.121.32.231:5060 F=sip:pinger at sipwise.local T=sip:5232580006 at 126.121.32.231:5060 IP=udp:127.0.0.1:5062 ID=46812103-c873ac75-232b4b5 at 127.0.0.1

Oct 31 12:55:15 softswitch lb[3944]: NOTICE: <script>: Relaying request, du='sip:126.121.32.231:1250', fs='udp:126.121.32.156:5060' - R=sip:5232580006 at 126.121.32.231:5060 ID=46812103-c873ac75-232b4b5 at 127.0.0.1

Oct 31 12:55:16 softswitch lb[3934]: NOTICE: <script>: New request - M=OPTIONS R=sip:162.211.23.163:5060 F=sip:ping at 69.164.175.54 T=sip:ping at 162.211.23.163 IP=udp:162.211.23.163:5060 ID=1512CE23-5453E9120009B4BF-D4E20700

Oct 31 12:55:16 softswitch lb[3934]: NOTICE: <script>: Relaying request, du='sip:127.0.0.1:5062', fs='udp:127.0.0.1:5060' - R=sip:162.211.23.163:5060 ID=1512CE23-5453E9120009B4BF-D4E20700

Oct 31 12:55:16 softswitch lb[3938]: NOTICE: <script>: Reply from Inbound - S=100 - Trying M=OPTIONS IP=udp:127.0.0.1:5062 ID=1512CE23-5453E9120009B4BF-D4E20700

Oct 31 12:55:16 softswitch lb[3938]: NOTICE: <script>: Sending reply, fs='udp:126.121.32.156:5060' - ID=1512CE23-5453E9120009B4BF-D4E20700

Oct 31 12:55:16 softswitch lb[3931]: NOTICE: <script>: New request - M=REGISTER R=sip:swphone.cloud.com F=sip:5232580006 at swphone.cloud.com T=sip:5232580006 at swphone.cloud.com IP=udp:126.121.32.231:1250 ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:16 softswitch lb[3931]: NOTICE: <script>: Relaying request, du='sip:127.0.0.1:5062', fs='udp:127.0.0.1:5060' - R=sip:swphone.cloud.com ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:16 softswitch lb[3940]: NOTICE: <script>: Reply from Inbound - S=100 - Trying M=REGISTER IP=udp:127.0.0.1:5062 ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:16 softswitch lb[3940]: NOTICE: <script>: Sending reply, fs='udp:126.121.32.156:5060' - ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:16 softswitch lb[3943]: NOTICE: <script>: Reply from Inbound - S=401 - Unauthorized M=REGISTER IP=udp:127.0.0.1:5062 ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:16 softswitch lb[3943]: NOTICE: <script>: Sending reply, fs='udp:126.121.32.156:5060' - ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:16 softswitch lb[3930]: NOTICE: <script>: New request - M=REGISTER R=sip:swphone.cloud.com:5060 F=sip:2538523566 at swphone.cloud.com:5060;transport=UDP T=sip:2538523566 at swphone.cloud.com:5060;transport=UDP IP=udp:69.164.160.210:5060 ID=3c1ccd0-7f000001-13c4-38ead-8b955d57-38ead

Oct 31 12:55:16 softswitch lb[3930]: NOTICE: <script>: Relaying request, du='sip:127.0.0.1:5062', fs='udp:127.0.0.1:5060' - R=sip:swphone.cloud.com:5060 ID=3c1ccd0-7f000001-13c4-38ead-8b955d57-38ead

Oct 31 12:55:16 softswitch lb[3941]: NOTICE: <script>: Reply from Inbound - S=100 - Trying M=REGISTER IP=udp:127.0.0.1:5062 ID=3c1ccd0-7f000001-13c4-38ead-8b955d57-38ead

Oct 31 12:55:16 softswitch lb[3941]: NOTICE: <script>: Sending reply, fs='udp:126.121.32.156:5060' - ID=3c1ccd0-7f000001-13c4-38ead-8b955d57-38ead

Oct 31 12:55:16 softswitch lb[3939]: NOTICE: <script>: Reply from Inbound - S=401 - Unauthorized M=REGISTER IP=udp:127.0.0.1:5062 ID=3c1ccd0-7f000001-13c4-38ead-8b955d57-38ead

Oct 31 12:55:16 softswitch lb[3939]: NOTICE: <script>: Sending reply, fs='udp:126.121.32.156:5060' - ID=3c1ccd0-7f000001-13c4-38ead-8b955d57-38ead

Oct 31 12:55:16 softswitch lb[3932]: NOTICE: <script>: New request - M=REGISTER R=sip:swphone.cloud.com:5060 F=sip:2538523566 at swphone.cloud.com:5060;transport=UDP T=sip:2538523566 at swphone.cloud.com:5060;transport=UDP IP=udp:69.164.160.210:5060 ID=3c1ccd0-7f000001-13c4-38ead-8b955d57-38ead

Oct 31 12:55:16 softswitch lb[3932]: NOTICE: <script>: Relaying request, du='sip:127.0.0.1:5062', fs='udp:127.0.0.1:5060' - R=sip:swphone.cloud.com:5060 ID=3c1ccd0-7f000001-13c4-38ead-8b955d57-38ead

Oct 31 12:55:16 softswitch lb[3942]: NOTICE: <script>: Reply from Inbound - S=100 - Trying M=REGISTER IP=udp:127.0.0.1:5062 ID=3c1ccd0-7f000001-13c4-38ead-8b955d57-38ead

Oct 31 12:55:16 softswitch lb[3942]: NOTICE: <script>: Sending reply, fs='udp:126.121.32.156:5060' - ID=3c1ccd0-7f000001-13c4-38ead-8b955d57-38ead

Oct 31 12:55:16 softswitch lb[3945]: NOTICE: <script>: Reply from Inbound - S=200 - OK M=REGISTER IP=udp:127.0.0.1:5062 ID=3c1ccd0-7f000001-13c4-38ead-8b955d57-38ead

Oct 31 12:55:16 softswitch lb[3945]: NOTICE: <script>: Sending reply, fs='udp:126.121.32.156:5060' - ID=3c1ccd0-7f000001-13c4-38ead-8b955d57-38ead

Oct 31 12:55:17 softswitch lb[3937]: NOTICE: <script>: New request - M=REGISTER R=sip:swphone.cloud.com F=sip:5232580006 at swphone.cloud.com T=sip:5232580006 at swphone.cloud.com IP=udp:126.121.32.231:1250 ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:17 softswitch lb[3937]: NOTICE: <script>: Relaying request, du='sip:127.0.0.1:5062', fs='udp:127.0.0.1:5060' - R=sip:swphone.cloud.com ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:17 softswitch lb[3944]: NOTICE: <script>: Reply from Inbound - S=100 - Trying M=REGISTER IP=udp:127.0.0.1:5062 ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:17 softswitch lb[3944]: NOTICE: <script>: Sending reply, fs='udp:126.121.32.156:5060' - ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:17 softswitch lb[3938]: NOTICE: <script>: Reply from Inbound - S=401 - Unauthorized M=REGISTER IP=udp:127.0.0.1:5062 ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:17 softswitch lb[3938]: WARNING: <script>: Consecutive Authentication Failure for '5232580006 at swphone.cloud.com' UA='FPBX-2.11.0(11.7.0)' IP='126.121.32.231' -  R=<null> ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:17 softswitch lb[3938]: NOTICE: <script>: Sending reply, fs='udp:126.121.32.156:5060' - ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com

Oct 31 12:55:17 softswitch lb[3933]: WARNING: <script>: Subscriber '5232580006 at swphone.cloud.com' UA='FPBX-2.11.0(11.7.0)' from IP='126.121.32.231' is temporarily banned, send 403 - R=sip:swphone.cloud.com ID=511538593775b82678c14d4a6913ce07 at swphone.cloud.com



-----Original Message-----
From: Kalen Krueger
Sent: Saturday, November 1, 2014 8:12 AM
To: 'Daniel Grotti'; Matthew Ogden
Cc: spce-user at lists.sipwise.com
Subject: RE: [Spce-user] Troubleshooting an asterisk server that keeps losing registration.



Matthew, how did you come to the conclusion that it was a stale nonce?    I would like to compare what I'm seeing in our asterisk boxes.



>>>> On 01/27/2014 04:35 PM, Matthew Ogden wrote:

>>>>> Did you guys end up making a decision on this? I still have

>>>>> Asterisk subscribers causing auth fail with stale nonce situations.



-----Original Message-----

From: Daniel Grotti [mailto:dgrotti at sipwise.com]

Sent: Saturday, November 1, 2014 2:56 AM

To: Matthew Ogden

Cc: spce-user at lists.sipwise.com<mailto:spce-user at lists.sipwise.com>; Kalen Krueger

Subject: RE: [Spce-user] Troubleshooting an asterisk server that keeps losing registration.



Thanks Metthew!

Didn't remember that :)



Daniel



On 1 Nov 2014 10:51, Matthew Ogden <matthew at tenacit.net<mailto:matthew at tenacit.net>> wrote:

>

> Hi Danel & Kalen

>

> Is this not the same issue I had? Mine was because it's using a stale

> nonce - which NGCP rejects. Basically if you send to many 401s or 407s

> the LB will ban it with a 403.

> So we were seeing a lot of asterisk boxes give up (and ours was an

> appliance that cannot retry automatically after 403)

>

> You can stop spce from blocking stale nonce registrations.  See this thread:

> http://lists.sipwise.com/pipermail/spce-user/2014-January/005712.html

>

> Daniel's suggestion was to add the P-NGCP-Stale header in the proxy,

> and then make the LB only do a 401 if it wasn't present.

>

> It saved me from a LOT of headaches.

>

> Thanks again!

>

>

> -----Original Message-----

> From: Spce-user [mailto:spce-user-bounces at lists.sipwise.com] On Behalf

> Of Daniel Grotti

> Sent: 01 November 2014 10:57 AM

> To: Kalen Krueger

> Cc: spce-user at lists.sipwise.com<mailto:spce-user at lists.sipwise.com>

> Subject: Re: [Spce-user] Troubleshooting an asterisk server that keeps

> losing registration.

>

> Mmm...yes this is well know issue of asterisk.

> But spce should send 403 only when a user is blocked.

> Don't get the scenario when PBX get 403 during a normal registration.

>

> In the worst case you can change the 403 reply on spce. But only of

> you really need. This is an asterisk issue.

>

> Daniel

>

> On 1 Nov 2014 09:12, Kalen Krueger <kalen at npinfo.com<mailto:kalen at npinfo.com>> wrote:

> >

> > Upon further review it appears that we’re getting this error out of

> > the blue….

> >

> >

> >

> >

> >

> > Then based on the “Forbidden” (I’m assuming 403 error), it stops

> > trying until we force it to.

> >

> >

> >

> > I’ve added the new option available in the PBX configuration to see

> > if this helps, but I’m just wondering why this would happen out of the blue?

> >

> >

> >

> > register_retry_403=yes

> >

> > ; Treat 403 responses to registrations as if they were

> >

> >                               ; 401 responses and continue retrying

> >according to normal

> >

> >                               ; retry rules.

> >

> >

> >

> > Kalen Krueger

> > Technical and Project Manager

> > NP Information Systems

> > www.npinfo.com<http://www.npinfo.com>

> >

> > kalen at npinfo.com<mailto:kalen at npinfo.com>

> > desk:  (253) 479-1321

> > office: (253) 852-1543

> > mobile: (206) 963-1309

> >

> >

> >

> >

> >

> >

> >

> > From: Spce-user [mailto:spce-user-bounces at lists.sipwise.com] On

> > Behalf Of Kalen Krueger

> > Sent: Friday, October 31, 2014 4:00 PM

> > To: spce-user at lists.sipwise.com<mailto:spce-user at lists.sipwise.com>

> > Subject: [Spce-user] Troubleshooting an asterisk server that keeps

> > losing registration.

> >

> >

> >

> > We’ve got one particular PBX we’re having a problem with.     At

> > seemingly random intervals sip:wise thinks it’s lost registration,

> > while the PBX still thinks it’s registered.  Therefore sip:wise

> > forwards the calls to the caller wave have listed in “Call Forward Unavailable”.

> >

> >

> >

> > We’ve been working on this for several weeks… trying different

> > things… and I need to reach out for some guidance.   What

> > information can provide to the community that would helpful?

> >

> >

> >

> > We’re running mr3.4.2 and the subscriber is FreePBX 2.11.0.37.

> >

> >

> >

> > Here’s a screenshot (some info scrubbed) of our trunk setup in

> > FreePBX, and the registration in sip:wise… in case we have something

> > obviously wrong.    I’m happy to collect tsharks, etc. to assist….

> > Just feel at this point like I’m running in circles.

> >

> >

> >

> > Thanks ahead of time for any guidance.

> >

> >

> >

> >

> >

> > Kalen Krueger

> > Technical and Project Manager

> > NP Information Systems

> > www.npinfo.com<http://www.npinfo.com>

> >

> > kalen at npinfo.com<mailto:kalen at npinfo.com>

> > desk:  (253) 479-1321

> > office: (253) 852-1543

> > mobile: (206) 963-1309

> >

> >

> >

> >

> >

> >

> >

> >

> >

> > ________________________________

> >

> >

> > This email and any files transmitted with it are confidential and

> > intended solely for the use of the individual or entity to whom they are addressed.

> > If you have received this email in error please notify the system manager.

> > Please note that any views or opinions presented in this email are

> > solely those of the author and do not necessarily represent those of the company.

> _______________________________________________

> Spce-user mailing list

> Spce-user at lists.sipwise.com<mailto:Spce-user at lists.sipwise.com>

> https://lists.sipwise.com/listinfo/spce-user
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sipwise.com/mailman/private/spce-user_lists.sipwise.com/attachments/20141101/e7ad0a91/attachment.html>


More information about the Spce-user mailing list