Redis suddenly keeps crashing everytime a celery task is scheduled from this morning. Everything was fine yesterday and I'm quite sure nothing has been updated in-between. I'm not really sure where to go from here :S
Crash report
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.
24343:M 27 Jul 12:39:51.221 # Server started, Redis version 3.0.6
24343:M 27 Jul 12:39:51.221 # WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command 'echo never > /sys/kernel/mm/transparent_hugepage/enabled' as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled.
24343:M 27 Jul 12:39:51.221 * DB loaded from disk: 0.000 seconds
24343:M 27 Jul 12:39:51.221 * The server is now ready to accept connections on port 6379
24343:M 27 Jul 12:40:10.353 #
=== REDIS BUG REPORT START: Cut & paste starting from here ===
24343:M 27 Jul 12:40:10.353 # ------------------------------------------------
24343:M 27 Jul 12:40:10.353 # !!! Software Failure. Press left mouse button to continue
24343:M 27 Jul 12:40:10.353 # Guru Meditation: "Unknown sorted set encoding" #t_zset.c:1350
24343:M 27 Jul 12:40:10.353 # (forcing SIGSEGV in order to print the stack trace)
24343:M 27 Jul 12:40:10.353 # ------------------------------------------------
24343:M 27 Jul 12:40:10.353 # Redis 3.0.6 crashed by signal: 11
24343:M 27 Jul 12:40:10.353 # SIGSEGV caused by address: 0xffffffffffffffff
24343:M 27 Jul 12:40:10.353 # Failed assertion: <no assertion failed> (<no file>:0)
24343:M 27 Jul 12:40:10.353 # --- STACK TRACE
/usr/bin/redis-server 127.0.0.1:6379(logStackTrace+0xa6)[0x557117ad6f66]
/usr/bin/redis-server 127.0.0.1:6379(_redisPanic+0x84)[0x557117ad5f04]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7fd68c2e1390]
/usr/bin/redis-server 127.0.0.1:6379(_redisPanic+0x84)[0x557117ad5f04]
/usr/bin/redis-server 127.0.0.1:6379(zaddGenericCommand+0x755)[0x557117ac59c5]
/usr/bin/redis-server 127.0.0.1:6379(call+0x8e)[0x557117aa2e6e]
/usr/bin/redis-server 127.0.0.1:6379(execCommand+0xcf)[0x557117ad560f]
/usr/bin/redis-server 127.0.0.1:6379(call+0x8e)[0x557117aa2e6e]
/usr/bin/redis-server 127.0.0.1:6379(processCommand+0x3ff)[0x557117aa5f8f]
/usr/bin/redis-server 127.0.0.1:6379(processInputBuffer+0x4f)[0x557117ab060f]
/usr/bin/redis-server 127.0.0.1:6379(readQueryFromClient+0xb2)[0x557117ab0752]
/usr/bin/redis-server 127.0.0.1:6379(aeProcessEvents+0x137)[0x557117a9d277]
/usr/bin/redis-server 127.0.0.1:6379(aeMain+0x2b)[0x557117a9d5db]
/usr/bin/redis-server 127.0.0.1:6379(main+0x364)[0x557117a9c254]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf0)[0x7fd68bf26840]
/usr/bin/redis-server 127.0.0.1:6379(_start+0x29)[0x557117a9c3c9]
24343:M 27 Jul 12:40:10.354 # --- INFO OUTPUT
24343:M 27 Jul 12:40:10.354 # # Server
redis_version:3.0.6
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:256ef3a4da0a4c20
redis_mode:standalone
os:Linux 4.15.0-1098-gcp x86_64
arch_bits:64
multiplexing_api:epoll
gcc_version:5.4.0
process_id:24343
run_id:65b8223cb857c470a993b708f6d98f454086b4bc
tcp_port:6379
uptime_in_seconds:19
uptime_in_days:0
hz:10
lru_clock:14758442
config_file:/etc/redis/redis.conf
# Clients
connected_clients:11
client_longest_output_list:0
client_biggest_input_buf:0
blocked_clients:0
# Memory
used_memory:832752
used_memory_human:813.23K
used_memory_rss:3530752
used_memory_peak:832752
used_memory_peak_human:813.23K
used_memory_lua:39936
mem_fragmentation_ratio:4.24
mem_allocator:jemalloc-3.6.0
# Persistence
loading:0
rdb_changes_since_last_save:8
rdb_bgsave_in_progress:0
rdb_last_save_time:1658925591
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:-1
aof_enabled:0
aof_rewrite_in_progress:0
aof_rewrite_scheduled:0
aof_last_rewrite_time_sec:-1
aof_current_rewrite_time_sec:-1
aof_last_bgrewrite_status:ok
aof_last_write_status:ok
# Stats
total_connections_received:11
total_commands_processed:90
instantaneous_ops_per_sec:1
total_net_input_bytes:15403
total_net_output_bytes:8256
instantaneous_input_kbps:0.56
instantaneous_output_kbps:0.49
rejected_connections:0
sync_full:0
sync_partial_ok:0
sync_partial_err:0
expired_keys:0
evicted_keys:0
keyspace_hits:1
keyspace_misses:21
pubsub_channels:0
pubsub_patterns:2
latest_fork_usec:0
migrate_cached_sockets:0
# Replication
role:master
connected_slaves:0
master_repl_offset:0
repl_backlog_active:0
repl_backlog_size:1048576
repl_backlog_first_byte_offset:0
repl_backlog_histlen:0
# CPU
used_cpu_sys:0.02
used_cpu_user:0.01
used_cpu_sys_children:0.00
used_cpu_user_children:0.00
# Commandstats
cmdstat_get:calls=1,usec=1,usec_per_call=1.00
cmdstat_set:calls=1,usec=9,usec_per_call=9.00
cmdstat_del:calls=5,usec=3,usec_per_call=0.60
cmdstat_lpush:calls=1,usec=8,usec_per_call=8.00
cmdstat_brpop:calls=17,usec=158,usec_per_call=9.29
cmdstat_llen:calls=20,usec=7,usec_per_call=0.35
cmdstat_sadd:calls=2,usec=11,usec_per_call=5.50
cmdstat_srem:calls=1,usec=10,usec_per_call=10.00
cmdstat_zrevrangebyscore:calls=1,usec=9,usec_per_call=9.00
cmdstat_ping:calls=12,usec=24,usec_per_call=2.00
cmdstat_multi:calls=7,usec=12,usec_per_call=1.71
cmdstat_exec:calls=6,usec=22,usec_per_call=3.67
cmdstat_psubscribe:calls=2,usec=7,usec_per_call=3.50
cmdstat_publish:calls=11,usec=82,usec_per_call=7.45
cmdstat_eval:calls=1,usec=23,usec_per_call=23.00
cmdstat_evalsha:calls=1,usec=15,usec_per_call=15.00
cmdstat_script:calls=1,usec=80,usec_per_call=80.00
# Cluster
cluster_enabled:0
# Keyspace
db0:keys=4,expires=0,avg_ttl=0
hash_init_value: 1658994522
24343:M 27 Jul 12:40:10.354 # --- CLIENT LIST OUTPUT
24343:M 27 Jul 12:40:10.354 # id=10 addr=127.0.0.1:57326 fd=13 name= age=17 idle=17 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=exec
id=4 addr=127.0.0.1:57314 fd=7 name= age=18 idle=18 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=ping
id=5 addr=127.0.0.1:57316 fd=8 name= age=18 idle=2 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=publish
id=6 addr=127.0.0.1:57318 fd=9 name= age=18 idle=18 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=publish
id=7 addr=127.0.0.1:57320 fd=10 name= age=17 idle=2 flags=N db=0 sub=0 psub=1 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=psubscribe
id=8 addr=127.0.0.1:57322 fd=11 name= age=17 idle=17 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=sadd
id=2 addr=127.0.0.1:57310 fd=5 name= age=18 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=brpop
id=3 addr=127.0.0.1:57312 fd=6 name= age=18 idle=0 flags=x db=0 sub=0 psub=0 multi=2 qbuf=0 qbuf-free=32768 obl=27 oll=0 omem=0 events=rw cmd=exec
id=9 addr=127.0.0.1:57324 fd=12 name= age=17 idle=17 flags=N db=0 sub=0 psub=1 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=psubscribe
id=11 addr=127.0.0.1:57328 fd=14 name= age=0 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=lpush
id=12 addr=127.0.0.1:57330 fd=15 name= age=0 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=mget
24343:M 27 Jul 12:40:10.354 # --- CURRENT CLIENT INFO
24343:M 27 Jul 12:40:10.354 # client: id=3 addr=127.0.0.1:57312 fd=6 name= age=18 idle=0 flags=x db=0 sub=0 psub=0 multi=2 qbuf=0 qbuf-free=32768 obl=27 oll=0 omem=0 events=rw cmd=exec
24343:M 27 Jul 12:40:10.354 # argv[0]: 'ZADD'
24343:M 27 Jul 12:40:10.354 # argv[1]: 'unacked_index'
24343:M 27 Jul 12:40:10.354 # argv[2]: '1658925610.3525639'
24343:M 27 Jul 12:40:10.354 # argv[3]: '41e456eb-d08a-480c-81f9-386204561616'
24343:M 27 Jul 12:40:10.354 # key 'unacked_index' found in DB containing the following object:
24343:M 27 Jul 12:40:10.354 # Object type: 3
24343:M 27 Jul 12:40:10.354 # Object encoding: 5
24343:M 27 Jul 12:40:10.354 # Object refcount: 1
24343:M 27 Jul 12:40:10.354 # Sorted set size: 0
24343:M 27 Jul 12:40:10.354 # --- REGISTERS
24343:M 27 Jul 12:40:10.354 #
RAX:0000000000000000 RBX:0000557117b18602
RCX:00007fd68c723370 RDX:0000000000000009
RDI:00007fd68b406000 RSI:000000000000003d
RBP:0000557117b1aa14 RSP:00007fff7acc95b0
R8 :00007fd68cc46740 R9 :00007fd68cc46740
R10:0000000000000030 R11:0000000000000246
R12:0000000000000546 R13:00007fd68b551000
R14:00007fd68b4e5620 R15:00007fd68b4e5620
RIP:0000557117ad5f04 EFL:0000000000010202
CSGSFS:002b000000000033
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95bf) -> e8e29de9a0d70500
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95be) -> 0000000000000000
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95bd) -> 0000000000000001
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95bc) -> 00007fff7acc9620
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95bb) -> 0000000000000000
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95ba) -> 0000000000008009
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95b9) -> 00007fd68b4130a8
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95b8) -> 00007fd68b537fd0
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95b7) -> 0000000100000000
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95b6) -> 00000005008000c0
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95b5) -> 00007fd600000001
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95b4) -> 41d8b84c8a969068
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95b3) -> 0000557117ac59c5
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95b2) -> 0000000000000003
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95b1) -> 00007fd68b412f40
24343:M 27 Jul 12:40:10.354 # (00007fff7acc95b0) -> 00007fd68b4130a8
24343:M 27 Jul 12:40:10.354 # --- FAST MEMORY TEST
24343:M 27 Jul 12:40:10.354 # Bio thread for job type #0 terminated
24343:M 27 Jul 12:40:10.354 # Bio thread for job type #1 terminated
24343:M 27 Jul 12:40:10.638 # Fast memory test PASSED, however your memory can still be broken. Please run a memory test for several hours if possible.
24343:M 27 Jul 12:40:10.638 #
=== REDIS BUG REPORT END. Make sure to include from START to END. ===
Additional information
- Ubuntu 16.04.7 LTS / Redis v=3.0.6 sha=00000000:0 malloc=jemalloc-3.6.0 bits=64 build=256ef3a4da0a4c20
- Just schedule a celery task (using Redis as a backend of course)
Comment From: oranagra
it's odd that it panics on Unknown sObject encoding: 5orted set encoding, but the crash log shows Object encoding: 5, which is ZIPLIST which is supported.
It's hard to say much more than that, except stating that this is a very old version.
Comment From: codefromhezad
Thanks for your comment, I didn't try to update Redis since it was working perfectly fine but I should have thought about that.
I just updated redis and it works again perfectly.
I don't know if you want to keep this crash report open or not since it was such an old version ?
Anyway, thanks again.
Comment From: oranagra
we can argue it's unresolved, but being such an old version, no one is gonna dig into it anyway, so there's no reason to keep it open. also, if you say an upgrade solved it, then maybe we can conclude it was already fixed (even though we don't know what it was). bottom line, let's close it.