Notice! - If a Redis module was involved, please open an issue in the module's repo instead! - If you're using docker on Apple M1, please make sure the image you're using was compiled for ARM!

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

537283:M 20 Nov 2023 12:31:18.005 * Background saving started by pid 741186
741186:C 20 Nov 2023 12:31:32.883 * DB saved on disk
741186:C 20 Nov 2023 12:31:33.041 * Fork CoW for RDB: current 89 MB, peak 89 MB, average 59 MB
537283:M 20 Nov 2023 12:31:33.273 * Background saving terminated with success
537283:M 20 Nov 2023 12:33:34.073 * 10000 changes in 120 seconds. Saving...
537283:M 20 Nov 2023 12:33:34.340 * Background saving started by pid 743130
743130:C 20 Nov 2023 12:33:49.702 * DB saved on disk
743130:C 20 Nov 2023 12:33:49.845 * Fork CoW for RDB: current 77 MB, peak 77 MB, average 47 MB
537283:M 20 Nov 2023 12:33:50.101 * Background saving terminated with success
537283:M 20 Nov 2023 12:35:51.097 * 10000 changes in 120 seconds. Saving...
537283:M 20 Nov 2023 12:35:51.338 * Background saving started by pid 744548
744548:C 20 Nov 2023 12:36:05.883 * DB saved on disk
744548:C 20 Nov 2023 12:36:06.047 * Fork CoW for RDB: current 107 MB, peak 107 MB, average 59 MB
537283:M 20 Nov 2023 12:36:06.381 * Background saving terminated with success

=== REDIS BUG REPORT START: Cut & paste starting from here ===
537283:M 20 Nov 2023 12:36:42.435 # === ASSERTION FAILED ===
537283:M 20 Nov 2023 12:36:42.435 # ==> networking.c:1480 'io_threads_op == IO_THREADS_OP_IDLE' is not true

------ STACK TRACE ------

Backtrace:
/home/redis/redis-work/redis_sentinel_prod/redis-6.0.10/src/redis-server 0.0.0.0:6379(unlinkClient+0x221)[0x542dd1]
/home/redis/redis-work/redis_sentinel_prod/redis-6.0.10/src/redis-server 0.0.0.0:6379(freeClient+0x263)[0x543053]
/home/redis/redis-work/redis_sentinel_prod/redis-6.0.10/src/redis-server 0.0.0.0:6379(RM_FreeThreadSafeContext+0x9)[0x497cf9]
/home/redis/redis-work/redis_sentinel_prod/data/modules/redisearch.so(+0x157142)[0x7fffe8eec142]
/lib64/libpthread.so.0(+0x81ca)[0x7ffff74281ca]
/lib64/libc.so.6(clone+0x43)[0x7ffff7094e73]

------ INFO OUTPUT ------
# Server
redis_version:7.2.3
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:b77510c9559a2463
redis_mode:standalone
os:Linux 5.15.128-1 x86_64
arch_bits:64
monotonic_clock:POSIX clock_gettime
multiplexing_api:epoll
atomicvar_api:c11-builtin
gcc_version:8.5.0
process_id:537283
process_supervised:no
run_id:1dd4d12c8e661a13c31ee400fb9548b8b071bb15
tcp_port:6379
server_time_usec:1700483802438266
uptime_in_seconds:18688
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:5984986
executable:/home/redis/redis-work/redis_sentinel_prod/redis-6.0.10/src/redis-server
config_file:/home/redis/redis-work/redis_sentinel_prod/data/redis.conf
io_threads_active:0
listener0:name=tcp,bind=0.0.0.0,port=6379

# Clients
connected_clients:1271
cluster_connections:0
maxclients:10000
client_recent_max_input_buffer:20480
client_recent_max_output_buffer:20504
blocked_clients:0
tracking_clients:0
clients_in_timeout_table:0
total_blocking_keys:0
total_blocking_keys_on_nokey:0

# Memory
used_memory:8048754928
used_memory_human:7.50G
used_memory_rss:8188547072
used_memory_rss_human:7.63G
used_memory_peak:8069676160
used_memory_peak_human:7.52G
used_memory_peak_perc:99.74%
used_memory_overhead:799139696
used_memory_startup:1013888
used_memory_dataset:7249615232
used_memory_dataset_perc:90.08%
allocator_allocated:8050302064
allocator_active:8062902272
allocator_resident:8210100224
total_system_memory:675916099584
total_system_memory_human:629.50G
used_memory_lua:31744
used_memory_vm_eval:31744
used_memory_lua_human:31.00K
used_memory_scripts_eval:0
number_of_cached_scripts:0
number_of_functions:0
number_of_libraries:0
used_memory_vm_functions:32768
used_memory_vm_total:64512
used_memory_vm_total_human:63.00K
used_memory_functions:184
used_memory_scripts:184
used_memory_scripts_human:184B
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
allocator_frag_ratio:1.00
allocator_frag_bytes:12600208
allocator_rss_ratio:1.02
allocator_rss_bytes:147197952
rss_overhead_ratio:1.00
rss_overhead_bytes:-21553152
mem_fragmentation_ratio:1.02
mem_fragmentation_bytes:139794344
mem_not_counted_for_evict:0
mem_replication_backlog:536877608
mem_total_replication_buffers:538578568
mem_clients_slaves:1707656
mem_clients_normal:5342864
mem_cluster_links:0
mem_aof_buffer:0
mem_allocator:jemalloc-5.3.0
active_defrag_running:0
lazyfree_pending_objects:0
lazyfreed_objects:38832

# Persistence
loading:0
async_loading:0
current_cow_peak: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:594639
rdb_bgsave_in_progress:0
rdb_last_save_time:1700483766
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:15
rdb_current_bgsave_time_sec:-1
rdb_saves:132
rdb_last_cow_size:112558080
rdb_last_load_keys_expired:0
rdb_last_load_keys_loaded:4528642
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_rewrites:0
aof_rewrites_consecutive_failures:0
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:110338
total_commands_processed:208696312
instantaneous_ops_per_sec:16425
total_net_input_bytes:25081856113
total_net_output_bytes:70074403043
total_net_repl_input_bytes:10317696255
total_net_repl_output_bytes:68010887862
instantaneous_input_kbps:1483.00
instantaneous_output_kbps:5972.07
instantaneous_input_repl_kbps:0.00
instantaneous_output_repl_kbps:5792.23
rejected_connections:0
sync_full:7
sync_partial_ok:4
sync_partial_err:7
expired_keys:358322
expired_stale_perc:8.37
expired_time_cap_reached_count:0
expire_cycle_cpu_milliseconds:9590
evicted_keys:0
evicted_clients:0
total_eviction_exceeded_time:0
current_eviction_exceeded_time:0
keyspace_hits:40088603
keyspace_misses:3758315
pubsub_channels:1
pubsub_patterns:47
pubsubshard_channels:0
latest_fork_usec:241026
total_forks:147
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
total_active_defrag_time:0
current_active_defrag_time:0
tracking_total_keys:0
tracking_total_items:0
tracking_total_prefixes:0
unexpected_error_replies:0
total_error_replies:34396
dump_payload_sanitizations:0
total_reads_processed:22124514
total_writes_processed:61381759
io_threaded_reads_processed:0
io_threaded_writes_processed:7858076
reply_buffer_shrinks:119429
reply_buffer_expands:11937
eventloop_cycles:19983213
eventloop_duration_sum:2739313376
eventloop_duration_cmd_sum:1313002872
instantaneous_eventloop_cycles_per_sec:1278
instantaneous_eventloop_duration_usec:115
acl_access_denied_auth:2
acl_access_denied_cmd:0
acl_access_denied_key:0
acl_access_denied_channel:0

# Replication
role:master
connected_slaves:4
slave0:ip=x.x.x.158,port=6379,state=online,offset=30411739454607,lag=1
slave1:ip=x.x.x.154,port=6379,state=online,offset=30411739711643,lag=1
slave2:ip=x.x.x.157,port=6379,state=online,offset=30411739702090,lag=1
slave3:ip=x.x.x.155,port=6379,state=online,offset=30411741371519,lag=0
master_failover_state:no-failover
master_replid:bf0f70b9a1592a3516fe5cfe52bcb2c29ab85841
master_replid2:3b185c49ed5edf6f3be0e605578303dd4384ae9f
master_repl_offset:30411741418999
second_repl_offset:30399789302774
repl_backlog_active:1
repl_backlog_size:536870912
repl_backlog_first_byte_offset:30411204535235
repl_backlog_histlen:536883765

# CPU
used_cpu_sys:722.041706
used_cpu_user:5928.805942
used_cpu_sys_children:483.488326
used_cpu_user_children:1503.562858
used_cpu_sys_main_thread:2.313608
used_cpu_user_main_thread:0.598206

# Modules
module:name=ReJSON,ver=999999,api=1,filters=0,usedby=[search],using=[],options=[handle-io-errors]
module:name=search,ver=999999,api=1,filters=0,usedby=[],using=[ReJSON],options=[]

# Commandstats
cmdstat_command:calls=0,usec=0,usec_per_call=0.00,rejected_calls=6,failed_calls=0
cmdstat_command|docs:calls=0,usec=0,usec_per_call=0.00,rejected_calls=6,failed_calls=0
cmdstat_expireat:calls=34960342,usec=27372525,usec_per_call=0.78,rejected_calls=0,failed_calls=0
cmdstat_sadd:calls=15,usec=366,usec_per_call=24.40,rejected_calls=0,failed_calls=0
cmdstat_exists:calls=70150,usec=69602,usec_per_call=0.99,rejected_calls=0,failed_calls=0
cmdstat_monitor:calls=1,usec=0,usec_per_call=0.00,rejected_calls=0,failed_calls=0
cmdstat_exec:calls=450,usec=13616,usec_per_call=30.26,rejected_calls=0,failed_calls=442
cmdstat_multi:calls=12809094,usec=715650,usec_per_call=0.06,rejected_calls=0,failed_calls=0
cmdstat_slaveof:calls=8,usec=816,usec_per_call=102.00,rejected_calls=442,failed_calls=0
cmdstat_del:calls=150020,usec=2509648,usec_per_call=16.73,rejected_calls=0,failed_calls=0
cmdstat_info:calls=27955,usec=1770259,usec_per_call=63.33,rejected_calls=2,failed_calls=0
cmdstat_module|list:calls=3,usec=10,usec_per_call=3.33,rejected_calls=0,failed_calls=0
cmdstat_FT._LIST:calls=3,usec=250,usec_per_call=83.33,rejected_calls=0,failed_calls=0
cmdstat_hmget:calls=311395,usec=1296654,usec_per_call=4.16,rejected_calls=0,failed_calls=0
cmdstat_ping:calls=496669,usec=472628,usec_per_call=0.95,rejected_calls=4373,failed_calls=0
cmdstat_config|rewrite:calls=8,usec=9455,usec_per_call=1181.88,rejected_calls=0,failed_calls=0
cmdstat_config|get:calls=1,usec=9,usec_per_call=9.00,rejected_calls=0,failed_calls=0
cmdstat_hincrby:calls=35708499,usec=89126566,usec_per_call=2.50,rejected_calls=0,failed_calls=0
cmdstat_publish:calls=93599,usec=735862,usec_per_call=7.86,rejected_calls=0,failed_calls=0
cmdstat_json.del:calls=3,usec=286,usec_per_call=95.33,rejected_calls=0,failed_calls=0
cmdstat_pexpireat:calls=12612584,usec=7362243,usec_per_call=0.58,rejected_calls=0,failed_calls=0
cmdstat_acl|users:calls=2,usec=7,usec_per_call=3.50,rejected_calls=0,failed_calls=0
cmdstat_acl|getuser:calls=6,usec=1818,usec_per_call=303.00,rejected_calls=0,failed_calls=0
cmdstat_acl|list:calls=1,usec=9,usec_per_call=9.00,rejected_calls=0,failed_calls=0
cmdstat_acl|setuser:calls=4,usec=621,usec_per_call=155.25,rejected_calls=0,failed_calls=0
cmdstat_hmset:calls=47559,usec=7206050,usec_per_call=151.52,rejected_calls=0,failed_calls=0
cmdstat_psync:calls=61,usec=1152,usec_per_call=18.89,rejected_calls=0,failed_calls=50
cmdstat_hset:calls=53372583,usec=39902160,usec_per_call=0.75,rejected_calls=0,failed_calls=0
cmdstat_zrevrange:calls=3199,usec=16668,usec_per_call=5.21,rejected_calls=0,failed_calls=0
cmdstat_select:calls=312,usec=701,usec_per_call=2.25,rejected_calls=0,failed_calls=0
cmdstat_discard:calls=12808644,usec=1097151,usec_per_call=0.09,rejected_calls=0,failed_calls=0
cmdstat_latency:calls=0,usec=0,usec_per_call=0.00,rejected_calls=1,failed_calls=0
cmdstat_latency|doctor:calls=1,usec=204278,usec_per_call=204278.00,rejected_calls=0,failed_calls=0
cmdstat_latency|latest:calls=1,usec=1,usec_per_call=1.00,rejected_calls=0,failed_calls=0
cmdstat_latency|help:calls=1,usec=10,usec_per_call=10.00,rejected_calls=1,failed_calls=0
cmdstat_json.set:calls=1963,usec=379191,usec_per_call=193.17,rejected_calls=0,failed_calls=0
cmdstat_expire:calls=29,usec=155,usec_per_call=5.34,rejected_calls=0,failed_calls=0
cmdstat_set:calls=364098,usec=533075,usec_per_call=1.46,rejected_calls=2664,failed_calls=0
cmdstat_FT.INFO:calls=135,usec=12141,usec_per_call=89.93,rejected_calls=0,failed_calls=0
cmdstat_keys:calls=782,usec=1008826325,usec_per_call=1290059.25,rejected_calls=0,failed_calls=0
cmdstat_hincrbyfloat:calls=40430858,usec=108784200,usec_per_call=2.69,rejected_calls=0,failed_calls=0
cmdstat_auth:calls=109822,usec=275117,usec_per_call=2.51,rejected_calls=0,failed_calls=2
cmdstat_json.get:calls=525330,usec=6220199,usec_per_call=11.84,rejected_calls=0,failed_calls=842
cmdstat_client|setinfo:calls=338,usec=687,usec_per_call=2.03,rejected_calls=0,failed_calls=0
cmdstat_client|setname:calls=240,usec=235,usec_per_call=0.98,rejected_calls=0,failed_calls=0
cmdstat_client|id:calls=1,usec=1,usec_per_call=1.00,rejected_calls=0,failed_calls=0
cmdstat_client|kill:calls=16,usec=2909,usec_per_call=181.81,rejected_calls=0,failed_calls=0
cmdstat_quit:calls=98361,usec=135376,usec_per_call=1.38,rejected_calls=0,failed_calls=0
cmdstat_subscribe:calls=90,usec=135,usec_per_call=1.50,rejected_calls=0,failed_calls=0
cmdstat_replconf:calls=47434,usec=45528,usec_per_call=0.96,rejected_calls=0,failed_calls=0
cmdstat_psubscribe:calls=7234,usec=26484,usec_per_call=3.66,rejected_calls=0,failed_calls=0
cmdstat_FT.SEARCH:calls=77,usec=6867385,usec_per_call=89186.82,rejected_calls=0,failed_calls=0
cmdstat_get:calls=3636331,usec=1019870,usec_per_call=0.28,rejected_calls=25563,failed_calls=0

# Errorstats
errorstat_ERR:count=846
errorstat_EXECABORT:count=442
errorstat_LOADING:count=4752
errorstat_NOAUTH:count=28304
errorstat_NOMASTERLINK:count=50
errorstat_WRONGPASS:count=2

# Latencystats
latency_percentiles_usec_expireat:p50=1.003,p99=2.007,p99.9=9.023
latency_percentiles_usec_sadd:p50=9.023,p99=209.919,p99.9=209.919
latency_percentiles_usec_exists:p50=0.001,p99=10.047,p99.9=41.215
latency_percentiles_usec_monitor:p50=0.001,p99=0.001,p99.9=0.001
latency_percentiles_usec_exec:p50=0.001,p99=856.063,p99.9=4521.983
latency_percentiles_usec_multi:p50=0.001,p99=1.003,p99.9=1.003
latency_percentiles_usec_slaveof:p50=59.135,p99=238.591,p99.9=238.591
latency_percentiles_usec_del:p50=10.047,p99=138.239,p99.9=405.503
latency_percentiles_usec_info:p50=34.047,p99=477.183,p99.9=1261.567
latency_percentiles_usec_module|list:p50=3.007,p99=4.015,p99.9=4.015
latency_percentiles_usec_FT._LIST:p50=91.135,p99=110.079,p99.9=110.079
latency_percentiles_usec_hmget:p50=3.007,p99=19.071,p99.9=74.239
latency_percentiles_usec_ping:p50=1.003,p99=8.031,p99.9=38.143
latency_percentiles_usec_config|rewrite:p50=675.839,p99=3014.655,p99.9=3014.655
latency_percentiles_usec_config|get:p50=9.023,p99=9.023,p99.9=9.023
latency_percentiles_usec_hincrby:p50=2.007,p99=15.039,p99.9=62.207
latency_percentiles_usec_publish:p50=2.007,p99=78.335,p99.9=321.535
latency_percentiles_usec_json.del:p50=112.127,p99=112.127,p99.9=112.127
latency_percentiles_usec_pexpireat:p50=1.003,p99=2.007,p99.9=7.007
latency_percentiles_usec_acl|users:p50=2.007,p99=5.023,p99.9=5.023
latency_percentiles_usec_acl|getuser:p50=107.007,p99=884.735,p99.9=884.735
latency_percentiles_usec_acl|list:p50=9.023,p99=9.023,p99.9=9.023
latency_percentiles_usec_acl|setuser:p50=126.463,p99=317.439,p99.9=317.439
latency_percentiles_usec_hmset:p50=116.223,p99=643.071,p99.9=1409.023
latency_percentiles_usec_psync:p50=6.015,p99=102.399,p99.9=112.127
latency_percentiles_usec_hset:p50=1.003,p99=3.007,p99.9=14.015
latency_percentiles_usec_zrevrange:p50=3.007,p99=45.055,p99.9=184.319
latency_percentiles_usec_select:p50=2.007,p99=15.039,p99.9=22.015
latency_percentiles_usec_discard:p50=0.001,p99=1.003,p99.9=3.007
latency_percentiles_usec_latency|doctor:p50=204472.319,p99=204472.319,p99.9=204472.319
latency_percentiles_usec_latency|latest:p50=1.003,p99=1.003,p99.9=1.003
latency_percentiles_usec_latency|help:p50=10.047,p99=10.047,p99.9=10.047
latency_percentiles_usec_json.set:p50=96.255,p99=1531.903,p99.9=5275.647
latency_percentiles_usec_expire:p50=2.007,p99=38.143,p99.9=38.143
latency_percentiles_usec_set:p50=1.003,p99=10.047,p99.9=33.023
latency_percentiles_usec_FT.INFO:p50=56.063,p99=933.887,p99.9=1105.919
latency_percentiles_usec_keys:p50=1002438.655,p99=1002438.655,p99.9=1002438.655
latency_percentiles_usec_hincrbyfloat:p50=2.007,p99=8.031,p99.9=30.079
latency_percentiles_usec_auth:p50=2.007,p99=15.039,p99.9=73.215
latency_percentiles_usec_json.get:p50=5.023,p99=119.295,p99.9=634.879
latency_percentiles_usec_client|setinfo:p50=1.003,p99=19.071,p99.9=31.103
latency_percentiles_usec_client|setname:p50=0.001,p99=15.039,p99.9=17.023
latency_percentiles_usec_client|id:p50=1.003,p99=1.003,p99.9=1.003
latency_percentiles_usec_client|kill:p50=63.231,p99=1490.943,p99.9=1490.943
latency_percentiles_usec_quit:p50=1.003,p99=13.055,p99.9=54.015
latency_percentiles_usec_subscribe:p50=1.003,p99=11.007,p99.9=18.047
latency_percentiles_usec_replconf:p50=0.001,p99=12.031,p99.9=37.119
latency_percentiles_usec_psubscribe:p50=2.007,p99=34.047,p99.9=89.087
latency_percentiles_usec_FT.SEARCH:p50=1187.839,p99=1002438.655,p99.9=1002438.655
latency_percentiles_usec_get:p50=0.001,p99=3.007,p99.9=11.007

# Cluster
cluster_enabled:0

# Keyspace
db0:keys=4543953,expires=134720,avg_ttl=13214743
db1:keys=2,expires=0,avg_ttl=0

------ MODULES INFO OUTPUT ------
# ReJSON_trace
ReJSON_trace:   0: redis_module::base_info_func
   1: rejson::__info_func
   2: modulesCollectInfo
             at /data/clickhouse/redis-work/redis_sentinel_prod/redis-7.2.3/src/module.c:10293:9
   3: logModulesInfo
             at /data/clickhouse/redis-work/redis_sentinel_prod/redis-7.2.3/src/debug.c:1900:22
      printCrashReport
             at /data/clickhouse/redis-work/redis_sentinel_prod/redis-7.2.3/src/debug.c:2183:5
   4: _serverAssert
             at /data/clickhouse/redis-work/redis_sentinel_prod/redis-7.2.3/src/debug.c:1062:9
   5: unlinkClient
             at /data/clickhouse/redis-work/redis_sentinel_prod/redis-7.2.3/src/networking.c:1480:5
   6: freeClient
             at /data/clickhouse/redis-work/redis_sentinel_prod/redis-7.2.3/src/networking.c:1636:5
   7: RM_FreeThreadSafeContext
             at /data/clickhouse/redis-work/redis_sentinel_prod/redis-7.2.3/src/module.c:8450:5
   8: thread_do
   9: start_thread
  10: clone


# search_version
search_version:99.99.99
search_redis_version:7.2.3 - oss

# search_index
search_number_of_indexes:45

# search_fields_statistics
search_fields_text:Text=211,Sortable=14,NoIndex=35
search_fields_numeric:Numeric=96,Sortable=55
search_fields_tag:Tag=13,Sortable=9

# search_dialect_statistics
search_dialect_1:1
search_dialect_2:0
search_dialect_3:0
search_dialect_4: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:30000
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:-1
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

------ CONFIG DEBUG OUTPUT ------
replica-read-only yes
lazyfree-lazy-expire no
lazyfree-lazy-user-del no
slave-read-only yes
lazyfree-lazy-eviction no
lazyfree-lazy-server-del no
lazyfree-lazy-user-flush no
io-threads 3
sanitize-dump-payload no
proto-max-bulk-len 512mb
client-query-buffer-limit 1gb
list-compress-depth 0
activedefrag no
repl-diskless-sync yes
io-threads-do-reads no
repl-diskless-load disabled

------ FAST MEMORY TEST ------
537283:M 20 Nov 2023 12:36:42.478 # main thread terminated
537283:M 20 Nov 2023 12:36:42.479 # Bio worker thread #0 terminated
537283:M 20 Nov 2023 12:36:42.479 # Bio worker thread #1 terminated
537283:M 20 Nov 2023 12:36:42.482 # Bio worker thread #2 terminated
537283:M 20 Nov 2023 12:36:42.485 # IO thread(tid:140737057978112) terminated
537283:M 20 Nov 2023 12:36:42.486 # IO thread(tid:140737049585408) terminated

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

       Please report the crash by opening an issue on github:

           http://github.com/redis/redis/issues

  If a Redis module was involved, please open in the module's repo instead.

  Suspect RAM error? Use redis-server --test-memory to verify it.

  Some other issues could be detected by redis-server --check-system
744888:C 20 Nov 2023 12:36:43.714 # WARNING Memory overcommit must be enabled! Without it, a background save or replication may fail under low memory condition. Being disabled, it can also cause failures without low memory condition, see https://github.com/jemalloc/jemalloc/issues/1328. 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.
744889:C 20 Nov 2023 12:36:43.715 * oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo

Additional information

Redis Version: 7.2.3 OS: Rocky Linux release 8.8 Redis Mode: Standalone Configuration: 5 nodes with sentinel running on each

Comment From: rishinair19

Is this because of redisearch module?

Comment From: sundb

@rishinair19 Thx, It's possible that it's not due to redisearch module. Like follow example: The example has reproduced the crash locally.

config

io-threads 4
diff --git a/tests/modules/blockedclient.c b/tests/modules/blockedclient.c
index 92060fd33..7d0e044b9 100644
--- a/tests/modules/blockedclient.c
+++ b/tests/modules/blockedclient.c
@@ -30,21 +30,21 @@ void *sub_worker(void *arg) {

 void *worker(void *arg) {
     // Retrieve blocked client
-    RedisModuleBlockedClient *bc = (RedisModuleBlockedClient *)arg;
+    // RedisModuleBlockedClient *bc = (RedisModuleBlockedClient *)arg;

     // Get Redis module context
-    RedisModuleCtx *ctx = RedisModule_GetThreadSafeContext(bc);
+    RedisModuleCtx *ctx = RedisModule_GetThreadSafeContext(NULL);

     // Acquire GIL
     RedisModule_ThreadSafeContextLock(ctx);

     // Create another thread which will try to acquire the GIL
-    pthread_t tid;
-    int res = pthread_create(&tid, NULL, sub_worker, ctx);
-    assert(res == 0);
+    // pthread_t tid;
+    // int res = pthread_create(&tid, NULL, sub_worker, ctx);
+    // assert(res == 0);

     // Wait for thread
-    pthread_join(tid, NULL);
+    // pthread_join(tid, NULL);

     // Release GIL
     RedisModule_ThreadSafeContextUnlock(ctx);
@@ -53,7 +53,7 @@ void *worker(void *arg) {
     RedisModule_ReplyWithSimpleString(ctx, "OK");

     // Unblock client
-    RedisModule_UnblockClient(bc, NULL);
+    // RedisModule_UnblockClient(bc, NULL);

     // Free the Redis module context
     RedisModule_FreeThreadSafeContext(ctx);
@@ -66,7 +66,7 @@ int acquire_gil(RedisModuleCtx *ctx, RedisModuleString **argv, int argc)
     UNUSED(argv);
     UNUSED(argc);

-    int flags = RedisModule_GetContextFlags(ctx);
+    /* int flags = RedisModule_GetContextFlags(ctx);
     int allFlags = RedisModule_GetContextFlagsAll();
     if ((allFlags & REDISMODULE_CTX_FLAGS_MULTI) &&
         (flags & REDISMODULE_CTX_FLAGS_MULTI)) {
@@ -78,19 +78,20 @@ int acquire_gil(RedisModuleCtx *ctx, RedisModuleString **argv, int argc)
         (flags & REDISMODULE_CTX_FLAGS_DENY_BLOCKING)) {
         RedisModule_ReplyWithSimpleString(ctx, "Blocked client is not allowed");
         return REDISMODULE_OK;
-    }
+    } */

     /* This command handler tries to acquire the GIL twice
      * once in the worker thread using "RedisModule_ThreadSafeContextLock"
      * second in the sub-worker thread
      * using "RedisModule_ThreadSafeContextTryLock"
      * as the GIL is already locked. */
-    RedisModuleBlockedClient *bc = RedisModule_BlockClient(ctx, NULL, NULL, NULL, 0);
+    // RedisModuleBlockedClient *bc = RedisModule_BlockClient(ctx, NULL, NULL, NULL, 0);

     pthread_t tid;
-    int res = pthread_create(&tid, NULL, worker, bc);
+    int res = pthread_create(&tid, NULL, worker, NULL);
     assert(res == 0);

+    RedisModule_ReplyWithSimpleString(ctx, "OK");
     return REDISMODULE_OK;
 }
./src/redis-benchmark -n 100000000 acquire_gil

when call RedisModule_FreeThreadSafeContext() and free client after RedisModule_ThreadSafeContextUnlock(), it's possible to trigger this assertion. ping @oranagra

Comment From: rishinair19

I had increased 'io-threads' in redis.conf to 3, reverted that change to default value and so far issue has not re-occurred.

Comment From: sundb

@rishinair19 Yes, it will only occur whenio-threads is turned on.

Comment From: rishinair19

Should I close this request then? I'm okay with io-thread being 1, not seeing issue anymore.

Comment From: sundb

@rishinair19 Please leave this issue open and we will fix it.

Comment From: oranagra

the thing is that the (fake) client is freed while the GIL is not locked, so this assertion could happen, and we can probably easily fix it by moving the code that handles clients_pending_write_node and pending_read_list_node into the if (c->conn) block (since this fake client will never have any IO anyway). but also other portions of unlinkClient can be dangerous to run. like removing it from unblocked_clients, the code in disableTracking, stat_clients_type_memory, etc. @MeirShpilraien PTAL

Comment From: MeirShpilraien

So I was looking at the code and I believe the only issue is if allocating a thread safe ctx which is not attached to a blocked client. If the thread safe context is attached to a blocked client then when releasing it, the freeClient will not be called. After a discussion with @oranagra we believe that the right thing to do is to refactor freeClient function in such way that all the server data structures will only be touched if there is actually a connection attached to the client. If there are not connection attached to the client, it can safely be freed without touching any server globals and so it will be safe to free it without holding the GIL.

Comment From: oranagra

few additional points: 1. stressing again that this is not just a but with IO threads (the assertion), there are multi-threading issues here with module threads touching server globals without a lock. 2. some of the actions in freeClient or unlinkClient can depend on c->conn being present, others can depend on the value of c->flags (doing things only if a certain flag is on, which could never happen for these fake clients). 3. i'd like to try to understand when this problem started, which version, or under which conditions.

@sundb maybe you want to try to tackle it?

Comment From: sundb

@oranagra i'll take it.

Comment From: sundb

FYI @oranagra @MeirShpilraien why RedisModule_Reply*() family API is out of lock, it is not thread-safe. when the thread safe context is attached to a blocked client, RedisModule_Reply*() will end up in the following call chain: RedisModule_Reply*() -> _addReplyProtoToList() -> closeClientOnOutputBufferLimitReached() we will touch server.stat_client_outbuf_limit_disconnections,server.client_obuf_limits and server.repl_backlog_size.

Comment From: MeirShpilraien

@sundb I believe that closeClientOnOutputBufferLimitReached will only do that if there is an actual connection on the client which I believe this is not the case with blocked client, am I missing something?

Comment From: sundb

@MeirShpilraien Ooh, I missed the if (!c->conn) in the closeClientOnOutputBufferLimitReached(), thanks.

Comment From: bossajie

is this also related to this error? When we turned it off, this error is not showing anymore.

Redis [CRASH] Redis crashing on 7.2.3 version

Comment From: sundb

@bossajie Yes, this fix is still in progress.