[Spce-user] mr9.5.4 - REDIS - Failed to get reply for query: Connection reset by peer

Adam Clark aclark at structuredcommunications.co.uk
Mon Oct 23 04:40:24 EDT 2023 

Hey Marco,

Thank you for coming back to me so quickly.

We did have a look in the REDIS config and it did say that it would error in the event of maximum connections being reached noting it in the error log but maybe that’s only if REDIS is set to debug?

We have 4 systems with this exact same problem, so I don’t know If its an underlying issue somewhere. Is there anything we can give you for debugging in your lab?

We have 2 systems that we have not yet fully restarted so when one of them plays up again we will run the netstat command.

Is it also worth setting REDIS to debug?

Kind Regards,

Adam





From: Marco Capetta via Spce-user <spce-user at lists.sipwise.com>
Sent: Monday, October 23, 2023 8:42 AM
To: spce-user at lists.sipwise.com
Subject: Re: [Spce-user] mr9.5.4 - REDIS - Failed to get reply for query: Connection reset by peer

Hi Adam,

This is something we never noticed in our tests, but it definitely looks a problem related to proxy-redis communication.

The first thing I would investigate is the number of opened connection to redis. If redis reaches the max number of accepted connections, then it starts dropping some of them or not accepting new connections.

You can use 'netstat' command to get how many connections redis has active in a particular moment. Maybe you can find there some of them stuck and you can try to identify who opened but didn't close it properly.

Thank you

Best Regards
Marco


On 20/10/23 18:26, Adam Clark wrote:
Afternoon all!

Been a while since I last posted (back in the v2.6 days)

Question…

We have a few boxes running mr9.5.4 that will at times stop processing registrations. We have alerts internally on systems that ping us on flapping SIP registrations.

On said boxes in the kamailio-lb.log we see:

lb[634146]: NOTICE: REPLY_FROM_INBOUND <script>: Reply from Inbound - S=500 - I'm terribly sorry, server error occurred (1/SL) M=REGISTER IP=«udp»:«127.0.0.1»:«5062» ID=«000001e4-27c6afde096c100099040080f0a581fc at IP-REMOVED» UA='<null>' DESTIP=«127.0.0.1»:«5060»

In kamailio-options-lb.log we see:

Line  8307: Sep  1 09:05:56 box01 proxy[634207]: ERROR: ROUTE_REG_HANDLE db_redis [redis_dbase.c:2043]: db_redis_perform_update(): Failed to get reply for query: Connection reset by peer
Line  8308: Sep  1 09:05:56 box01 proxy[634207]: ERROR: ROUTE_REG_HANDLE db_redis [redis_dbase.c:2298]: db_redis_perform_update(): failed to perform the update
Line  8309: Sep  1 09:05:56 box01 proxy[634207]: ERROR: ROUTE_REG_HANDLE db_redis [redis_dbase.c:2850]: db_redis_update(): failed to do the query
Line  8310: Sep  1 09:05:56 box01 proxy[634207]: ERROR: ROUTE_REG_HANDLE usrloc [ucontact.c:1147]: db_update_ucontact_ruid(): updating database failed
Line  8311: Sep  1 09:05:56 box01 proxy[634207]: ERROR: ROUTE_REG_HANDLE usrloc [ucontact.c:1663]: update_contact_db(): failed to update database
Line  8312: Sep  1 09:05:56 box01 proxy[634207]: ERROR: ROUTE_REG_HANDLE registrar [save.c:796]: update_contacts(): failed to update contact
Line  8313: Sep  1 09:05:56 box01 proxy[634207]: ERROR: ROUTE_REG_HANDLE <script>: Contacts failed - R=«sip:box01.easyipt.co.uk;transport=udp» ID=«0216ED4BE98140000000375C at 92.207.169.202<mailto:0216ED4BE98140000000375C at 92.207.169.202>» UA='NEC SL2100'
Line  8314: Sep  1 09:05:56 box01 proxy[634207]: NOTICE: ROUTE_REG_HANDLE <script>: Sending reply S=500 Server Error fs='«127.0.0.1»:«5062»' du='«127.0.0.1»:«5060»' - R=«sip:REMOVED;transport=udp» ID=«0216ED4BE98140000000375C at REMOVED» UA='NEC SL2100'
Line  8315: Sep  1 09:05:56 box01 proxy[634207]: ERROR: ROUTE_REG_HANDLE sl [sl_funcs.c:414]: sl_reply_error(): stateless error reply used: I'm terribly sorry, server error occurred (1/SL)

Redis.log does not show anything:

Sep  1 09:08:57 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:08:57.481 - DB 3: 11 keys (0 volatile) in 64 slots HT.
Sep  1 09:08:57 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:08:57.481 - DB 4: 2 keys (0 volatile) in 8 slots HT.
Sep  1 09:08:57 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:08:57.481 - DB 19: 24 keys (24 volatile) in 32 slots HT.
Sep  1 09:08:57 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:08:57.481 - DB 20: 57 keys (0 volatile) in 64 slots HT.
Sep  1 09:08:57 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:08:57.481 - DB 21: 31 keys (0 volatile) in 64 slots HT.
Sep  1 09:08:57 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:08:57.481 - DB 23: 32 keys (0 volatile) in 32 slots HT.
Sep  1 09:08:57 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:08:57.481 - Closing idle client
Sep  1 09:08:59 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:08:59.290 - Closing idle client
Sep  1 09:09:01 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:01.252 - Accepted 127.0.0.1:51798
Sep  1 09:09:01 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:01.258 - Client closed connection
Sep  1 09:09:01 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:01.517 - Accepted 127.0.0.1:51802
Sep  1 09:09:01 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:01.518 - Accepted 127.0.0.1:51804
Sep  1 09:09:01 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:01.519 - Accepted 127.0.0.1:51806
Sep  1 09:09:02 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:02.312 - Accepted 127.0.0.1:51808
Sep  1 09:09:02 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:02.314 - Accepted 127.0.0.1:51810
Sep  1 09:09:02 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:02.506 - DB 3: 7 keys (0 volatile) in 64 slots HT.
Sep  1 09:09:02 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:02.506 - DB 4: 1 keys (0 volatile) in 8 slots HT.
Sep  1 09:09:02 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:02.506 - DB 19: 24 keys (24 volatile) in 32 slots HT.
Sep  1 09:09:02 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:02.506 - DB 20: 57 keys (0 volatile) in 64 slots HT.
Sep  1 09:09:02 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:02.506 - DB 21: 32 keys (0 volatile) in 64 slots HT.
Sep  1 09:09:02 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:02.506 - DB 23: 32 keys (0 volatile) in 32 slots HT.
Sep  1 09:09:03 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:03.553 - Client closed connection
Sep  1 09:09:03 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:03.553 - Client closed connection
Sep  1 09:09:03 box01 (info) redis[634122]:  634122:M 01 Sep 2023 09:09:03.553 - Client closed connection

Restarting REDIS does clear the problem for a period of time however It does return. Typically, if the box is physically restarted it goes away for a few months..

Boxes are all VM on ESXi hosts.

Just wondering what I we can do to debug this a little further, or if anyone knows what would be at catalyst for this?

Thank you in advance 😊

Kind Regards,

Adam





--
Marco Capetta
R&D Manager

Sipwise GmbH | an ALE Company <http://www.sipwise.com/>
c/o ALE International – Austria Branch
Saturn Tower
Leonard-Bernstein-Straße 10
1220 Vienna, Austria

Email:  mcapetta at sipwise.com <mailto:mcapetta at sipwise.com>
Website:  www.sipwise.com <http://www.sipwise.com/>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sipwise.com/pipermail/spce-user_lists.sipwise.com/attachments/20231023/746652b6/attachment-0001.html>

More information about the Spce-user mailing list