Segmentation Fault in v5.0

[oruchreis]

I've upgraded keydb version from 0.9.6 to 5.0 and it crashed with this error. I've downgraded back to 0.9.6 and it worked well.

22:C 26 Jul 2019 08:25:53.323 # oO0OoO0OoO0Oo KeyDB is starting oO0OoO0OoO0Oo
22:C 26 Jul 2019 08:25:53.323 # KeyDB version=5.0.0, bits=64, commit=b0a0f03b, modified=0, pid=22, just started
22:C 26 Jul 2019 08:25:53.323 # Configuration loaded
22:M 26 Jul 2019 08:25:53.324 * Running mode=standalone, port=6379.
22:M 26 Jul 2019 08:25:53.325 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
22:M 26 Jul 2019 08:25:53.325 # Server initialized
22:M 26 Jul 2019 08:25:53.325 * <ft> RediSearch version 1.4.11 (Git=v1.4.11)
22:M 26 Jul 2019 08:25:53.325 * <ft> concurrency: ON, gc: ON, prefix min length: 2, prefix max expansions: 200, query timeout (ms): 0, timeout policy: fail, cursor read size: 1000, cursor max idle (ms): 300000, max doctable size: 1000000, search pool size: 20, index pool size: 8, 
22:M 26 Jul 2019 08:25:53.332 * <ft> Initialized thread pool!
22:M 26 Jul 2019 08:25:53.332 * Module 'ft' loaded from /data/redisearch.so
22:M 26 Jul 2019 08:25:53.332 * Loading RDB produced by version 0.9.6
22:M 26 Jul 2019 08:25:53.332 * RDB age 1206 seconds
22:M 26 Jul 2019 08:25:53.332 * RDB memory usage when created 1021.16 Mb
22:M 26 Jul 2019 08:25:59.569 * DB loaded from disk: 6.236 seconds
22:M 26 Jul 2019 08:25:59.569 * Ready to accept connections
 === KEYDB BUG REPORT START: Cut & paste starting from here ===
22:M 26 Jul 2019 08:25:59.569 # KeyDB 5.0.0 crashed by signal: 11
22:M 26 Jul 2019 08:25:59.569 # Crashed running the instruction at: 0x55d708de6a2a
22:M 26 Jul 2019 08:25:59.569 # Accessing address: 0x1a8
22:M 26 Jul 2019 08:25:59.569 # Failed assertion: <no assertion failed> (<no file>:0)
 ------ STACK TRACE ------
bash: line 1:    22 Segmentation fault      (core dumped) keydb-server /conf/redis.conf --loadmodule /data/redisearch.so TIMEOUT 0 ON_TIMEOUT fail 2> >(tee -a /data/redis.log >&2)

[oruchreis]

This time it crashed when I call FT.EXPLAIN command of redisearch in v.0.9.6. But it didn't crash at startup like before.

=== KEYDB BUG REPORT START: Cut & paste starting from here ===
7:S 26 Jul 2019 08:57:21.318 # === ASSERTION FAILED ===
7:S 26 Jul 2019 08:57:21.318 # ==> multi.cpp:296 'GlobalLocksAcquired()' is not true
7:S 26 Jul 2019 08:57:21.318 # (forcing SIGSEGV to print the bug report.)
7:S 26 Jul 2019 08:57:21.318 # KeyDB 0.9.6 crashed by signal: 11
7:S 26 Jul 2019 08:57:21.318 # Crashed running the instruction at: 0x55aced61926e
7:S 26 Jul 2019 08:57:21.318 # Accessing address: 0xffffffffffffffff
7:S 26 Jul 2019 08:57:21.318 # Failed assertion: GlobalLocksAcquired() (multi.cpp:296)
 ------ STACK TRACE ------
EIP:
keydb-server *:6379(_serverAssert+0x7e) [0x55aced61926e]
 Backtrace:
keydb-server *:6379(logStackTrace(ucontext_t*)+0x6b) [0x55aced61c25b]
keydb-server *:6379(sigsegvHandler(int, siginfo_t*, void*)+0xbf) [0x55aced61c9ef]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12890) [0x7fc625d61890]
keydb-server *:6379(_serverAssert+0x7e) [0x55aced61926e]
keydb-server *:6379(touchWatchedKey(redisDb*, redisObject*)+0x71) [0x55aced618cf1]
keydb-server *:6379(RM_CloseKey(RedisModuleKey*)+0x75) [0x55aced64b125]
keydb-server *:6379(+0xc7646) [0x55aced64c646]
keydb-server *:6379(moduleFreeContext(RedisModuleCtx*)+0x9b) [0x55aced64c76b]
keydb-server *:6379(RM_FreeThreadSafeContext(RedisModuleCtx*)+0x9) [0x55aced64c809]
/data/redisearch.so(+0x42140) [0x7fc622b05140]
/data/redisearch.so(+0xadabe) [0x7fc622b70abe]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76db) [0x7fc625d566db]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f) [0x7fc625a7f88f]
 ------ INFO OUTPUT ------
7:S 26 Jul 2019 08:57:21.318 # === ASSERTION FAILED ===
7:S 26 Jul 2019 08:57:21.318 # ==> object.cpp:961 'GlobalLocksAcquired()' is not true
7:S 26 Jul 2019 08:57:21.318 # (forcing SIGSEGV to print the bug report.)
bash: line 1:     7 Segmentation fault      (core dumped) keydb-server /conf/redis.conf --loadmodule /data/redisearch.so TIMEOUT 0 ON_TIMEOUT fail 2> >(tee -a /data/redis.log >&2)

[oruchreis]

I deleted rdb db file and v5.0 started without any error. I think the upgrading process from v0.9.6 to v5.0 breaks something. Also I'm using redisearch v1.4.11, maybe it broke the db when upgrading.

[oruchreis]

I've downgraded back to v0.9.6 again. Because when I try to create an index and add document with redisearch, v5.0 crashed and I didn't catch up the log of that. As far as I saw the sentinel did failover because the master hanged and didn't respond to the sentinel. I suspect of this bug resurfaced with v5.0 #27

[JohnSully]

Upon further investigation this may be a bug in RediSearch itself. The module is supposed to call RM_ThreadSafeContextLock to lock before attempting to call functions such as RM_FreeThreadSafeContext. In Redis this bug is silent because they do not have the extensive lock validation asserts that KeyDB has. KeyDB will crash instead of silently corrupting data as would happen in Redis under this scenario.

I will attempt to repro this locally and coordinate a fix with RediSearch.

EDIT: There are multiple bugs here. One is definitely KeyDB, the other is likely RediSearch.

[JohnSully]

I think I've fixed this with change cbe5c04. You did not include the callstack so I cannot know for sure if this was the crash you experienced.

As for the bug in your second message I've split that off into issue #70 .

I'll be adding a second test suite to validate popular modules. I was hesitant to do so before because I didn't want the test suite to be dependent on external proprietary code (RediSearch is not OSS) but a second extended test suite should be fine.

[JohnSully]

Docker has been updated with the fix. If it happens again get me the callstack and I will continue investigating.

Also for your second issue I’m contacting the redisearch maintainers. However if they won’t fix it in a reasonable period of time I will implement a workaround.