search

redis / redis

Redis is an in-memory database that persists on disk. The data model is key-value, but many different kind of values are supported: Strings, Lists, Sets, Sorted Sets, Hashes, Streams, HyperLogLogs, Bitmaps.
http://redis.io
Other
66.9k stars 23.79k forks source link

[CRASH] occurs when executing redisCommand() using the hiredis library. #12551

Open hjim1021 opened 1 year ago

hjim1021 commented 1 year ago

=== 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. ===

sundb commented 1 year ago

@hjim1021 What is the meaning of through hiredis?

hjim1021 commented 1 year ago

@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

hjim1021 commented 1 year ago

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

sundb commented 1 year ago

@hjim1021Thanks for the info, I'll try to see if I can reproduce it.

sundb commented 1 year ago

@hjim1021 Hi, did you enable defragment? I still can't reproduce it locally, can you provide some useful information, like special configurations or environment.

hjim1021 commented 1 year ago

@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