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

Adam Clark aclark at structuredcommunications.co.uk
Fri Oct 20 12:26:56 EDT 2023 

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» 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


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sipwise.com/pipermail/spce-user_lists.sipwise.com/attachments/20231020/c9fdeefc/attachment-0001.html>

More information about the Spce-user mailing list