bulk-update crashes at a certain percentage

[nemote95]

I am trying to update nodes of a graph ( about 300 million nodes and 200 billion edges) using redisgraph-bulk-loader (latest version).

The csv file for this update is about 6Gb, containing two columns of integers, one representing the id of the node and the other represnting the date and time for that node. I ran the following command :

redisgraph-bulk-update $graph_name -h [host_IP_address] -p [host_redis_port] --csv csv _file_dir --query "MATCH (n:Article) WHERE n.id = row[0] SET n.date = row[1]".

This query used to work previously, but when I tried recently, it crashed at 7% of the progress. I tried changing the token size to half of the token, but it was not helpful. I also tried testing the command on 1% of the data. The progress bar showed 100% for the smaller update, but it stalled after that.

Any idea why this is crashing at a certain point?

Cheers.

[LiorKogan]

What version or Redis and RedisGraph are you using?

[nemote95]

Thanks for your reply. I am using Redis version 6.2.6, RedisGraph 2.8.11

[alonre24]

@nemote95 We believe that the fix in #2301 might solve the problem. Can you please try running redislabs/redisgraph:edge docker image and see if you still get the crash?
Also, if it will crash, please attach Redis' crash report.
Thanks!

[nemote95]

Hi, thanks for your reply. I tried the edge version and it failed again after updating 7% of the data. here is the Redis log :

=== REDIS BUG REPORT START: Cut & paste starting from here ===
1:M 06 Apr 2022 00:48:31.985 # Redis 6.2.6 crashed by signal: 11, si_code: 2
1:M 06 Apr 2022 00:48:31.985 # Accessing address: 0x7f1a77c8d000
1:M 06 Apr 2022 00:48:31.985 # Crashed running the instruction at: 0x7f1a7c0a7f04

------ STACK TRACE ------
EIP:
/usr/lib/redis/modules/redisgraph.so(+0x1e3f04)[0x7f1a7c0a7f04]

Backtrace:
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12980)[0x7f1a7e48b980]
/usr/lib/redis/modules/redisgraph.so(+0x1e3f04)[0x7f1a7c0a7f04]
/usr/lib/redis/modules/redisgraph.so(AR_EXP_Evaluate+0x98)[0x7f1a7c0a9048]
/usr/lib/redis/modules/redisgraph.so(AR_EXP_ReduceToScalar+0xbf)[0x7f1a7c0a926f]
/usr/lib/redis/modules/redisgraph.so(AR_EXP_FromASTNode+0x22)[0x7f1a7c0a6692]
/usr/lib/redis/modules/redisgraph.so(parse_params+0x16d)[0x7f1a7c0fa4bd]
/usr/lib/redis/modules/redisgraph.so(ExecutionCtx_FromQuery+0x22)[0x7f1a7c0b8332]
/usr/lib/redis/modules/redisgraph.so(_query+0x9d)[0x7f1a7c0b8b4d]
/usr/lib/redis/modules/redisgraph.so(+0x242eb4)[0x7f1a7c106eb4]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76db)[0x7f1a7e4806db]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f1a7e1a961f]

------ REGISTERS ------
1:M 06 Apr 2022 00:48:31.995 # 
RAX:00007e72bf58bcfc RBX:00007f1a77879610
RCX:0000000200000000 RDX:00000000000c11c6
RDI:00007e72bf58bcfc RSI:0000000100000008
RBP:00007f1a7848b300 RSP:00007f1a77879610
R8 :00000000000c11c6 R9 :00000000000000f8
R10:0000000000000001 R11:0000000000000003
R12:00000000000413a0 R13:0000000000209cf8
R14:00007e72c6e08090 R15:0000000000000000
RIP:00007f1a7c0a7f04 EFL:0000000000010216
CSGSFS:002b000000000033
1:M 06 Apr 2022 00:48:31.995 # (00007f1a7787961f) -> 0000000200000008
1:M 06 Apr 2022 00:48:31.995 # (00007f1a7787961e) -> 00007e72c6e083fc
1:M 06 Apr 2022 00:48:31.995 # (00007f1a7787961d) -> 0000000200000008
1:M 06 Apr 2022 00:48:31.995 # (00007f1a7787961c) -> 00007e72c6e0839c
1:M 06 Apr 2022 00:48:31.995 # (00007f1a7787961b) -> 0000000200000008
1:M 06 Apr 2022 00:48:31.995 # (00007f1a7787961a) -> 00007e72c6e0833c
1:M 06 Apr 2022 00:48:31.995 # (00007f1a77879619) -> 0000000200000008
1:M 06 Apr 2022 00:48:31.995 # (00007f1a77879618) -> 00007e72c6e082dc
1:M 06 Apr 2022 00:48:31.995 # (00007f1a77879617) -> 0000000200000008
1:M 06 Apr 2022 00:48:31.995 # (00007f1a77879616) -> 00007e72c6e0827c
1:M 06 Apr 2022 00:48:31.995 # (00007f1a77879615) -> 0000000200000008
1:M 06 Apr 2022 00:48:31.995 # (00007f1a77879614) -> 00007e72c6e0821c
1:M 06 Apr 2022 00:48:31.995 # (00007f1a77879613) -> 0000000200000008
1:M 06 Apr 2022 00:48:31.995 # (00007f1a77879612) -> 00007e72c6e081bc
1:M 06 Apr 2022 00:48:31.995 # (00007f1a77879611) -> 0000000200000008
1:M 06 Apr 2022 00:48:31.995 # (00007f1a77879610) -> 00007e72c6e0815c

------ INFO OUTPUT ------
# Server
redis_version:6.2.6
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:74a783698e8a44d9
redis_mode:standalone
os:Linux 5.11.0-1028-oracle x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:c11-builtin
gcc_version:7.5.0
process_id:1
process_supervised:no
run_id:396d8c8375928cf7b9aa75ffd7a972fbdd1c6296
tcp_port:6379
server_time_usec:1649206111917573
uptime_in_seconds:8210
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:5038943
executable:/data/redis-server
config_file:
io_threads_active:0

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

# Memory
used_memory:325319233744
used_memory_human:302.98G
used_memory_rss:272050577408
used_memory_rss_human:253.37G
used_memory_peak:458860426952
used_memory_peak_human:427.35G
used_memory_peak_perc:70.90%
used_memory_overhead:30861034961
used_memory_startup:844048
used_memory_dataset:294458198783
used_memory_dataset_perc:90.51%
allocator_allocated:325305697408
allocator_active:327506374656
allocator_resident:329744535552
total_system_memory:608295211008
total_system_memory_human:566.52G
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.01
allocator_frag_bytes:2200677248
allocator_rss_ratio:1.01
allocator_rss_bytes:2238160896
rss_overhead_ratio:0.83
rss_overhead_bytes:-57693958144
mem_fragmentation_ratio:0.84
mem_fragmentation_bytes:-53254030832
mem_not_counted_for_evict:0
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:19056209
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:2694750208
current_cow_size_age:22
current_fork_perc:0.53
current_save_keys_processed:2923521
current_save_keys_total:556280002
rdb_changes_since_last_save:1
rdb_bgsave_in_progress:1
rdb_last_save_time:1649197901
rdb_last_bgsave_status:ok
rdb_last_bgsave_time_sec:-1
rdb_current_bgsave_time_sec:25
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:6
total_commands_processed:14
instantaneous_ops_per_sec:0
total_net_input_bytes:20027853
total_net_output_bytes:55814
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:10
evicted_keys:0
keyspace_hits:556305470
keyspace_misses:0
pubsub_channels:0
pubsub_patterns:0
latest_fork_usec:7540053
total_forks:1
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:2
dump_payload_sanitizations:0
total_reads_processed:1381
total_writes_processed:15
io_threaded_reads_processed:0
io_threaded_writes_processed:0

# Replication
role:master
connected_slaves:0
master_failover_state:no-failover
master_replid:a68731f9ade00d61fe483db792bc0c7b71edb388
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:366.423267
used_cpu_user:6954.117282
used_cpu_sys_children:0.000938
used_cpu_user_children:0.002828
used_cpu_sys_main_thread:0.563749
used_cpu_user_main_thread:9.959565

# Modules
module:name=graph,ver=20811,api=1,filters=0,usedby=[],using=[],options=[]

# Commandstats
cmdstat_command:calls=2,usec=882,usec_per_call=441.00,rejected_calls=0,failed_calls=0
cmdstat_config:calls=2,usec=32,usec_per_call=16.00,rejected_calls=0,failed_calls=0
cmdstat_graph.QUERY:calls=4,usec=9427,usec_per_call=2356.75,rejected_calls=0,failed_calls=0
cmdstat_ping:calls=1,usec=1,usec_per_call=1.00,rejected_calls=2,failed_calls=0
cmdstat_graph.CONFIG:calls=1,usec=9,usec_per_call=9.00,rejected_calls=0,failed_calls=0
cmdstat_graph.EXPLAIN:calls=2,usec=158,usec_per_call=79.00,rejected_calls=0,failed_calls=0
cmdstat_module:calls=2,usec=8,usec_per_call=4.00,rejected_calls=0,failed_calls=0

# Errorstats
errorstat_LOADING:count=2

# Cluster
cluster_enabled:0

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

------ CLIENT LIST OUTPUT ------
id=8 addr=172.17.0.1:54558 laddr=172.17.0.2:6379 fd=12 name= age=7363 idle=1144 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=graph.CONFIG user=default redir=-1
id=10 addr=10.0.0.22:41418 laddr=172.17.0.2:6379 fd=10 name= age=1104 idle=1104 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=graph.QUERY user=default redir=-1
id=11 addr=10.0.0.22:41420 laddr=172.17.0.2:6379 fd=11 name= age=1104 idle=1104 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=graph.QUERY user=default redir=-1
id=21 addr=10.0.0.30:37462 laddr=172.17.0.2:6379 fd=13 name= age=25 idle=10 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 argv-mem=18974145 obl=0 oll=0 omem=0 tot-mem=18994665 events=r cmd=graph.QUERY user=default redir=-1

------ MODULES INFO OUTPUT ------
# graph_executing commands
graph_command:GRAPH.QUERY CYPHER rows=[[....]]] UNWIND $rows AS row MATCH (n:Article) WHERE n.id = row[0] SET n.publication_date = row[1]

------ FAST MEMORY TEST ------
1:M 18 Apr 2022 10:43:37.434 # main thread terminated
1:M 18 Apr 2022 10:43:37.434 # Bio thread for job type #0 terminated
1:M 18 Apr 2022 10:43:37.434 # Bio thread for job type #1 terminated
1:M 18 Apr 2022 10:43:37.434 # 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: gsignal (base: 0x7f9d3ce5cdc0)
Module: /lib/x86_64-linux-gnu/libc.so.6 (base 0x7f9d3ce1e000)
$ xxd -r -p /tmp/dump.hex /tmp/dump.bin
$ objdump --adjust-vma=0x7f9d3ce5cdc0 -D -b binary -m i386:x86-64 /tmp/dump.bin
------
1:M 18 Apr 2022 10:43:37.434 # dump of function (hexdump of 327 bytes):
4881ec180100004189f841ba08000000660f6f0518d017004989e164488b042528000000488984240801000031c00f29842480000000660f76c0488db424800000004c89ca31ffb80e0000000f298424900000000f298424a00000000f298424b00000000f298424c00000000f298424d00000000f298424e00000000f298424f00000000f05b92700000089c80f054889c7b8ba0000000f0589c64489c2b8ea0000000f05483d00f0ffff773b4189c041ba0800000031d24c89cebf02000000b80e0000000f05488b8c24080100006448330c25280000004489c0751f4881c418010000c30f1f00488b15b9bf3a00f7d841b8ffffffff648902ebb4e81f5c0f00662e0f1f8400000000000f1f44000085ff780cf7dfe9950200000f1f440000488b0581bf3a0064c70016000000b8ffffffffc3662e0f1f8400000000006690900f1f44000066
Function at 0x7f9d3cf52ae0 is __stack_chk_fail

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

[alonre24]

@nemote95 Are you sure that you're using the updated edge docker?
I'm asking since the date that appears in the beginning of the crash report is April 6th:

1:M 06 Apr 2022 00:48:31.985 # Redis 6.2.6 crashed by signal: 11, si_code: 2
1:M 06 Apr 2022 00:48:31.985 # Accessing address: 0x7f1a77c8d000
1:M 06 Apr 2022 00:48:31.985 # Crashed running the instruction at: 0x7f1a7c0a7f04
...