RedisJSON / RedisJSON

RedisJSON - a JSON data type for Redis
https://redis.io/docs/stack/json/
Other
3.84k stars 327 forks source link

[CRASH] periodical crash after Lightroom starts exporting (maybe RAM issue) #827

Open dontsovcmc opened 2 years ago

dontsovcmc commented 2 years ago

Here are 9 crashes log. I think I have anought RAM or HDD. Redis first crashes when I start exporting photos in Lightroom (RAM). After exporting stop Redis continues to crash... Can't understand a reason. I use Redis to cash Python http responses.

=== REDIS BUG REPORT START: Cut & paste starting from here ===
22916:C 17 Sep 2022 14:36:53.792 # Redis 6.2.7 crashed by signal: 6, si_code: 0
22916:C 17 Sep 2022 14:36:53.817 # Crashed running the instruction at: 0x7fff6e8aa32a

------ STACK TRACE ------
EIP:
0   libsystem_kernel.dylib              0x00007fff6e8aa32a __pthread_kill + 10

Backtrace:
0   libsystem_platform.dylib            0x00007fff6e95f5fd _sigtramp + 29
1   ???                                 0x00000001055b5c28 0x0 + 4384840744
2   libsystem_c.dylib                   0x00007fff6e831808 abort + 120
3   rejson.so                           0x0000000103967889 _ZN3std3sys4unix14abort_internal17h4329bd900762fe80E + 9
4   rejson.so                           0x0000000103965ff9 rust_panic + 201
5   rejson.so                           0x0000000103965da6 _ZN3std9panicking20rust_panic_with_hook17h3147bfce63989ccbE + 470
6   rejson.so                           0x0000000103965bb3 _ZN3std9panicking19begin_panic_handler28_$u7b$$u7b$closure$u7d$$u7d$17h354f8ce5af2f2ce8E + 179
7   rejson.so                           0x0000000103964ae7 _ZN3std10sys_common9backtrace26__rust_end_short_backtrace17h63e1494bcfb6c060E + 23
8   rejson.so                           0x000000010396588a rust_begin_unwind + 74
9   rejson.so                           0x000000010398d003 _ZN4core9panicking9panic_fmt17h6e7523bddca0f9b8E + 51
10  rejson.so                           0x0000000103980fb0 _ZN4core7unicode9printable5check17hc7e3c932df8eb6d4E + 0
11  rejson.so                           0x0000000103977019 _ZN4core3ops8function6FnOnce9call_once17h4e847a559d6f2a5bE + 9
12  rejson.so                           0x000000010397b6db _ZN4core10intrinsics17const_eval_select17h048caff331f6c9efE + 27
13  rejson.so                           0x000000010398d241 _ZN4core3str16slice_error_fail17h48af51deb8b0c4bcE + 33
14  rejson.so                           0x00000001038aceb3 _ZN10serde_json3ser18format_escaped_str17h102c9338e20d8e79E + 963
15  rejson.so                           0x00000001038b07d0 _ZN5serde3ser12SerializeMap15serialize_entry17hf277180fa268d0a1E + 288
16  rejson.so                           0x00000001038f9c78 _ZN5ijson3ser74_$LT$impl$u20$serde..ser..Serialize$u20$for$u20$ijson..object..IObject$GT$9serialize17hcb373b62483bb55dE + 152
17  rejson.so                           0x00000001038b07f1 _ZN5serde3ser12SerializeMap15serialize_entry17hf277180fa268d0a1E + 321
18  rejson.so                           0x00000001038f9c78 _ZN5ijson3ser74_$LT$impl$u20$serde..ser..Serialize$u20$for$u20$ijson..object..IObject$GT$9serialize17hcb373b62483bb55dE + 152
19  rejson.so                           0x00000001038b07f1 _ZN5serde3ser12SerializeMap15serialize_entry17hf277180fa268d0a1E + 321
20  rejson.so                           0x00000001038f9c78 _ZN5ijson3ser74_$LT$impl$u20$serde..ser..Serialize$u20$for$u20$ijson..object..IObject$GT$9serialize17hcb373b62483bb55dE + 152
21  rejson.so                           0x00000001038faf32 _ZN6rejson9redisjson12type_methods8rdb_save17h8038bade9665b5a8E + 466
22  redis-server                        0x0000000100cf78ba rdbSaveObject + 634
23  redis-server                        0x0000000100cf82e1 rdbSaveKeyValuePair + 881
24  redis-server                        0x0000000100cf8d42 rdbSaveRio + 1010
25  redis-server                        0x0000000100cf93e6 rdbSave + 214
26  redis-server                        0x0000000100cf968d rdbSaveBackground + 141
27  redis-server                        0x0000000100cc49bb serverCron + 2123
28  redis-server                        0x0000000100cbeffb aeProcessEvents + 1051
29  redis-server                        0x0000000100cbf12d aeMain + 29
30  redis-server                        0x0000000100ccd417 main + 1831
31  libdyld.dylib                       0x00007fff6e762cc9 start + 1
32  ???                                 0x000000000000001c 0x0 + 28

------ REGISTERS ------
22916:C 17 Sep 2022 14:36:53.823 # 
RAX:0000000000000000 RBX:00000001055efdc0
RCX:00007ffeeef45168 RDX:0000000000000000
RDI:0000000000000303 RSI:0000000000000006
RBP:00007ffeeef45190 RSP:00007ffeeef45168
R8 :00007ffeeef4503f R9 :0000000000000001
R10:00000001055efdc0 R11:0000000000000246
R12:0000000000000303 R13:00000001039bdf48
R14:0000000000000006 R15:0000000000000016
RIP:00007fff6e8aa32a EFL:0000000000000246
CS :0000000000000007 FS:0000000000000000  GS:0000000000000000
22916:C 17 Sep 2022 14:36:53.823 # (00007ffeeef45177) -> 00007ffeeef452a0
22916:C 17 Sep 2022 14:36:53.823 # (00007ffeeef45176) -> 0000000103967889
22916:C 17 Sep 2022 14:36:53.823 # (00007ffeeef45175) -> 00007ffeeef451e0
22916:C 17 Sep 2022 14:36:53.824 # (00007ffeeef45174) -> 0000000000000001
22916:C 17 Sep 2022 14:36:53.824 # (00007ffeeef45173) -> 0000000000000000
22916:C 17 Sep 2022 14:36:53.824 # (00007ffeeef45172) -> ffffffffeef45268
22916:C 17 Sep 2022 14:36:53.824 # (00007ffeeef45171) -> 00007ffefffff9df
22916:C 17 Sep 2022 14:36:53.824 # (00007ffeeef45170) -> 0000000000000000
22916:C 17 Sep 2022 14:36:53.824 # (00007ffeeef4516f) -> 0000000000000002
22916:C 17 Sep 2022 14:36:53.824 # (00007ffeeef4516e) -> 00007fff6e831808
22916:C 17 Sep 2022 14:36:53.824 # (00007ffeeef4516d) -> 00007ffeeef451d0
22916:C 17 Sep 2022 14:36:53.825 # (00007ffeeef4516c) -> 00000001039c2308
22916:C 17 Sep 2022 14:36:53.825 # (00007ffeeef4516b) -> 00007ffeeef451b0
22916:C 17 Sep 2022 14:36:53.825 # (00007ffeeef4516a) -> 0000000000000001
22916:C 17 Sep 2022 14:36:53.825 # (00007ffeeef45169) -> 0000000000000003
22916:C 17 Sep 2022 14:36:53.825 # (00007ffeeef45168) -> 00007fff6e96ae60

------ INFO OUTPUT ------
# Server
redis_version:6.2.7
redis_git_sha1:e6f67092
redis_git_dirty:0
redis_build_id:b62801a3bc178a02
redis_mode:standalone
os:Darwin 19.6.0 x86_64
arch_bits:64
monotonic_clock:POSIX clock_gettime
multiplexing_api:kqueue
atomicvar_api:c11-builtin
gcc_version:4.2.1
process_id:22916
process_supervised:no
run_id:570d8c5d1ea5d5bf51dbb1d37aa360675d5396e4
tcp_port:6379
server_time_usec:1663414599059240
uptime_in_seconds:249345
uptime_in_days:2
hz:10
configured_hz:10
lru_clock:2470215
executable:/usr/local/Caskroom/redis-stack-server/6.2.4-v2/bin/redis-server
config_file:/usr/local/Caskroom/redis-stack-server/6.2.4-v2/etc/redis-stack.conf
io_threads_active:0

# Clients
connected_clients:1
cluster_connections:0
maxclients:10000
client_recent_max_input_buffer:48
client_recent_max_output_buffer:0
blocked_clients:0
tracking_clients:0
clients_in_timeout_table:0

# Memory
used_memory:1717815344
used_memory_human:1.60G
used_memory_rss:2150400
used_memory_rss_human:2.05M
used_memory_peak:1718000240
used_memory_peak_human:1.60G
used_memory_peak_perc:99.99%
used_memory_overhead:3095376
used_memory_startup:1197680
used_memory_dataset:1714719968
used_memory_dataset_perc:99.89%
allocator_allocated:1717811360
allocator_active:2117632
allocator_resident:2117632
[redis_crash.txt](https://github.com/redis/redis/files/9591567/redis_crash.txt)

total_system_memory:17179869184
total_system_memory_human:16.00G
used_memory_lua:32768
used_memory_lua_human:32.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:0.00
allocator_frag_bytes:18446744071993857888
allocator_rss_ratio:1.00
allocator_rss_bytes:0
rss_overhead_ratio:1.02
rss_overhead_bytes:32768
mem_fragmentation_ratio:0.00
mem_fragmentation_bytes:-1715660960
mem_not_counted_for_evict:0
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:17456
mem_aof_buffer:0
mem_allocator:libc
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:116
rdb_bgsave_in_progress:0
rdb_last_save_time:1663413808
rdb_last_bgsave_status:err
rdb_last_bgsave_time_sec:22
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:11
total_commands_processed:119512
instantaneous_ops_per_sec:0
total_net_input_bytes:2999877755
total_net_output_bytes:2506515434
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:2
expired_stale_perc:0.00
expired_time_cap_reached_count:0
expire_cycle_cpu_milliseconds:3637
evicted_keys:0
keyspace_hits:51683
keyspace_misses:33906
pubsub_channels:0
pubsub_patterns:0
latest_fork_usec:4224
total_forks:307
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:292741
total_writes_processed:119503
io_threaded_reads_processed:0
io_threaded_writes_processed:0

# Replication
role:master
connected_slaves:0
master_failover_state:no-failover
master_replid:492d22f0a4431378774f780de63752bb7b9d0b0a
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:1.300701
used_cpu_user:5.447012
used_cpu_sys_children:0.000000
used_cpu_user_children:0.000000

# Modules
module:name=timeseries,ver=10617,api=1,filters=0,usedby=[],using=[],options=[handle-io-errors]
module:name=ReJSON,ver=20200,api=1,filters=0,usedby=[search|graph],using=[],options=[handle-io-errors]
module:name=graph,ver=20819,api=1,filters=0,usedby=[],using=[ReJSON],options=[]
module:name=search,ver=20414,api=1,filters=0,usedby=[],using=[ReJSON],options=[handle-io-errors]
module:name=bf,ver=20218,api=1,filters=0,usedby=[],using=[],options=[]

# Commandstats
cmdstat_expire:calls=6,usec=10802,usec_per_call=1800.33,rejected_calls=0,failed_calls=0
cmdstat_exec:calls=2,usec=8397,usec_per_call=4198.50,rejected_calls=0,failed_calls=0
cmdstat_json.set:calls=33897,usec=75744482,usec_per_call=2234.55,rejected_calls=1,failed_calls=0
cmdstat_persist:calls=2,usec=45,usec_per_call=22.50,rejected_calls=0,failed_calls=0
cmdstat_sadd:calls=2,usec=4862,usec_per_call=2431.00,rejected_calls=0,failed_calls=0
cmdstat_json.get:calls=85589,usec=26247853,usec_per_call=306.67,rejected_calls=0,failed_calls=0
cmdstat_hset:calls=8,usec=7197,usec_per_call=899.62,rejected_calls=0,failed_calls=0
cmdstat_multi:calls=2,usec=1613,usec_per_call=806.50,rejected_calls=0,failed_calls=0
cmdstat_info:calls=4,usec=108,usec_per_call=27.00,rejected_calls=0,failed_calls=0

# Errorstats
errorstat_MISCONF:count=1

# Cluster
cluster_enabled:0

# Keyspace
db0:keys=33898,expires=0,avg_ttl=0

------ CLIENT LIST OUTPUT ------
id=21 addr=127.0.0.1:65449 laddr=127.0.0.1:6379 fd=9 name= age=70465 idle=21 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=17456 events=r cmd=json.set user=default redir=-1

------ MODULES INFO OUTPUT ------
# ReJSON_trace
ReJSON_trace:   0: backtrace::backtrace::trace
   1: backtrace::capture::Backtrace::new
   2: redis_module::base_info_func
   3: rejson::__info_func
   4: _modulesCollectInfo
   5: _printCrashReport
   6: _sigsegvHandler
   7: __sigtramp

# graph_executing commands

# search_version
search_RedisSearch_version:6.2.7

# search_index
search_number_of_indexes:0

# search_fields_statistics

# search_runtime_configurations
search_concurrent_mode:OFF
search_enableGC:ON
search_minimal_term_prefix:2
search_maximal_prefix_expansions:200
search_query_timeout_ms:500
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:10000
search_max_aggregate_results:10000
search_search_pool_size:20
search_index_pool_size:8
search_gc_scan_size:100
search_min_phonetic_term_length:3

------ DUMPING CODE AROUND EIP ------
Symbol: __pthread_kill (base: 0x7fff6e8aa320)
Module: /usr/lib/system/libsystem_kernel.dylib (base 0x7fff6e8a3000)
$ xxd -r -p /tmp/dump.hex /tmp/dump.bin
$ objdump --adjust-vma=0x7fff6e8aa320 -D -b binary -m i386:x86-64 /tmp/dump.bin
------
22916:C 17 Sep 2022 14:36:53.856 # dump of function (hexdump of 138 bytes):
b8480100024989ca0f0573084889c7e9e5a2ffffc3909090b8530000024989ca0f0573084889c7e9cda2ffffc3909090b8830100024989ca0f0573084889c7e9b5a2ffffc34585c07416554889e5e8cba2ffffc70016000000b8ffffffff5dc341b840000000e9adc4ffff90b86a0000024989ca0f0573084889c7e979a2ffffc3909090b81e00000249
Function at 0x7fff6e8a463e is __error

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

Additional information

  1. MacOS Catalina 10.15.7
  2. Steps to reproduce: don't know
oshadmi commented 2 years ago

Seems dup or related to #823

jer-0 commented 2 years ago

@dontsovcmc quick question, do you also run graph commands on the same redis instance ?

dontsovcmc commented 2 years ago

@dontsovcmc quick question, do you also run graph commands on the same redis instance ?

No. Only get.json, set.json commands from Python.