=== REDIS BUG REPORT START: Cut & paste starting from here === 42524:M 06 Sep 2023 14:57:31.062 # === ASSERTION FAILED === 42524:M 06 Sep 2023 14:57:31.062 # ==> t_zset.c:280 'x && curscore == x->score && sdscmp(x->ele,ele) == 0' is not true
------ INFO OUTPUT ------
Server
redis_version:6.2.13 redis_git_sha1:024897ed redis_git_dirty:0 redis_build_id:baf36c7e8b74f48 redis_mode:standalone os:Linux 5.15.24-0-lts x86_64 arch_bits:64 monotonic_clock:POSIX clock_gettime multiplexing_api:epoll atomicvar_api:c11-builtin gcc_version:10.3.1 process_id:42524 process_supervised:no run_id:16f764e394738ca24955efcdd63e02e4ee110f76 tcp_port:6379 server_time_usec:1693979851062574 uptime_in_seconds:88282 uptime_in_days:1 hz:10 configured_hz:10 lru_clock:16258250 executable:/usr/bin/redis-server config_file:/etc/redis.conf io_threads_active:0
Clients
connected_clients:13 cluster_connections:0 maxclients:10000 client_recent_max_input_buffer:36 client_recent_max_output_buffer:0 blocked_clients:0 tracking_clients:0 clients_in_timeout_table:0
Memory
used_memory:7684815 used_memory_human:7.33M used_memory_rss:14503936 used_memory_rss_human:13.83M used_memory_peak:11210610 used_memory_peak_human:10.69M used_memory_peak_perc:68.55% used_memory_overhead:1592671 used_memory_startup:788045 used_memory_dataset:6092144 used_memory_dataset_perc:88.33% allocator_allocated:7683464 allocator_active:14473216 allocator_resident:14473216 total_system_memory:67179421696 total_system_memory_human:62.57G used_memory_lua:30720 used_memory_lua_human:30.00K used_memory_scripts:0 used_memory_scripts_human:0B number_of_cached_scripts:0 maxmemory:0 maxmemory_human:0B maxmemory_policy:noeviction allocator_frag_ratio:1.88 allocator_frag_bytes:6789752 allocator_rss_ratio:1.00 allocator_rss_bytes:0 rss_overhead_ratio:1.00 rss_overhead_bytes:30720 mem_fragmentation_ratio:1.89 mem_fragmentation_bytes:6820472 mem_not_counted_for_evict:186 mem_replication_backlog:0 mem_clients_slaves:0 mem_clients_normal:221260 mem_aof_buffer:190 mem_allocator:libc active_defrag_running:0 lazyfree_pending_objects:0 lazyfreed_objects:0
Persistence
loading:0 current_cow_size:0 current_cow_size_age:0 current_fork_perc:0.00 current_save_keys_processed:0 current_save_keys_total:0 rdb_changes_since_last_save:6204 rdb_bgsave_in_progress:0 rdb_last_save_time:1693979807 rdb_last_bgsave_status:ok rdb_last_bgsave_time_sec:0 rdb_current_bgsave_time_sec:-1 rdb_last_cow_size:3121152 aof_enabled:1 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 aof_last_cow_size:0 module_fork_in_progress:0 module_fork_last_cow_size:0 aof_current_size:470364392 aof_base_size:285237534 aof_pending_rewrite:0 aof_buffer_length:0 aof_rewrite_buffer_length:0 aof_pending_bio_fsync:0 aof_delayed_fsync:0
Stats
total_connections_received:566336 total_commands_processed:4100490 instantaneous_ops_per_sec:7765 total_net_input_bytes:339496602 total_net_output_bytes:205277554 instantaneous_input_kbps:694.83 instantaneous_output_kbps:46.94 rejected_connections:0 sync_full:0 sync_partial_ok:0 sync_partial_err:0 expired_keys:544 expired_stale_perc:0.00 expired_time_cap_reached_count:0 expire_cycle_cpu_milliseconds:3761 evicted_keys:0 keyspace_hits:1233832 keyspace_misses:128582 pubsub_channels:0 pubsub_patterns:0 latest_fork_usec:705 total_forks:352 migrate_cached_sockets:0 slave_expires_tracked_keys:0 active_defrag_hits:0 active_defrag_misses:0 active_defrag_key_hits:0 active_defrag_key_misses:0 tracking_total_keys:0 tracking_total_items:0 tracking_total_prefixes:0 unexpected_error_replies:0 total_error_replies:17954 dump_payload_sanitizations:0 total_reads_processed:4684839 total_writes_processed:4118836 io_threaded_reads_processed:0 io_threaded_writes_processed:0
Replication
role:master connected_slaves:0 master_failover_state:no-failover master_replid:9d9e80fab32065f5426197739eead35fdb6be19d master_replid2:0000000000000000000000000000000000000000 master_repl_offset:0 second_repl_offset:-1 repl_backlog_active:0 repl_backlog_size:1048576 repl_backlog_first_byte_offset:0 repl_backlog_histlen:0
CPU
used_cpu_sys:178.932064 used_cpu_user:148.696761 used_cpu_sys_children:3.406465 used_cpu_user_children:12.095729 used_cpu_sys_main_thread:170.893670 used_cpu_user_main_thread:145.115127
Modules
Commandstats
cmdstat_lrem:calls=129423,usec=17950359,usec_per_call=138.70,rejected_calls=17426,failed_calls=0 cmdstat_del:calls=102599,usec=811037,usec_per_call=7.90,rejected_calls=12,failed_calls=0 cmdstat_zscore:calls=380539,usec=1675316,usec_per_call=4.40,rejected_calls=140,failed_calls=0 cmdstat_command:calls=12,usec=49203,usec_per_call=4100.25,rejected_calls=0,failed_calls=0 cmdstat_zrem:calls=412384,usec=1569094,usec_per_call=3.80,rejected_calls=0,failed_calls=0 cmdstat_rpush:calls=84950,usec=174871,usec_per_call=2.06,rejected_calls=0,failed_calls=0 cmdstat_exists:calls=198747,usec=233787,usec_per_call=1.18,rejected_calls=1,failed_calls=0 cmdstat_rename:calls=50,usec=608,usec_per_call=12.16,rejected_calls=0,failed_calls=0 cmdstat_zadd:calls=941974,usec=5348570,usec_per_call=5.68,rejected_calls=346,failed_calls=0 cmdstat_zincrby:calls=699106,usec=6401080,usec_per_call=9.16,rejected_calls=24,failed_calls=0 cmdstat_hmget:calls=104058,usec=290528,usec_per_call=2.79,rejected_calls=0,failed_calls=0 cmdstat_set:calls=273466,usec=1291390,usec_per_call=4.72,rejected_calls=3,failed_calls=0 cmdstat_llen:calls=161,usec=777,usec_per_call=4.83,rejected_calls=0,failed_calls=0 cmdstat_hgetall:calls=13,usec=166,usec_per_call=12.77,rejected_calls=1,failed_calls=0 cmdstat_get:calls=677314,usec=1454516,usec_per_call=2.15,rejected_calls=0,failed_calls=0 cmdstat_keys:calls=364,usec=1377936,usec_per_call=3785.54,rejected_calls=0,failed_calls=0 cmdstat_lrange:calls=137,usec=2347,usec_per_call=17.13,rejected_calls=0,failed_calls=0 cmdstat_expire:calls=664,usec=2883,usec_per_call=4.34,rejected_calls=0,failed_calls=0 cmdstat_zrange:calls=1445,usec=764207,usec_per_call=528.86,rejected_calls=0,failed_calls=0 cmdstat_hmset:calls=93084,usec=703222,usec_per_call=7.55,rejected_calls=0,failed_calls=0
Errorstats
errorstat_ERR:count=17440 errorstat_LOADING:count=514
Cluster
cluster_enabled:0
Keyspace
db0:keys=11202,expires=125,avg_ttl=347015299
------ CLIENT LIST OUTPUT ------ id=7148 addr=127.0.0.1:45864 laddr=127.0.0.1:6379 fd=12 name= age=86667 idle=7 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=17020 events=r cmd=set user=default redir=-1 id=12 addr=127.0.0.1:58928 laddr=127.0.0.1:6379 fd=10 name= age=88257 idle=16 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=17012 events=r cmd=del user=default redir=-1 id=7149 addr=127.0.0.1:45866 laddr=127.0.0.1:6379 fd=16 name= age=86662 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=93 qbuf-free=32675 argv-mem=63 obl=0 oll=0 omem=0 tot-mem=49861 events=r cmd=zadd user=default redir=-1 id=5084 addr=127.0.0.1:41478 laddr=127.0.0.1:6379 fd=23 name= age=87112 idle=345 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=17020 events=r cmd=set user=default redir=-1 id=557287 addr=127.0.0.1:58776 laddr=127.0.0.1:6379 fd=19 name= age=13163 idle=4 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=17020 events=r cmd=set user=default redir=-1 id=557918 addr=127.0.0.1:60130 laddr=127.0.0.1:6379 fd=18 name= age=1327 idle=118 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=17020 events=r cmd=set user=default redir=-1 id=557921 addr=127.0.0.1:60138 laddr=127.0.0.1:6379 fd=20 name= age=1327 idle=6 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=17020 events=r cmd=set user=default redir=-1 id=5 addr=127.0.0.1:58912 laddr=127.0.0.1:6379 fd=13 name= age=88280 idle=7 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=17012 events=r cmd=exists user=default redir=-1 id=557144 addr=127.0.0.1:58476 laddr=127.0.0.1:6379 fd=11 name= age=16144 idle=3 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=17020 events=r cmd=set user=default redir=-1 id=86951 addr=127.0.0.1:46098 laddr=127.0.0.1:6379 fd=17 name= age=61545 idle=1 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=17020 events=r cmd=set user=default redir=-1 id=6 addr=127.0.0.1:58914 laddr=127.0.0.1:6379 fd=14 name= age=88279 idle=1 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=17020 events=r cmd=set user=default redir=-1 id=7 addr=127.0.0.1:58916 laddr=127.0.0.1:6379 fd=15 name= age=88278 idle=11 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=17020 events=r cmd=set user=default redir=-1 id=557271 addr=127.0.0.1:58744 laddr=127.0.0.1:6379 fd=21 name= age=13341 idle=262 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=17028 events=r cmd=lrem user=default redir=-1
------ CURRENT CLIENT INFO ------ id=7149 addr=127.0.0.1:45866 laddr=127.0.0.1:6379 fd=16 name= age=86662 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=93 qbuf-free=32675 argv-mem=63 obl=0 oll=0 omem=0 tot-mem=49861 events=r cmd=zadd user=default redir=-1 argv[0]: 'ZADD' argv[1]: 'peer_pre_tx' argv[2]: '2640' argv[3]: 'HoNY4MVsNFXlZCUZgUG/bgQMiZ51KP9gtJvvJ2eQb3g=' 42524:M 06 Sep 2023 14:57:31.063 # key 'peer_pre_tx' found in DB containing the following object: 42524:M 06 Sep 2023 14:57:31.063 # Object type: 3 42524:M 06 Sep 2023 14:57:31.063 # Object encoding: 7 42524:M 06 Sep 2023 14:57:31.063 # Object refcount: 1
------ MODULES INFO OUTPUT ------
------ FAST MEMORY TEST ------ 42524:M 06 Sep 2023 14:57:31.063 # Bio thread for job type #0 terminated 42524:M 06 Sep 2023 14:57:31.064 # Bio thread for job type #1 terminated 42524:M 06 Sep 2023 14:57:31.064 # Bio thread for job type #2 terminated *** Preparing to test memory region 55ee96768000 (122880 bytes) *** Preparing to test memory region 55ee97d30000 (380928 bytes) *** Preparing to test memory region 7f15b621e000 (57344 bytes) *** Preparing to test memory region 7f15b6261000 (155648 bytes) *** Preparing to test memory region 7f15b62ab000 (425984 bytes) *** Preparing to test memory region 7f15b631c000 (1048576 bytes) *** Preparing to test memory region 7f15b6420000 (98304 bytes) *** Preparing to test memory region 7f15b6440000 (491520 bytes) *** Preparing to test memory region 7f15b64cb000 (32768 bytes) *** Preparing to test memory region 7f15b64f5000 (425984 bytes) *** Preparing to test memory region 7f15b656d000 (131072 bytes) *** Preparing to test memory region 7f15b6593000 (557056 bytes) *** Preparing to test memory region 7f15b6622000 (262144 bytes) *** Preparing to test memory region 7f15b6666000 (65536 bytes) *** Preparing to test memory region 7f15b6678000 (32768 bytes) *** Preparing to test memory region 7f15b6686000 (32768 bytes) *** Preparing to test memory region 7f15b6694000 (65536 bytes) *** Preparing to test memory region 7f15b66a7000 (98304 bytes) *** Preparing to test memory region 7f15b66cd000 (65536 bytes) *** Preparing to test memory region 7f15b66e6000 (32768 bytes) *** Preparing to test memory region 7f15b6702000 (65536 bytes) *** Preparing to test memory region 7f15b672f000 (16384 bytes) *** Preparing to test memory region 7f15b673c000 (16384 bytes) *** Preparing to test memory region 7f15b6744000 (16384 bytes) *** Preparing to test memory region 7f15b674e000 (16384 bytes) *** Preparing to test memory region 7f15b6756000 (65536 bytes) *** Preparing to test memory region 7f15b6778000 (638976 bytes) *** Preparing to test memory region 7f15b6817000 (65536 bytes) *** Preparing to test memory region 7f15b682d000 (90112 bytes) *** Preparing to test memory region 7f15b6844000 (90112 bytes) *** Preparing to test memory region 7f15b685c000 (53248 bytes) *** Preparing to test memory region 7f15b686c000 (32768 bytes) *** Preparing to test memory region 7f15b6876000 (69632 bytes) *** Preparing to test memory region 7f15b6892000 (32768 bytes) *** Preparing to test memory region 7f15b689d000 (32768 bytes) *** Preparing to test memory region 7f15b68aa000 (32768 bytes) *** Preparing to test memory region 7f15b68b3000 (16384 bytes) *** Preparing to test memory region 7f15b68b9000 (32768 bytes) *** Preparing to test memory region 7f15b68c2000 (36864 bytes) *** Preparing to test memory region 7f15b68cd000 (65536 bytes) *** Preparing to test memory region 7f15b68df000 (32768 bytes) *** Preparing to test memory region 7f15b68ea000 (151552 bytes) *** Preparing to test memory region 7f15b6912000 (167936 bytes) *** Preparing to test memory region 7f15b6940000 (90112 bytes) *** Preparing to test memory region 7f15b6957000 (16384 bytes) *** Preparing to test memory region 7f15b695d000 (32768 bytes) *** Preparing to test memory region 7f15b6968000 (36864 bytes) *** Preparing to test memory region 7f15b6973000 (36864 bytes) *** Preparing to test memory region 7f15b697e000 (32768 bytes) *** Preparing to test memory region 7f15b6989000 (364544 bytes) *** Preparing to test memory region 7f15b69e5000 (32768 bytes) *** Preparing to test memory region 7f15b69ef000 (53248 bytes) *** Preparing to test memory region 7f15b69fe000 (266240 bytes) *** Preparing to test memory region 7f15b6a4f000 (90112 bytes) *** Preparing to test memory region 7f15b6a67000 (36864 bytes) *** Preparing to test memory region 7f15b6a72000 (36864 bytes) *** Preparing to test memory region 7f15b6a7e000 (32768 bytes) *** Preparing to test memory region 7f15b6a88000 (36864 bytes) *** Preparing to test memory region 7f15b6a93000 (380928 bytes) *** Preparing to test memory region 7f15b6af1000 (40960 bytes) *** Preparing to test memory region 7f15b6afe000 (69632 bytes) *** Preparing to test memory region 7f15b6b11000 (102400 bytes) *** Preparing to test memory region 7f15b6b37000 (16384 bytes) *** Preparing to test memory region 7f15b6b3f000 (94208 bytes) *** Preparing to test memory region 7f15b6b59000 (32768 bytes) *** Preparing to test memory region 7f15b6b63000 (36864 bytes) *** Preparing to test memory region 7f15b6b6f000 (106496 bytes) *** Preparing to test memory region 7f15b6b8c000 (32768 bytes) *** Preparing to test memory region 7f15b6b97000 (32768 bytes) *** Preparing to test memory region 7f15b6ba0000 (16384 bytes) *** Preparing to test memory region 7f15b6ba7000 (356352 bytes) *** Preparing to test memory region 7f15b6c07000 (1835008 bytes) *** Preparing to test memory region 7f15b6dc8000 (1159168 bytes) *** Preparing to test memory region 7f15b6eec000 (12288 bytes) *** Preparing to test memory region 7f15b6ef5000 (36864 bytes) *** Preparing to test memory region 7f15b6f00000 (16384 bytes) *** Preparing to test memory region 7f15b7b0c000 (1097728 bytes) *** Preparing to test memory region 7f15b7cae000 (12288 bytes) .O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O.O Fast memory test PASSED, however your memory can still be broken. Please run a memory test for several hours if possible.
=== REDIS BUG REPORT END. Make sure to include from START to END. ===
Comment From: sundb
@hjim1021 What is the meaning of through hiredis?
Comment From: hjim1021
@sundb This occurs when executing redisCommand() below using the hiredis library.
include
... reply = redisCommand(c, "ZADD peer_pre_tx %lu %s", pre_tx_bytes, tmp); if (reply) freeReplyObject(reply);
------ CURRENT CLIENT INFO ------ id=7149 addr=127.0.0.1:45866 laddr=127.0.0.1:6379 fd=16 name= age=86662 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=93 qbuf-free=32675 argv-mem=63 obl=0 oll=0 omem=0 tot-mem=49861 events=r cmd=zadd user=default redir=-1 argv[0]: 'ZADD' argv[1]: 'peer_pre_tx' argv[2]: '2640' argv[3]: 'HoNY4MVsNFXlZCUZgUG/bgQMiZ51KP9gtJvvJ2eQb3g=' 42524:M 06 Sep 2023 14:57:31.063 # key 'peer_pre_tx' found in DB containing the following object: 42524:M 06 Sep 2023 14:57:31.063 # Object type: 3 42524:M 06 Sep 2023 14:57:31.063 # Object encoding: 7 42524:M 06 Sep 2023 14:57:31.063 # Object refcount: 1
Comment From: hjim1021
This seems to happen when adding more than 2000 members to one redis key using the ZADD command.
=== REDIS BUG REPORT START: Cut & paste starting from here === 42524:M 06 Sep 2023 14:57:31.062 # === ASSERTION FAILED === 42524:M 06 Sep 2023 14:57:31.062 # ==> t_zset.c:280 'x && curscore == x->score && sdscmp(x->ele,ele) == 0' is not true
Comment From: sundb
@hjim1021Thanks for the info, I'll try to see if I can reproduce it.
Comment From: sundb
@hjim1021 Hi, did you enable defragment? I still can't reproduce it locally, can you provide some useful information, like special configurations or environment.
Comment From: hjim1021
@sundb Hi, OS is Alpine Linux 3.15.10. I used it after installing it with "apk add --no-cache redis" redis configurations used the redis.conf file below.
bind * -::* protected-mode yes port 6379 tcp-backlog 511 unixsocket /run/redis/redis.sock unixsocketperm 770 timeout 0 tcp-keepalive 300 loglevel notice logfile /mnt/log/redis/redis.log databases 16 always-show-logo no set-proc-title yes proc-title-template "{title} {listen-addr} {server-mode}" stop-writes-on-bgsave-error yes rdbcompression yes rdbchecksum yes dbfilename dump.rdb rdb-del-sync-files no dir /mnt/log/redis
replica-serve-stale-data yes replica-read-only yes repl-diskless-sync no repl-diskless-sync-delay 5 repl-diskless-load disabled repl-disable-tcp-nodelay no replica-priority 100 acllog-max-len 128 lazyfree-lazy-eviction no lazyfree-lazy-expire no lazyfree-lazy-server-del no replica-lazy-flush no lazyfree-lazy-user-del no lazyfree-lazy-user-flush no oom-score-adj no oom-score-adj-values 0 200 800 disable-thp yes appendonly yes appendfilename "appendonly.aof" appendfsync everysec no-appendfsync-on-rewrite no auto-aof-rewrite-percentage 100 auto-aof-rewrite-min-size 64mb aof-load-truncated yes aof-use-rdb-preamble yes lua-time-limit 5000 slowlog-log-slower-than 10000 slowlog-max-len 128 latency-monitor-threshold 0 notify-keyspace-events "" hash-max-ziplist-entries 512 hash-max-ziplist-value 64 list-max-ziplist-size -2 list-compress-depth 0 set-max-intset-entries 512 zset-max-ziplist-entries 128 zset-max-ziplist-value 64 hll-sparse-max-bytes 3000 stream-node-max-bytes 4096 stream-node-max-entries 100 activerehashing yes client-output-buffer-limit normal 0 0 0 client-output-buffer-limit replica 256mb 64mb 60 client-output-buffer-limit pubsub 32mb 8mb 60 hz 10 dynamic-hz yes aof-rewrite-incremental-fsync yes rdb-save-incremental-fsync yes jemalloc-bg-thread yes