RSCoordinator icon indicating copy to clipboard operation
RSCoordinator copied to clipboard
verified publisher icon RediSearch

Crash if create cluster with module loaded

Open pnthai88 opened this issue 4 years ago • 0 comments

If create new cluster with module loaded, all replica(s) crash I'm working on a trick by not load module while creating cluster and load it later


8:C 19 Oct 2021 16:54:03.100 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo

8:C 19 Oct 2021 16:54:03.100 # Redis version=6.2.6, bits=64, commit=00000000, modified=0, pid=8, just started

8:C 19 Oct 2021 16:54:03.100 # Configuration loaded

8:M 19 Oct 2021 16:54:03.101 * monotonic clock: POSIX clock_gettime

8:M 19 Oct 2021 16:54:03.102 * No cluster configuration found, I'm d12496ccd71ba0e5ed952db734d4980e6109a98a

8:M 19 Oct 2021 16:54:03.104 * Running mode=cluster, port=6388.

8:M 19 Oct 2021 16:54:03.105 # Server initialized

RSValue size: 16

8:M 19 Oct 2021 16:54:03.107 * <search> redis version observed by redisearch : 6.2.6

8:M 19 Oct 2021 16:54:03.107 * <search> Redis version found by RedisSearch : 6.2.6 - oss

8:M 19 Oct 2021 16:54:03.107 * <search> RediSearch version 2.0.12 (Git=Up-722-ga7f2d75b)

8:M 19 Oct 2021 16:54:03.107 * <search> Low level api version 1 initialized successfully

8:M 19 Oct 2021 16:54:03.107 * <search> concurrent writes: OFF, gc: ON, prefix min length: 2, prefix max expansions: 200, query timeout (ms): 500, timeout policy: return, cursor read size: 1000, cursor max idle (ms): 300000, max doctable size: 1000000, max number of search results:  1000000, search pool size: 20, index pool size: 8, 

8:M 19 Oct 2021 16:54:03.107 * <search> Initialized thread pool!

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed DictRegister

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed TrieType_Register

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed IndexSpec_RegisterType

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed TagIndex_RegisterType

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed InvertedIndex_RegisterType

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed NumericIndexType_Register

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 - <search> Successfully executed RedisModule_CreateCommand

8:M 19 Oct 2021 16:54:03.107 * <search> Cluster configuration: 0 partitions, type: 0, coordinator timeout: 0ms

Creating thread...

Thread created

8:M 19 Oct 2021 16:54:03.108 * <search> Register write commands

8:M 19 Oct 2021 16:54:03.108 * Module 'search' loaded from /plugin/oss-module.so

8:M 19 Oct 2021 16:54:03.109 * Ready to accept connections

8:M 19 Oct 2021 16:54:04.108 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:05.108 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:06.108 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:07.108 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:08.108 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:09.109 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:10.109 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:11.109 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:12.109 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:13.109 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:14.109 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:15.110 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:16.110 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:17.110 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:18.110 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:19.110 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:20.111 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:21.111 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:22.111 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:23.111 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:24.111 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:25.112 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:26.112 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:27.112 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:28.112 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:29.112 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:30.112 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:31.113 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:32.113 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:33.045 - Accepted 172.0.0.100:35536

8:M 19 Oct 2021 16:54:33.113 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:34.113 # <search> Got no slots in CLUSTER SLOTS

8:M 19 Oct 2021 16:54:34.939 # configEpoch set to 9 via CLUSTER SET-CONFIG-EPOCH

8:M 19 Oct 2021 16:54:35.020 - Accepting cluster node connection from 172.0.0.100:45521

8:M 19 Oct 2021 16:54:35.020 # IP address for this node updated to 172.0.0.108

8:M 19 Oct 2021 16:54:35.122 - Accepting cluster node connection from 172.0.0.106:42959

8:M 19 Oct 2021 16:54:35.124 - Accepting cluster node connection from 172.0.0.103:34361

8:M 19 Oct 2021 16:54:35.354 - Accepting cluster node connection from 172.0.0.109:46361

8:M 19 Oct 2021 16:54:35.895 - Accepting cluster node connection from 172.0.0.102:33227

8:M 19 Oct 2021 16:54:35.908 - Accepting cluster node connection from 172.0.0.104:38533

8:M 19 Oct 2021 16:54:35.981 - Accepting cluster node connection from 172.0.0.107:36625



=== REDIS BUG REPORT START: Cut & paste starting from here ===

8:M 19 Oct 2021 16:54:36.115 # Redis 6.2.6 crashed by signal: 11, si_code: 1

8:M 19 Oct 2021 16:54:36.115 # Accessing address: 0xe0000000e

8:M 19 Oct 2021 16:54:36.115 # Crashed running the instruction at: 0x7ff2f3c6becb


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

EIP:

/plugin/oss-module.so(+0xd2ecb)[0x7ff2f3c6becb]


Backtrace:

/lib/x86_64-linux-gnu/libpthread.so.0(+0x14140)[0x7ff2f52ff140]

/plugin/oss-module.so(+0xd2ecb)[0x7ff2f3c6becb]

/plugin/oss-module.so(+0xdf79b)[0x7ff2f3c7879b]

/plugin/oss-module.so(+0xe01b2)[0x7ff2f3c791b2]

/plugin/oss-module.so(+0x1895a7)[0x7ff2f3d225a7]

/plugin/oss-module.so(+0x189687)[0x7ff2f3d22687]

/plugin/oss-module.so(uv__io_poll+0x338)[0x7ff2f3d2c668]

/plugin/oss-module.so(uv_run+0x11c)[0x7ff2f3d22f7c]

/plugin/oss-module.so(+0xdf41e)[0x7ff2f3c7841e]

/lib/x86_64-linux-gnu/libpthread.so.0(+0x8ea7)[0x7ff2f52f3ea7]

/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7ff2f5223def]


------ REGISTERS ------

8:M 19 Oct 2021 16:54:36.117 # 

RAX:0000000000000ccb RBX:0000000000000000

RCX:0000000000004000 RDX:0000000000000ccb

RDI:00007ff2f3effa50 RSI:0000000000000001

RBP:0000000e0000000e RSP:00007ff2f29c4050

R8 :0000000000000007 R9 :00007ff2f4e00900

R10:00007ff2f29c7f28 R11:0000000000000005

R12:00007ff2f3effa50 R13:00007ff2f3efee50

R14:00007ff2f29c45f0 R15:00007ff2f3efeed0

RIP:00007ff2f3c6becb EFL:0000000000010202

CSGSFS:002b000000000033

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c405f) -> 00007ff2f3efee68

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c405e) -> 00000000fbad8001

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c405d) -> f9e8ea33bc3dc200

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c405c) -> 00007ff2d4000d4e

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c405b) -> 00007ff2f29c40a0

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c405a) -> 00007ff2f29c40a0

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c4059) -> 00007ff2f3d225a7

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c4058) -> 00007ff2f29c40a0

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c4057) -> 0000000000000000

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c4056) -> 00007ff2f3efec80

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c4055) -> 00007ff2f3c791b2

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c4054) -> 00007ff2d40013c0

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c4053) -> 00007ff2f3c7879b

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c4052) -> 00005613fd930340

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c4051) -> 00007ff2d4001390

8:M 19 Oct 2021 16:54:36.117 # (00007ff2f29c4050) -> 00005613fd930320


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

# Server

redis_version:6.2.6

redis_git_sha1:00000000

redis_git_dirty:0

redis_build_id:1527eab61b27d3bf

redis_mode:cluster

os:Linux 5.10.16.3-microsoft-standard-WSL2 x86_64

arch_bits:64

multiplexing_api:epoll

atomicvar_api:atomic-builtin

gcc_version:10.2.1

process_id:8

process_supervised:no

run_id:82efb3980c89f1000f7c3b6fe0a0ac3ffdf8dbf0

tcp_port:6388

server_time_usec:1634662476113977

uptime_in_seconds:33

uptime_in_days:0

hz:10

configured_hz:10

lru_clock:7272524

executable:/data/redis-server

config_file:/etc/redis/redis.conf

io_threads_active:0


# Clients

connected_clients:1

cluster_connections:18

maxclients:100000

client_recent_max_input_buffer:40

client_recent_max_output_buffer:0

blocked_clients:0

tracking_clients:0

clients_in_timeout_table:0


# Memory

used_memory:7064392

used_memory_human:6.74M

used_memory_rss:15343616

used_memory_rss_human:14.63M

used_memory_peak:7125416

used_memory_peak_human:6.80M

used_memory_peak_perc:99.14%

used_memory_overhead:6926640

used_memory_startup:6906120

used_memory_dataset:137752

used_memory_dataset_perc:87.03%

allocator_allocated:7690752

allocator_active:8130560

allocator_resident:11612160

total_system_memory:51343355904

total_system_memory_human:47.82G

used_memory_lua:37888

used_memory_lua_human:37.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.06

allocator_frag_bytes:439808

allocator_rss_ratio:1.43

allocator_rss_bytes:3481600

rss_overhead_ratio:1.32

rss_overhead_bytes:3731456

mem_fragmentation_ratio:2.17

mem_fragmentation_bytes:8281584

mem_not_counted_for_evict:0

mem_replication_backlog:0

mem_clients_slaves:0

mem_clients_normal:20520

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:0

rdb_bgsave_in_progress:0

rdb_last_save_time:1634662443

rdb_last_bgsave_status:ok

rdb_last_bgsave_time_sec:-1

rdb_current_bgsave_time_sec:-1

rdb_last_cow_size:0

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:1

total_commands_processed:110

instantaneous_ops_per_sec:3

total_net_input_bytes:293

total_net_output_bytes:8775

instantaneous_input_kbps:0.11

instantaneous_output_kbps:0.04

rejected_connections:0

sync_full:0

sync_partial_ok:0

sync_partial_err:0

expired_keys:0

expired_stale_perc:0.00

expired_time_cap_reached_count:0

expire_cycle_cpu_milliseconds:0

evicted_keys:0

keyspace_hits:0

keyspace_misses:0

pubsub_channels:0

pubsub_patterns:0

latest_fork_usec:0

total_forks:0

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:1

dump_payload_sanitizations:0

total_reads_processed:8

total_writes_processed:8

io_threaded_reads_processed:0

io_threaded_writes_processed:0


# Replication

role:master

connected_slaves:0

master_failover_state:no-failover

master_replid:aa3c19f73e8266888bea425b3f96f8480ed69b53

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

used_cpu_user:0.049102

used_cpu_sys_children:0.000000

used_cpu_user_children:0.000000

used_cpu_sys_main_thread:0.000000

used_cpu_user_main_thread:0.004382


# Modules

module:name=search,ver=20010,api=1,filters=0,usedby=[],using=[],options=[]


# Commandstats

cmdstat_info:calls=5,usec=91,usec_per_call=18.20,rejected_calls=0,failed_calls=0

cmdstat_search.CLUSTERREFRESH:calls=33,usec=2642,usec_per_call=80.06,rejected_calls=0,failed_calls=0

cmdstat_cluster:calls=71,usec=756,usec_per_call=10.65,rejected_calls=0,failed_calls=1

cmdstat_auth:calls=1,usec=2,usec_per_call=2.00,rejected_calls=0,failed_calls=0


# Errorstats

errorstat_ERR:count=1


# Cluster

cluster_enabled:1


# Keyspace


------ CLIENT LIST OUTPUT ------

id=95 addr=172.0.0.100:35536 laddr=172.0.0.108:6388 fd=15 name= age=4 idle=2 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=20520 events=r cmd=cluster user=default redir=-1


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


------ FAST MEMORY TEST ------

8:M 19 Oct 2021 16:54:36.117 # main thread terminated

8:M 19 Oct 2021 16:54:36.118 # Bio thread for job type #0 terminated

8:M 19 Oct 2021 16:54:36.118 # Bio thread for job type #1 terminated

8:M 19 Oct 2021 16:54:36.118 # Bio thread for job type #2 terminated

8:M 19 Oct 2021 16:54:36.118 # IO thread(tid:140681227736832) terminated

8:M 19 Oct 2021 16:54:36.118 # IO thread(tid:140681219344128) terminated

8:M 19 Oct 2021 16:54:36.118 # IO thread(tid:140681210951424) terminated


Fast memory test PASSED, however your memory can still be broken. Please run a memory test for several hours if possible.


------ DUMPING CODE AROUND EIP ------

Symbol: (null) (base: (nil))

Module: /plugin/oss-module.so (base 0x7ff2f3b99000)

$ xxd -r -p /tmp/dump.hex /tmp/dump.bin

$ objdump --adjust-vma=(nil) -D -b binary -m i386:x86-64 /tmp/dump.bin

------


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


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

pnthai88 avatar Oct 19 '21 16:10 pnthai88