Describe the bug

Running JSON Indexing tutorial https://redis.com/blog/index-and-query-json-docs-with-redis/ Server crash when running the tutorial.

To reproduce

Run redis-redisjson docker image over MacBook Pro chip Apple M1 (2020) 16 GB RAM

Run the following instructions in redis-cli: 127.0.0.1:6379> JSON.SET myDoc $ '{"title": "foo", "content": "bar"}' OK JSON.GET myDoc . "{\"title\":\"foo\",\"content\":\"bar\"}" 127.0.0.1:6379> FT.CREATE myIdx ON JSON SCHEMA $.title AS title TEXT OK 127.0.0.1:6379> FT.SEARCH myIdx "@title:foo" Error: Server closed the connection

Expected behavior

Command should have been executed properly

Additional information

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

1:M 18 Mar 2022 07:30:21.570 # Redis 6.2.6 crashed by signal: 11, si_code: 1

1:M 18 Mar 2022 07:30:21.570 # Accessing address: 0x3a64695f646c71

1:M 18 Mar 2022 07:30:21.570 # Crashed running the instruction at: 0x40037f4303

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

EIP:

/usr/lib/redis/modules/redisearch.so(DocTable_Put+0x193)[0x40037f4303]

Backtrace:

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

/usr/lib/redis/modules/redisearch.so(DocTable_Put+0x193)[0x40037f4303]

/usr/lib/redis/modules/redisearch.so(+0x12a298)[0x4003808298]

/usr/lib/redis/modules/redisearch.so(Indexer_Add+0x55)[0x4003808895]

/usr/lib/redis/modules/redisearch.so(Document_AddToIndexes+0xee)[0x40037f601e]

/usr/lib/redis/modules/redisearch.so(IndexSpec_UpdateDoc+0x135)[0x400382d575]

/usr/lib/redis/modules/redisearch.so(IndexSpec_UpdateMatchingWithSchemaRules+0xb8)[0x400382dc18]

/usr/lib/redis/modules/redisearch.so(+0x14fcca)[0x400382dcca]

redis-server *:6379(+0xd5c42)[0x40000d5c42]

redis-server *:6379(dictScan+0x22c)[0x400004a87c]

redis-server *:6379(RM_Scan+0x76)[0x40000d5306]

/usr/lib/redis/modules/redisearch.so(+0x14e235)[0x400382c235]

/usr/lib/redis/modules/redisearch.so(+0xf689e)[0x40037d489e]

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

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

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

1:M 18 Mar 2022 07:30:21.576 #

RAX:0000004002a96050 RBX:0000000000000000

RCX:0000000000000001 RDX:00000040079463f0

RDI:00000040079254b9 RSI:323a64695f646c69

RBP:0000004007925031 RSP:00000040073120d0

R8 :00000040079254b1 R9 :00000040022a4dc0

R10:0000000000000000 R11:00000040079254b1

R12:0000000000000008 R13:00000000000003e8

R14:00000040079463c0 R15:0000004002989390

RIP:00000040037f4303 EFL:0000000000000206

CSGSFS:002b000000000033

1:M 18 Mar 2022 07:30:21.576 # (00000040073120df) -> 0000004003808265

1:M 18 Mar 2022 07:30:21.576 # (00000040073120de) -> 0000000000000001

1:M 18 Mar 2022 07:30:21.576 # (00000040073120dd) -> 0000004003808298

1:M 18 Mar 2022 07:30:21.576 # (00000040073120dc) -> 0000004002989300

1:M 18 Mar 2022 07:30:21.576 # (00000040073120db) -> 0000004007935000

1:M 18 Mar 2022 07:30:21.576 # (00000040073120da) -> 00000040073121d0

1:M 18 Mar 2022 07:30:21.576 # (00000040073120d9) -> 0000004002989390

1:M 18 Mar 2022 07:30:21.576 # (00000040073120d8) -> 0000004002989390

1:M 18 Mar 2022 07:30:21.576 # (00000040073120d7) -> 00000040073152e0

1:M 18 Mar 2022 07:30:21.576 # (00000040073120d6) -> 0000004002989300

1:M 18 Mar 2022 07:30:21.576 # (00000040073120d5) -> 0000000000000001

1:M 18 Mar 2022 07:30:21.576 # (00000040073120d4) -> 0000000000000001

1:M 18 Mar 2022 07:30:21.576 # (00000040073120d3) -> 3ff0000000000000

1:M 18 Mar 2022 07:30:21.576 # (00000040073120d2) -> 00000040029893c8

1:M 18 Mar 2022 07:30:21.576 # (00000040073120d1) -> 0000000000000000

1:M 18 Mar 2022 07:30:21.576 # (00000040073120d0) -> 0000000000000000

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

Server

redis_version:6.2.6

redis_git_sha1:00000000

redis_git_dirty:0

redis_build_id:20572a8fe0b422d3

redis_mode:standalone

os:Linux 5.10.104-linuxkit x86_64

arch_bits:64

multiplexing_api:epoll

atomicvar_api:atomic-builtin

gcc_version:10.2.1

process_id:1

process_supervised:no

run_id:5174eedb694e67a6192c84a72bb5968e44a49de1

tcp_port:6379

server_time_usec:1647588621567928

uptime_in_seconds:51906

uptime_in_days:0

hz:10

configured_hz:10

lru_clock:3421453

executable:/data/redis-server

config_file:

io_threads_active:0

Clients

connected_clients:3

cluster_connections:0

maxclients:10000

client_recent_max_input_buffer:32

client_recent_max_output_buffer:0

blocked_clients:0

tracking_clients:0

clients_in_timeout_table:0

Memory

used_memory:1334328

used_memory_human:1.27M

used_memory_rss:0

used_memory_rss_human:0B

used_memory_peak:1334328

used_memory_peak_human:1.27M

used_memory_peak_perc:101.64%

used_memory_overhead:966536

used_memory_startup:904632

used_memory_dataset:367792

used_memory_dataset_perc:85.59%

allocator_allocated:1541368

allocator_active:2105344

allocator_resident:4689920

total_system_memory:8337530880

total_system_memory_human:7.76G

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

allocator_frag_bytes:563976

allocator_rss_ratio:2.23

allocator_rss_bytes:2584576

rss_overhead_ratio:0.00

rss_overhead_bytes:-4689920

mem_fragmentation_ratio:0.00

mem_fragmentation_bytes:-1154024

mem_not_counted_for_evict:0

mem_replication_backlog:0

mem_clients_slaves:0

mem_clients_normal:61520

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

rdb_bgsave_in_progress:0

rdb_last_save_time:1647588595

rdb_last_bgsave_status:ok

rdb_last_bgsave_time_sec:0

rdb_current_bgsave_time_sec:-1

rdb_last_cow_size:2318336

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

total_commands_processed:645

instantaneous_ops_per_sec:0

total_net_input_bytes:17631

total_net_output_bytes:1633874

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

expire_cycle_cpu_milliseconds:268

evicted_keys:0

keyspace_hits:212

keyspace_misses:1

pubsub_channels:0

pubsub_patterns:0

latest_fork_usec:6012

total_forks:4

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

dump_payload_sanitizations:0

total_reads_processed:592

total_writes_processed:588

io_threaded_reads_processed:0

io_threaded_writes_processed:0

Replication

role:master

connected_slaves:0

master_failover_state:no-failover

master_replid:b97b5c4b0ca1bbb50399307b7e209d7242d7cac9

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

used_cpu_user:39.827659

used_cpu_sys_children:0.039383

used_cpu_user_children:0.086702

used_cpu_sys_main_thread:0.001989

used_cpu_user_main_thread:0.025859

Modules

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

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

Commandstats

cmdstat_json.del:calls=1,usec=449,usec_per_call=449.00,rejected_calls=0,failed_calls=0

cmdstat_json.strappend:calls=1,usec=1215,usec_per_call=1215.00,rejected_calls=0,failed_calls=0

cmdstat_scan:calls=4,usec=960,usec_per_call=240.00,rejected_calls=0,failed_calls=0

cmdstat_json.get:calls=58,usec=11743,usec_per_call=202.47,rejected_calls=0,failed_calls=4

cmdstat_memory:calls=35,usec=675,usec_per_call=19.29,rejected_calls=0,failed_calls=0

cmdstat_command:calls=2,usec=8086,usec_per_call=4043.00,rejected_calls=0,failed_calls=0

cmdstat_module:calls=1,usec=186,usec_per_call=186.00,rejected_calls=0,failed_calls=0

cmdstat_json.type:calls=22,usec=3462,usec_per_call=157.36,rejected_calls=0,failed_calls=0

cmdstat_json.set:calls=18,usec=13024,usec_per_call=723.56,rejected_calls=0,failed_calls=4

cmdstat_FT.SEARCH:calls=3,usec=11000,usec_per_call=3666.67,rejected_calls=0,failed_calls=0

cmdstat_dbsize:calls=6,usec=45,usec_per_call=7.50,rejected_calls=0,failed_calls=0

cmdstat_exists:calls=2,usec=125,usec_per_call=62.50,rejected_calls=0,failed_calls=0

cmdstat_set:calls=3,usec=1311,usec_per_call=437.00,rejected_calls=0,failed_calls=0

cmdstat_ttl:calls=41,usec=458,usec_per_call=11.17,rejected_calls=0,failed_calls=0

cmdstat_strlen:calls=4,usec=204,usec_per_call=51.00,rejected_calls=0,failed_calls=0

cmdstat_del:calls=1,usec=333,usec_per_call=333.00,rejected_calls=0,failed_calls=0

cmdstat_type:calls=35,usec=491,usec_per_call=14.03,rejected_calls=0,failed_calls=0

cmdstat_FT.CREATE:calls=2,usec=6847,usec_per_call=3423.50,rejected_calls=0,failed_calls=0

cmdstat_json.strlen:calls=9,usec=1981,usec_per_call=220.11,rejected_calls=0,failed_calls=0

cmdstat_get:calls=4,usec=162,usec_per_call=40.50,rejected_calls=0,failed_calls=0

cmdstat_json.objlen:calls=8,usec=774,usec_per_call=96.75,rejected_calls=0,failed_calls=0

cmdstat_json.numincrby:calls=1,usec=1121,usec_per_call=1121.00,rejected_calls=0,failed_calls=0

cmdstat_client:calls=5,usec=293,usec_per_call=58.60,rejected_calls=0,failed_calls=0

cmdstat_info:calls=360,usec=117910,usec_per_call=327.53,rejected_calls=0,failed_calls=0

cmdstat_json.debug:calls=19,usec=1515,usec_per_call=79.74,rejected_calls=0,failed_calls=0

Errorstats

errorstat_ERR:count=3

errorstat_Existing:count=4

errorstat_expected:count=1

errorstat_key:count=1

Cluster

cluster_enabled:0

Keyspace

db0:keys=8,expires=0,avg_ttl=0

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

id=9 addr=172.17.0.1:58814 laddr=172.17.0.2:6379 fd=10 name= age=51878 idle=51363 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=json.get user=default redir=-1

id=10 addr=172.17.0.1:58816 laddr=172.17.0.2:6379 fd=11 name=redisinsight-common-77b2f736 age=51863 idle=220 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=info user=default redir=-1

id=12 addr=172.17.0.1:58820 laddr=172.17.0.2:6379 fd=9 name= age=42099 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=40954 argv-mem=0 obl=0 oll=0 omem=0 tot-mem=61520 events=r cmd=FT.CREATE user=default redir=-1

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

ReJSON_trace

ReJSON_trace: 0: redis_module::base_info_func

         at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/redis-module-1.0.0/src/lib.rs:78:33

1: rejson::__info_func

         at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/redis-module-1.0.0/src/macros.rs:120:13

2: modulesCollectInfo

         at /usr/src/redis/src/module.c:7078:9

3: logModulesInfo

         at /usr/src/redis/src/debug.c:1598:22

4: printCrashReport

         at /usr/src/redis/src/debug.c:1849:5

  sigsegvHandler

         at /usr/src/redis/src/debug.c:1831:5

5:

6: dllist2_append

         at /build/src/util/dllist.h:87:6

  DocTable_Set

         at /build/src/doc_table.c:106:3

  DocTable_Put

         at /build/src/doc_table.c:226:3

7: makeDocumentId

         at /build/src/indexer.c:275:7

  doAssignIds

         at /build/src/indexer.c:298:30

  Indexer_Process

         at /build/src/indexer.c:435:5

8: Indexer_Add

         at /build/src/indexer.c:494:5

9: Document_AddToIndexes

         at /build/src/document.c:671:7

10: IndexSpec_UpdateDoc

         at /build/src/spec.c:2271:3

  IndexSpec_UpdateDoc

         at /build/src/spec.c:2233:5

11: IndexSpec_UpdateMatchingWithSchemaRules

         at /build/src/spec.c:2490:9

  IndexSpec_UpdateMatchingWithSchemaRules

         at /build/src/spec.c:2475:6

12: Indexes_ScanProc

         at /build/src/spec.c:1666:5

13: moduleScanCallback

         at /usr/src/redis/src/module.c:7601:5

14: dictScan

         at /usr/src/redis/src/dict.c:911:13

15: RM_Scan

         at /usr/src/redis/src/module.c:7689:22

  RM_Scan

         at /usr/src/redis/src/module.c:7682:5

16: Indexes_ScanAndReindexTask

         at /build/src/spec.c:1689:10

17: thread_do

         at /build/deps/thpool/thpool.c:340:9

18: start_thread

19: clone

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

1:M 18 Mar 2022 07:30:21.685 # main thread terminated

1:M 18 Mar 2022 07:30:21.686 # Bio thread for job type #0 terminated

1:M 18 Mar 2022 07:30:21.686 # Bio thread for job type #1 terminated

1:M 18 Mar 2022 07:30:21.687 # Bio thread for job type #2 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: DocTable_Put (base: 0x40037f4170)

Module: /usr/lib/redis/modules/redisearch.so (base 0x40036de000)

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

$ objdump --adjust-vma=0x40037f4170 -D -b binary -m i386:x86-64 /tmp/dump.bin


1:M 18 Mar 2022 07:30:21.688 # dump of function (hexdump of 531 bytes):

41574989ff415641554189cd41544989d4554889f5534c89cb4883ec388b4424704c89442408f20f1144241889442420488d47384889c74889442410e8effeffff4885c00f853e020000498b471048837c240800488d4801488b05291c310049894f1048894c2428488b000f847f0100004885db0f8476010000be48000000bf010000004183cd02ffd049834720484c89e64889ef4989c6e823cc0400660fefc045886e1b498946084989c3418b4614f20f5a44241849c746200000000025000000fff3410f11461083c80141894614488b4c24280fb644242049890e4188461c488b05400b31004c895c2420bf1000000048894c2418ff10488d7301bf010000004989c5488b057c1b3100ff10488b7424084889da498945004889c7e8ce38fcff49895d084883c3104c8b5c242049015f20488b4c24184d896e40498b770889ca4839f172084889c831d248f7f64d8b6f1889d34c39eb72094c39ee0f87450100004889d8410fb75e1d48c1e004490347308d53014188561d0fb6d64188561e48833800498d56300f84d9000000488b700848895608488b700849c74638000000004989763048895008498307014c89df48894c2408e844d40400490147204c89e24889ee488b4c2408488b7c2410e8dbfdffff4883c4384c89f05b5d415c415d415e415fc3660f1f840000000000be40000000bf01000000ffd049834720404c89e64889ef4989c6e8b1ca0400660fefc0

Function at 0x40037f40a0 is DocIdMap_Get

Function at 0x4003840e30 is sdsnewlen

Function at 0x4003841770 is sdsAllocSize

Function at 0x40037f4120 is DocIdMap_Put

=== REDIS BUG REPORT END. Make sure to include from START to END. ===

Comment From: sundb

Same as #10162. You can make an issue in https://github.com/RedisJSON/RedisJSON.

Comment From: sundb

@oranagra Title is wrong, RedisJson not RedisSearch.

Comment From: oranagra

@sundb it crashed in redisearch.so, after an FT.CREATE command... they're both there (and also, i don't care that much, same product / maintainer).