KeyDB: [CRASH] server started to throw "read error on connection to ..."

Crash report

phpredis started to throw “read error on connection to 127.0.0.1:11080” at a random time with minimal load. This happened already twice in 2 different servers in different times. When I realized it’s not working, i couldnt connect via keydb-cli as well. Until i restarted the server, logs were also not coming for quite some. Despite that it wasnt working, keydb process was still running and systemctl status keydb also showed “running”.

Paste the complete crash log between the quotes below. Please include a few lines from the log preceding the crash report to provide some context.

### BEFORE RESTART
....
27373:27392:M 24 Jul 2022 15:50:06.665 * Background saving terminated with success
27373:27392:M 24 Jul 2022 15:55:07.028 * 1 changes in 300 seconds. Saving...
27373:27392:M 24 Jul 2022 15:55:07.029 * Background saving started
27373:12175:M 24 Jul 2022 15:55:07.605 * DB saved on disk
27373:12175:M 24 Jul 2022 15:55:07.610 * RDB: 40 MB of memory used by copy-on-write
27373:27392:M 24 Jul 2022 15:55:07.634 * Background saving terminated with success
27373:27392:M 24 Jul 2022 16:00:08.081 * 1 changes in 300 seconds. Saving...
27373:27392:M 24 Jul 2022 16:00:08.081 * Background saving started
27373:16152:M 24 Jul 2022 16:00:08.636 * DB saved on disk
27373:16152:M 24 Jul 2022 16:00:08.640 * RDB: 41 MB of memory used by copy-on-write
27373:27392:M 24 Jul 2022 16:00:08.688 * Background saving terminated with success
27373:27392:M 24 Jul 2022 16:05:09.049 * 1 changes in 300 seconds. Saving...
27373:27392:M 24 Jul 2022 16:05:09.049 * Background saving started
27373:19768:M 24 Jul 2022 16:05:09.614 * DB saved on disk
27373:19768:M 24 Jul 2022 16:05:09.618 * RDB: 41 MB of memory used by copy-on-write
27373:27392:M 24 Jul 2022 16:05:09.657 * Background saving terminated with success

### AFTER RESTART (no logs since 16:05 until i restart)

27373:signal-handler (1658696015) Received SIGTERM scheduling shutdown...
27373:27392:M 24 Jul 2022 23:53:35.257 # User requested shutdown...
27373:27392:M 24 Jul 2022 23:53:35.257 * Saving the final RDB snapshot before exiting.
27373:27392:M 24 Jul 2022 23:53:35.782 * DB saved on disk
27373:27392:M 24 Jul 2022 23:53:35.782 * Removing the pid file.
27373:27393:M 24 Jul 2022 23:53:35.782 # Accepting client connection: accept: Bad file descriptor
27373:27392:M 24 Jul 2022 23:53:35.818 # KeyDB is now ready to exit, bye bye...
23552:23523:C 24 Jul 2022 23:53:36.163 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
23552:23523:C 24 Jul 2022 23:53:36.163 # KeyDB version=6.3.1, bits=64, commit=00000000, modified=0, pid=23552, just started
23552:23523:C 24 Jul 2022 23:53:36.163 # Configuration loaded
23552:23523:M 24 Jul 2022 23:53:36.165 * monotonic clock: POSIX clock_gettime
23552:23523:M 24 Jul 2022 23:53:36.166 * Running mode=standalone, port=11080.
23552:23523:M 24 Jul 2022 23:53:36.166 # Server initialized
23552:23523:M 24 Jul 2022 23:53:36.166 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
23552:23523:M 24 Jul 2022 23:53:36.167 * Loading RDB produced by version 6.3.1
23552:23523:M 24 Jul 2022 23:53:36.168 * RDB age 1 seconds
23552:23523:M 24 Jul 2022 23:53:36.168 * RDB memory usage when created 29.44 Mb
23552:23523:M 24 Jul 2022 23:53:36.387 # Done loading RDB, keys loaded: 0, keys expired: 0.
23552:23523:M 24 Jul 2022 23:53:36.387 * DB loaded from disk: 0.219 seconds

Aditional information

  1. OS distribution and version

Ubuntu Server 18.04 and keydb 6.3.1 with more than enough ram and disk space.

Config:

bind 127.0.0.1
port 11080

protected-mode yes

timeout 15

daemonize yes
pidfile /var/run/keydb/keydb-server.pid

loglevel notice
logfile /var/log/keydb/keydb-server.log

set-proc-title yes
proc-title-template "{title} {listen-addr} {server-mode}"

dir /var/lib/keydb

maxclients 5000
server-threads 2

policies
maxmemory 1G
maxmemory-policy noeviction

save 300 1
save 60 100
stop-writes-on-bgsave-error yes
rdbcompression yes
rdbchecksum yes
dbfilename dump.rdb
rdb-del-sync-files no

appendonly no
  1. Steps to reproduce (if any) Nothing I can tell. It started to happen random recently. It didn’t ever happen for months before. It might be related to v6.3.1, but I don’t remember when I upgraded to this version.

About this issue

  • Original URL
  • State: closed
  • Created 2 years ago
  • Comments: 31

Most upvoted comments

We have a cluster here at Snap that has begun to repro this which should help a lot with debugging. I really appreciate everyone’s help providing data and I hope to have a fix soon.

On Wed, Aug 17, 2022 at 1:20 PM solracsf @.***> wrote:

I had a similar problem here; different machines, but all under Ubuntu 20.04. OpenSSL 3 doesn’t apply here. They all, after some time (days) start refusing connection (a simple keydb-cli -h 10.1.0.2 PING timeout) and there is nothing in the logs. Restarting (systemctl restart keydb) solves the issue, until it starts again.

KeyDB 6.3.1 is the version.

After that, I’ve stopped/disabled KeyDB, and installed Redis 6.2.7; since that, with a very similar config file, no problems, crash or whatever, on the same machine where KeyDB stopped working. Note that machine is simply listening on the LAN interface and localhost, no cluster or replication is enabled here. I really don’t know how to help debug this…

— Reply to this email directly, view it on GitHub https://github.com/Snapchat/KeyDB/issues/474#issuecomment-1218293913, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA5W4AQ26J4NY6LYF2JS5E3VZUNPFANCNFSM54RHRK2Q . You are receiving this because you were mentioned.Message ID: @.***>