Bug | Crash when querying with some combinations of optional terms

[massyah]

Some queries involving optional terms return weird results and can crash redis. I've managed to reproduce this issue both using my compiled redissearch.so and the docker image.

This seems to be an issue related to my index configuration, as I can't reproduce the crash on the "getting started" index example.

It might be related to another issue mentioned as a comment here: #1169 (comment)

My index include these two fields :

                rs.TextField(name="title", weight=12, phonetic_matcher="dm:fr"),
                rs.TagField(name="category"),

I also provide a dump.rdb of the faulty index (it's super small, <1Mo, and non confidential).
redis-search-crash.rdb.gz

Steps to reproduce:

# download, gunzip and store the redis-search-crash.rdb sample file locally 
# spin up a redis search from docker loading the faulty dump.rdb 
docker run -v $PWD/redis-search-crash.rdb:/data/dump.rdb --rm --name "demo-redis-search-crash" -p 7777:6379 redislabs/redisearch:latest

In another terminal :

docker exec -it demo-redis-search-crash redis-cli FT.SEARCH 100km_fr:places "~roussilon turenne" LIMIT 0 10 # we get 160 results 
docker exec -it demo-redis-search-crash redis-cli FT.SEARCH 100km_fr:places "hello ~roussilon ~turenne" LIMIT 0 10 # 1 result, which is expected since hello occurs only once 
docker exec -it demo-redis-search-crash redis-cli FT.SEARCH 100km_fr:places "~roussilon hello ~turenne" LIMIT 0 10 # 160 results, weird I think, as the query should be equivalent to the previous one 
docker exec -it demo-redis-search-crash redis-cli FT.SEARCH 100km_fr:places "~roussilon ~turenne hello" LIMIT 0 10 # redis has crashed 

Crash log :

=== REDIS BUG REPORT START: Cut & paste starting from here ===
1:M 16 Jun 2020 15:01:00.985 # Redis 5.0.7 crashed by signal: 11
1:M 16 Jun 2020 15:01:00.985 # Crashed running the instruction at: 0x7f7ef12463e0
1:M 16 Jun 2020 15:01:00.985 # Accessing address: (nil)
1:M 16 Jun 2020 15:01:00.985 # Failed assertion: <no assertion failed> (<no file>:0)

------ STACK TRACE ------
EIP:
/usr/lib/redis/modules/redisearch.so(+0x883e0)[0x7f7ef12463e0]

Backtrace:
redis-server *:6379(logStackTrace+0x32)[0x55f290216572]
redis-server *:6379(sigsegvHandler+0x9e)[0x55f290216c4e]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12730)[0x7f7ef1f70730]
/usr/lib/redis/modules/redisearch.so(+0x883e0)[0x7f7ef12463e0]
/usr/lib/redis/modules/redisearch.so(+0x9eaac)[0x7f7ef125caac]
/usr/lib/redis/modules/redisearch.so(+0x9ef21)[0x7f7ef125cf21]
/usr/lib/redis/modules/redisearch.so(+0x9efee)[0x7f7ef125cfee]
/usr/lib/redis/modules/redisearch.so(+0x9ebe8)[0x7f7ef125cbe8]
/usr/lib/redis/modules/redisearch.so(+0x42474)[0x7f7ef1200474]
/usr/lib/redis/modules/redisearch.so(AREQ_Execute+0x10)[0x7f7ef1200730]
/usr/lib/redis/modules/redisearch.so(+0x428fc)[0x7f7ef12008fc]
redis-server *:6379(RedisModuleCommandDispatcher+0x54)[0x55f290242d14]
redis-server *:6379(call+0x9b)[0x55f2901d235b]
redis-server *:6379(processCommand+0x51e)[0x55f2901d2c1e]
redis-server *:6379(processInputBuffer+0x171)[0x55f2901e2e61]
redis-server *:6379(aeProcessEvents+0x101)[0x55f2901cc311]
redis-server *:6379(aeMain+0x2b)[0x55f2901cc71b]
redis-server *:6379(main+0x4ca)[0x55f2901c957a]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xeb)[0x7f7ef1dc109b]
redis-server *:6379(_start+0x2a)[0x55f2901c97da]

------ INFO OUTPUT ------
# Server
redis_version:5.0.7
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:9d06145e39725623
redis_mode:standalone
os:Linux 4.19.76-linuxkit x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:atomic-builtin
gcc_version:8.3.0
process_id:1
run_id:aee3079a1850169b411fabcacf2a0e6578b4e4ad
tcp_port:6379
uptime_in_seconds:69
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:15261356
executable:/data/redis-server
config_file:

# Clients
connected_clients:1
client_recent_max_input_buffer:2
client_recent_max_output_buffer:0
blocked_clients:0

# Memory
used_memory:3176848
used_memory_human:3.03M
used_memory_rss:8855552
used_memory_rss_human:8.45M
used_memory_peak:3176848
used_memory_peak_human:3.03M
used_memory_peak_perc:100.19%
used_memory_overhead:1074782
used_memory_startup:823888
used_memory_dataset:2102066
used_memory_dataset_perc:89.34%
allocator_allocated:3531088
allocator_active:3923968
allocator_resident:6508544
total_system_memory:3140308992
total_system_memory_human:2.92G
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.11
allocator_frag_bytes:392880
allocator_rss_ratio:1.66
allocator_rss_bytes:2584576
rss_overhead_ratio:1.36
rss_overhead_bytes:2347008
mem_fragmentation_ratio:2.83
mem_fragmentation_bytes:5725728
mem_not_counted_for_evict:0
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:49734
mem_aof_buffer:0
mem_allocator:jemalloc-5.1.0
active_defrag_running:0
lazyfree_pending_objects:0

# Persistence
loading:0
rdb_changes_since_last_save:0
rdb_bgsave_in_progress:0
rdb_last_save_time:1592319591
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

# Stats
total_connections_received:1
total_commands_processed:21
instantaneous_ops_per_sec:0
total_net_input_bytes:635
total_net_output_bytes:1681
instantaneous_input_kbps:0.00
instantaneous_output_kbps:0.00
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
evicted_keys:0
keyspace_hits:23
keyspace_misses:15
pubsub_channels:0
pubsub_patterns:0
latest_fork_usec: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

# Replication
role:master
connected_slaves:0
master_replid:77449eacd59bb7b7ba8e6b67d9ea757dd7bbeec5
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.297684
used_cpu_user:0.132758
used_cpu_sys_children:0.022263
used_cpu_user_children:0.033691

# Commandstats
cmdstat_FT.SEARCH:calls=6,usec=1445,usec_per_call=240.83
cmdstat_hgetall:calls=15,usec=172,usec_per_call=11.47

# Cluster
cluster_enabled:0

# Keyspace
db0:keys=3994,expires=0,avg_ttl=0
db1:keys=163,expires=0,avg_ttl=0

------ CLIENT LIST OUTPUT ------
id=8 addr=172.17.0.1:59212 fd=8 name= age=65 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=93 qbuf-free=32675 obl=0 oll=1 omem=40 events=r cmd=FT.SEARCH

------ CURRENT CLIENT INFO ------
id=8 addr=172.17.0.1:59212 fd=8 name= age=65 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=93 qbuf-free=32675 obl=0 oll=1 omem=40 events=r cmd=FT.SEARCH
argv[0]: 'FT.SEARCH'
argv[1]: '100km_fr:places'
argv[2]: '~roussilon ~turenne'
argv[3]: 'LIMIT'
argv[4]: '0'
argv[5]: '10'

------ REGISTERS ------
1:M 16 Jun 2020 15:01:00.986 # 
RAX:0000000000000001 RBX:00007f7ef195bf00
RCX:00007f7ef198d860 RDX:0000000000000000
RDI:00007f7ee473e7a0 RSI:00000000000000a1
RBP:0000000000000000 RSP:00007ffed86f3660
R8 :00007f7ef125ca10 R9 :0000000000000000
R10:00007f7ef19b8c43 R11:00007f7ef1d977f0
R12:00007f7ee473e7a0 R13:00007ffed86f3678
R14:0000000000000000 R15:0000000000000000
RIP:00007f7ef12463e0 EFL:0000000000010202
CSGSFS:002b000000000033
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f366f) -> 00007f7ee4847480
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f366e) -> 0000000000000008
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f366d) -> 0000000000000020
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f366c) -> 0000000000000004
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f366b) -> 00007f7ef125caac
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f366a) -> 00007ffed86f38e0
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f3669) -> ffffffffffffffff
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f3668) -> 00007ffed86f36c8
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f3667) -> 00007f7ee4819da0
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f3666) -> 00007f7ee47b1ed0
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f3665) -> 00007f7ef195bf00
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f3664) -> 000000000000000c
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f3663) -> 0000000000000000
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f3662) -> 0000000000000000
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f3661) -> 00007ffed86f36c8
1:M 16 Jun 2020 15:01:00.986 # (00007ffed86f3660) -> 0000000000000000

------ FAST MEMORY TEST ------
1:M 16 Jun 2020 15:01:00.986 # Bio thread for job type #0 terminated
1:M 16 Jun 2020 15:01:00.987 # Bio thread for job type #1 terminated
1:M 16 Jun 2020 15:01:00.987 # Bio thread for job type #2 terminated
*** Preparing to test memory region 55f290344000 (2248704 bytes)
*** Preparing to test memory region 55f29238d000 (135168 bytes)
*** Preparing to test memory region 7f7ee1e00000 (8388608 bytes)
*** Preparing to test memory region 7f7ee2722000 (8388608 bytes)
*** Preparing to test memory region 7f7ee2f23000 (8388608 bytes)
*** Preparing to test memory region 7f7ee3724000 (8388608 bytes)
*** Preparing to test memory region 7f7ee3f25000 (8388608 bytes)
*** Preparing to test memory region 7f7ee4725000 (2621440 bytes)
*** Preparing to test memory region 7f7ee49a6000 (8388608 bytes)
*** Preparing to test memory region 7f7ee51a7000 (8388608 bytes)
*** Preparing to test memory region 7f7ee59a8000 (8388608 bytes)
*** Preparing to test memory region 7f7ee61a9000 (8388608 bytes)
*** Preparing to test memory region 7f7ee69aa000 (8388608 bytes)
*** Preparing to test memory region 7f7ee71ab000 (8388608 bytes)
*** Preparing to test memory region 7f7ee79ac000 (8388608 bytes)
*** Preparing to test memory region 7f7ee81ad000 (8388608 bytes)
*** Preparing to test memory region 7f7ee89ae000 (8388608 bytes)
*** Preparing to test memory region 7f7ee91af000 (8388608 bytes)
*** Preparing to test memory region 7f7ee99b0000 (8388608 bytes)
*** Preparing to test memory region 7f7eea1b1000 (8388608 bytes)
*** Preparing to test memory region 7f7eea9b2000 (8388608 bytes)
*** Preparing to test memory region 7f7eeb1b3000 (8388608 bytes)
*** Preparing to test memory region 7f7eeb9b4000 (8388608 bytes)
*** Preparing to test memory region 7f7eec1b5000 (8388608 bytes)
*** Preparing to test memory region 7f7eec9b6000 (8388608 bytes)
*** Preparing to test memory region 7f7eed1b7000 (8388608 bytes)
*** Preparing to test memory region 7f7eed9b8000 (8388608 bytes)
*** Preparing to test memory region 7f7eee1b9000 (8388608 bytes)
*** Preparing to test memory region 7f7eee9ba000 (8388608 bytes)
*** Preparing to test memory region 7f7eef1bb000 (8388608 bytes)
*** Preparing to test memory region 7f7eef9bc000 (8388608 bytes)
*** Preparing to test memory region 7f7ef01bd000 (8388608 bytes)
*** Preparing to test memory region 7f7ef09be000 (8388608 bytes)
*** Preparing to test memory region 7f7ef13fd000 (12288 bytes)
*** Preparing to test memory region 7f7ef1400000 (8388608 bytes)
*** Preparing to test memory region 7f7ef1d97000 (24576 bytes)
*** Preparing to test memory region 7f7ef1f5a000 (16384 bytes)
*** Preparing to test memory region 7f7ef1f7b000 (16384 bytes)
*** Preparing to test memory region 7f7ef1f88000 (4096 bytes)
*** Preparing to test memory region 7f7ef211b000 (8192 bytes)
*** Preparing to test memory region 7f7ef2148000 (4096 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
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: /usr/lib/redis/modules/redisearch.so (base 0x7f7ef11be000)
$ 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/antirez/redis/issues

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

[ashtul]

The test does not expose the crash bug. only wrong answers.

[ashtul]

Note:
The crash happens for FT.SEARCH 100km_fr:places "~roussilon ~turenne".

[ashtul]

fixed by #1286