[CRASH] 在redis6.2.12中偶现崩溃

[sndwow]

=== REDIS BUG REPORT START: Cut & paste starting from here ===
20232:M 19 Jun 2023 17:16:19.484 # Redis 6.2.12 crashed by signal: 11, si_code: 128
20232:M 19 Jun 2023 17:16:19.484 # Accessing address: (nil)
20232:M 19 Jun 2023 17:16:19.484 # Crashed running the instruction at: 0x7febea236891

------ STACK TRACE ------
EIP:
/usr/local/redis/bin/module/tair_hash.so(+0x1891)[0x7febea236891]

Backtrace:
/lib64/libpthread.so.0(+0xf630)[0x7febe9727630]
/usr/local/redis/bin/module/tair_hash.so(+0x1891)[0x7febea236891]
/usr/local/redis/bin/module/tair_hash.so(+0x532f)[0x7febea23a32f]
/usr/local/redis/bin/redis-server 0.0.0.0:6379(RedisModuleCommandDispatcher+0x4e)[0x4c201e]
/usr/local/redis/bin/redis-server 0.0.0.0:6379(call+0xd5)[0x43ac95]
/usr/local/redis/bin/redis-server 0.0.0.0:6379(processCommand+0x57d)[0x43c8dd]
/usr/local/redis/bin/redis-server 0.0.0.0:6379(processInputBuffer+0xf3)[0x44f6b3]
/usr/local/redis/bin/redis-server 0.0.0.0:6379[0x4e2878]
/usr/local/redis/bin/redis-server 0.0.0.0:6379(aeProcessEvents+0x292)[0x433b42]
/usr/local/redis/bin/redis-server 0.0.0.0:6379(aeMain+0x1d)[0x433dad]
/usr/local/redis/bin/redis-server 0.0.0.0:6379(main+0x311)[0x430031]
/lib64/libc.so.6(__libc_start_main+0xf5)[0x7febe936c555]
/usr/local/redis/bin/redis-server 0.0.0.0:6379[0x4304f9]

------ REGISTERS ------
20232:M 19 Jun 2023 17:16:19.485 #
RAX:00007febea24f5e0 RBX:0000000000000002
RCX:0000000000000020 RDX:00007febea23ed91
RDI:00007febd6fd0960 RSI:00007febd6fd0960
RBP:0000000000000000 RSP:00007ffcab943910
R8 :0000000000000010 R9 :ffffffffffffffff
R10:00007febea251778 R11:0000000000000080
R12:0000000000000001 R13:00007febd5b98080
R14:00007febd5c2d140 R15:653a5f5f6e6f6974
RIP:00007febea236891 EFL:0000000000010202
CSGSFS:0000000000000033
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab94391f) -> 00007ffcab943a5f
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab94391e) -> 0000000000000006
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab94391d) -> 00007febea23a32f
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab94391c) -> 00007febd698cbb0
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab94391b) -> 00007ffcab943a10
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab94391a) -> 0005fe77fcce2319
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab943919) -> 00007febd5c2d140
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab943918) -> 00007febd6006ac0
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab943917) -> 00007febea236740
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab943916) -> 00007febe91531e0
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab943915) -> 00007febd698ba40
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab943914) -> 00007febd5add500
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab943913) -> 00007febd5b995b0
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab943912) -> 00000000e915c538
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab943911) -> 00007ffcab943a10
20232:M 19 Jun 2023 17:16:19.485 # (00007ffcab943910) -> 00007febe915f538

------ INFO OUTPUT ------

Server

redis_version:6.2.12
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:2f403e6148073f44
redis_mode:standalone
os:Linux 3.10.0-1160.90.1.el7.x86_64 x86_64
arch_bits:64
monotonic_clock:POSIX clock_gettime
multiplexing_api:epoll
atomicvar_api:c11-builtin
gcc_version:10.2.1
process_id:20232
process_supervised:no
run_id:511d833fcf6ecca6c8f1971421f98e4e7a9766ef
tcp_port:6379
server_time_usec:1687166179484441
uptime_in_seconds:66
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:9444579
executable:/usr/local/redis/bin/redis-server
config_file:/usr/local/redis/bin/redis.conf
io_threads_active:0

Clients

connected_clients:3
cluster_connections:0
maxclients:99968
client_recent_max_input_buffer:41000
client_recent_max_output_buffer:48
blocked_clients:0
tracking_clients:0
clients_in_timeout_table:0

Memory

used_memory:100874768
used_memory_human:96.20M
used_memory_rss:112099328
used_memory_rss_human:106.91M
used_memory_peak:105685112
used_memory_peak_human:100.79M
used_memory_peak_perc:95.45%
used_memory_overhead:10460936
used_memory_startup:6259984
used_memory_dataset:90413832
used_memory_dataset_perc:95.56%
allocator_allocated:101258952
allocator_active:101863424
allocator_resident:110850048
total_system_memory:33020231680
total_system_memory_human:30.75G
used_memory_lua:63488
used_memory_lua_human:62.00K
used_memory_scripts:6056
used_memory_scripts_human:5.91K
number_of_cached_scripts:17
maxmemory:26843545600
maxmemory_human:25.00G
maxmemory_policy:noeviction
allocator_frag_ratio:1.01
allocator_frag_bytes:604472
allocator_rss_ratio:1.09
allocator_rss_bytes:8986624
rss_overhead_ratio:1.01
rss_overhead_bytes:1249280
mem_fragmentation_ratio:1.11
mem_fragmentation_bytes:11226960
mem_not_counted_for_evict:0
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:61544
mem_aof_buffer:0
mem_allocator:jemalloc-5.1.0
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:1802
rdb_bgsave_in_progress:0
rdb_last_save_time:1687166174
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:0
rdb_current_bgsave_time_sec:-1
rdb_last_cow_size:10690560
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
aof_last_cow_size:0
module_fork_in_progress:0
module_fork_last_cow_size:0

Stats

total_connections_received:4598
total_commands_processed:38722
instantaneous_ops_per_sec:884
total_net_input_bytes:5400871
total_net_output_bytes:637803
instantaneous_input_kbps:112.54
instantaneous_output_kbps:8.84
rejected_connections:0
sync_full:0
sync_partial_ok:0
sync_partial_err:0
expired_keys:1
expired_stale_perc:0.00
expired_time_cap_reached_count:0
expire_cycle_cpu_milliseconds:2
evicted_keys:0
keyspace_hits:150167
keyspace_misses:5733
pubsub_channels:0
pubsub_patterns:0
latest_fork_usec:3294
total_forks:1
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:68
dump_payload_sanitizations:0
total_reads_processed:39110
total_writes_processed:34455
io_threaded_reads_processed:0
io_threaded_writes_processed:0

Replication

role:master
connected_slaves:0
master_failover_state:no-failover
master_replid:fc9ad30fb2308a46f3e3172a962462d395ce25aa
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:0.460402
used_cpu_user:0.842212
used_cpu_sys_children:0.047405
used_cpu_user_children:0.263251
used_cpu_sys_main_thread:0.458837
used_cpu_user_main_thread:0.838200

Modules

module:name=tairzset,ver=1,api=1,filters=0,usedby=[],using=[],options=[]
module:name=exstrtype,ver=1,api=1,filters=0,usedby=[],using=[],options=[]
module:name=search,ver=20610,api=1,filters=0,usedby=[],using=[],options=[handle-io-errors]
module:name=tairhash,ver=1,api=1,filters=0,usedby=[],using=[],options=[]

Commandstats

cmdstat_hdel:calls=2,usec=10,usec_per_call=5.00,rejected_calls=0,failed_calls=0
cmdstat_zrange:calls=330,usec=1112,usec_per_call=3.37,rejected_calls=0,failed_calls=33
cmdstat_exzrevrange:calls=103,usec=2395,usec_per_call=23.25,rejected_calls=0,failed_calls=0
cmdstat_hexists:calls=1,usec=1,usec_per_call=1.00,rejected_calls=0,failed_calls=0
cmdstat_exhkeys:calls=92,usec=219,usec_per_call=2.38,rejected_calls=0,failed_calls=0
cmdstat_sadd:calls=1,usec=3,usec_per_call=3.00,rejected_calls=0,failed_calls=0
cmdstat_ping:calls=6,usec=3,usec_per_call=0.50,rejected_calls=0,failed_calls=0
cmdstat_expire:calls=4114,usec=4185,usec_per_call=1.02,rejected_calls=0,failed_calls=0
cmdstat_zadd:calls=4115,usec=12736,usec_per_call=3.10,rejected_calls=0,failed_calls=0
cmdstat_scan:calls=228,usec=150756,usec_per_call=661.21,rejected_calls=0,failed_calls=0
cmdstat_del:calls=5107,usec=12174,usec_per_call=2.38,rejected_calls=0,failed_calls=0
cmdstat_select:calls=4595,usec=1009,usec_per_call=0.22,rejected_calls=0,failed_calls=0
cmdstat_info:calls=5,usec=294,usec_per_call=58.80,rejected_calls=0,failed_calls=0
cmdstat_hmset:calls=1,usec=7,usec_per_call=7.00,rejected_calls=0,failed_calls=0
cmdstat_exists:calls=3,usec=3,usec_per_call=1.00,rejected_calls=0,failed_calls=0
cmdstat_ltrim:calls=198,usec=71,usec_per_call=0.36,rejected_calls=0,failed_calls=0
cmdstat_exzadd:calls=33,usec=2872,usec_per_call=87.03,rejected_calls=0,failed_calls=0
cmdstat_set:calls=1418,usec=8012,usec_per_call=5.65,rejected_calls=0,failed_calls=0
cmdstat_exzcard:calls=24,usec=41,usec_per_call=1.71,rejected_calls=0,failed_calls=0
cmdstat_zrem:calls=1,usec=5,usec_per_call=5.00,rejected_calls=0,failed_calls=0
cmdstat_zinterstore:calls=55,usec=6259,usec_per_call=113.80,rejected_calls=0,failed_calls=0
cmdstat_zrevrange:calls=5494,usec=12431,usec_per_call=2.26,rejected_calls=0,failed_calls=0
cmdstat_hlen:calls=13,usec=29,usec_per_call=2.23,rejected_calls=0,failed_calls=0
cmdstat_hget:calls=270,usec=784,usec_per_call=2.90,rejected_calls=0,failed_calls=0
cmdstat_exhset:calls=56,usec=1717,usec_per_call=30.66,rejected_calls=0,failed_calls=0
cmdstat_type:calls=15,usec=52,usec_per_call=3.47,rejected_calls=0,failed_calls=0
cmdstat_ttl:calls=17,usec=47,usec_per_call=2.76,rejected_calls=0,failed_calls=0
cmdstat_hgetall:calls=329,usec=1216,usec_per_call=3.70,rejected_calls=1,failed_calls=0
cmdstat_hvals:calls=66,usec=60,usec_per_call=0.91,rejected_calls=0,failed_calls=0
cmdstat_get:calls=867,usec=1038,usec_per_call=1.20,rejected_calls=0,failed_calls=0
cmdstat_zrangebyscore:calls=616,usec=1276,usec_per_call=2.07,rejected_calls=0,failed_calls=0
cmdstat_smembers:calls=90,usec=476,usec_per_call=5.29,rejected_calls=0,failed_calls=0
cmdstat_eval:calls=2189,usec=43351,usec_per_call=19.80,rejected_calls=0,failed_calls=33
cmdstat_lrange:calls=198,usec=209,usec_per_call=1.06,rejected_calls=0,failed_calls=0
cmdstat_hset:calls=1,usec=14,usec_per_call=14.00,rejected_calls=0,failed_calls=0
cmdstat_client:calls=3,usec=5,usec_per_call=1.67,rejected_calls=0,failed_calls=0
cmdstat_hscan:calls=13,usec=130,usec_per_call=10.00,rejected_calls=0,failed_calls=0
cmdstat_scard:calls=159,usec=395,usec_per_call=2.48,rejected_calls=0,failed_calls=0
cmdstat_zremrangebyrank:calls=1,usec=3,usec_per_call=3.00,rejected_calls=0,failed_calls=0
cmdstat_zcard:calls=186,usec=280,usec_per_call=1.51,rejected_calls=0,failed_calls=0
cmdstat_srem:calls=1,usec=3,usec_per_call=3.00,rejected_calls=0,failed_calls=0
cmdstat_zremrangebyscore:calls=649,usec=987,usec_per_call=1.52,rejected_calls=0,failed_calls=0
cmdstat_spop:calls=2457,usec=2409,usec_per_call=0.98,rejected_calls=0,failed_calls=0
cmdstat_exhdelrepl:calls=1,usec=4,usec_per_call=4.00,rejected_calls=0,failed_calls=0
cmdstat_sscan:calls=1,usec=5,usec_per_call=5.00,rejected_calls=0,failed_calls=0
cmdstat_auth:calls=4598,usec=8298,usec_per_call=1.80,rejected_calls=0,failed_calls=0

Errorstats

errorstat_ERR:count=34
errorstat_LOADING:count=1
errorstat_WRONGTYPE:count=33

Cluster

cluster_enabled:0

Keyspace

db0:keys=75515,expires=1780,avg_ttl=5838460898
db5:keys=8,expires=0,avg_ttl=0
db6:keys=90,expires=0,avg_ttl=0

------ CLIENT LIST OUTPUT ------
id=154 addr=172.16.183.135:44085 laddr=172.16.183.139:6379 fd=7 name=redisinsight-cli-30f24486 age=64 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=73 qbuf-free=40881 argv-mem=32 obl=0 oll=0 omem=0 tot-mem=61520 events=r cmd=exhset user=default redir=-1
id=155 addr=172.16.183.135:44087 laddr=172.16.183.139:6379 fd=9 name=redisinsight-browser-b425b0be age=64 idle=64 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=20512 events=r cmd=client user=default redir=-1
id=11 addr=172.16.183.135:44083 laddr=172.16.183.139:6379 fd=10 name=120.55.39.163@10006 age=65 idle=5 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=20496 events=r cmd=ping user=default redir=-1

------ CURRENT CLIENT INFO ------
id=154 addr=172.16.183.135:44085 laddr=172.16.183.139:6379 fd=7 name=redisinsight-cli-30f24486 age=64 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=73 qbuf-free=40881 argv-mem=32 obl=0 oll=0 omem=0 tot-mem=61520 events=r cmd=exhset user=default redir=-1
argv[0]: 'exhset'
argv[1]: 'rroom_demotion'
argv[2]: '1049_1'
argv[3]: 'abc'
argv[4]: 'EX'
argv[5]: '0'
20232:M 19 Jun 2023 17:16:19.486 # key 'rroom_demotion' found in DB containing the following object:
20232:M 19 Jun 2023 17:16:19.486 # Object type: 5
20232:M 19 Jun 2023 17:16:19.486 # Object encoding: 0
20232:M 19 Jun 2023 17:16:19.486 # Object refcount: 1

------ MODULES INFO OUTPUT ------

search_version

search_version:2.6.10
search_redis_version:6.2.12 - oss

search_index

search_number_of_indexes:0

search_fields_statistics

search_dialect_statistics

search_dialect_1:0
search_dialect_2:0
search_dialect_3:0

search_runtime_configurations

search_concurrent_mode:OFF
search_enableGC:ON
search_minimal_term_prefix:2
search_maximal_prefix_expansions:200
search_query_timeout_ms:500
search_timeout_policy:return
search_cursor_read_size:1000
search_cursor_max_idle_time:300000
search_max_doc_table_size:1000000
search_max_search_results:1000000
search_max_aggregate_results:-1
search_search_pool_size:20
search_index_pool_size:8
search_gc_scan_size:100
search_min_phonetic_term_length:3

------ FAST MEMORY TEST ------
20232:M 19 Jun 2023 17:16:19.486 # Bio thread for job type #0 terminated
20232:M 19 Jun 2023 17:16:19.486 # Bio thread for job type #1 terminated
20232:M 19 Jun 2023 17:16:19.486 # Bio thread for job type #2 terminated
20232:M 19 Jun 2023 17:16:19.486 # IO thread(tid:140651036468992) terminated
20232:M 19 Jun 2023 17:16:19.486 # IO thread(tid:140651028076288) terminated
20232:M 19 Jun 2023 17:16:19.486 # IO thread(tid:140651019683584) terminated
20232:M 19 Jun 2023 17:16:19.486 # IO thread(tid:140651011290880) terminated
20232:M 19 Jun 2023 17:16:19.486 # IO thread(tid:140651002898176) terminated
20232:M 19 Jun 2023 17:16:19.486 # IO thread(tid:140650994505472) terminated
20232:M 19 Jun 2023 17:16:19.486 # IO thread(tid:140650986112768) terminated
*** Preparing to test memory region 5f8000 (446464 bytes)
*** Preparing to test memory region 10fa000 (135168 bytes)
*** Preparing to test memory region 111b000 (135168 bytes)
*** Preparing to test memory region 7febd4f00000 (95420416 bytes)
*** Preparing to test memory region 7febdab07000 (6291456 bytes)
*** Preparing to test memory region 7febdb108000 (8388608 bytes)
*** Preparing to test memory region 7febdb909000 (8388608 bytes)
*** Preparing to test memory region 7febdc10a000 (8388608 bytes)
*** Preparing to test memory region 7febdc90b000 (8388608 bytes)
*** Preparing to test memory region 7febdd10c000 (8388608 bytes)
*** Preparing to test memory region 7febe0913000 (8388608 bytes)
*** Preparing to test memory region 7febe1114000 (8388608 bytes)
*** Preparing to test memory region 7febe1fb7000 (24576 bytes)
*** Preparing to test memory region 7febe1fbd000 (9437184 bytes)
*** Preparing to test memory region 7febe8e00000 (4194304 bytes)
*** Preparing to test memory region 7febe9713000 (20480 bytes)
*** Preparing to test memory region 7febe9930000 (16384 bytes)
*** Preparing to test memory region 7febea250000 (4096 bytes)
*** Preparing to test memory region 7febea251000 (20480 bytes)
*** Preparing to test memory region 7febea261000 (4096 bytes)
*** Preparing to test memory region 7febea262000 (4096 bytes)
*** Preparing to test memory region 7febea265000 (4096 bytes)
.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.

[sndwow]

使用的是release-v1.0.0-20230215版本，已经确定为tairHash导致的崩溃

[sndwow]

复现方式为：exhset room key abc EX 0
部分场景下有过期时间为0的情况，该命令被多次执行的时候redis崩溃

[sndwow]

再次每次测试之后发现，并非 EX 0 的时候才会出现，有时候其他情况也会出现，比如EX 120 或者 EX 50。
测试的场景是频繁接口请求去设置更改某个field的内容和EX值

[chenyang8094]

再次每次测试之后发现，并非 EX 0 的时候才会出现，有时候其他情况也会出现，比如EX 120 或者 EX 50。 测试的场景是频繁接口请求去设置更改某个field的内容和EX值

你好，请问你用的是什么模式？还有，你是否开启了coredump，有的话把coredump信息也贴一下。