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