Redisgraph: Query crashing Redis

[dandago]

Hi,

I have a situation where I'm running a query and it's consistently crashing RedisGraph. The query in question is:

GRAPH.QUERY DiseaseGraph "MATCH (p) RETURN 'Infected on day ' + p.infectedDay + ': ' + COUNT(p)"

I am running Redis with RedisGraph via Docker as follows:

sudo docker run -p 6379:6379 -it --rm redislabs/redisgraph:edge

Same problem with latest tag instead of edge.

The output I got from Redis is as follows:

...
1:M 10 Apr 2020 12:51:11.682 * <graph> Thread pool created, using 4 threads.
1:M 10 Apr 2020 12:51:11.682 * Module 'graph' loaded from /usr/lib/redis/modules/redisgraph.so
1:M 10 Apr 2020 12:51:11.683 * Ready to accept connections
unrecognized type: 1315152504
redis-server: /redisgraph/src/value.c:267: SIValue_ToString: Assertion `false' failed.


=== REDIS BUG REPORT START: Cut & paste starting from here ===
1:M 10 Apr 2020 12:51:56.915 # Redis 5.0.8 crashed by signal: 11
1:M 10 Apr 2020 12:51:56.915 # Crashed running the instruction at: 0x7f2064b45611
1:M 10 Apr 2020 12:51:56.915 # Accessing address: (nil)
1:M 10 Apr 2020 12:51:56.915 # Failed assertion: <no assertion failed> (<no file>:0)

------ STACK TRACE ------
EIP:
/lib/x86_64-linux-gnu/libc.so.6(abort+0x1fd)[0x7f2064b45611]

Backtrace:
redis-server *:6379(logStackTrace+0x32)[0x56144e603592]
redis-server *:6379(sigsegvHandler+0x9e)[0x56144e603c6e]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x12730)[0x7f2064cf6730]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x1fd)[0x7f2064b45611]
/lib/x86_64-linux-gnu/libc.so.6(+0x2240f)[0x7f2064b4540f]
/lib/x86_64-linux-gnu/libc.so.6(+0x30102)[0x7f2064b53102]
/usr/lib/redis/modules/redisgraph.so(+0x1aaf18)[0x7f2063ae5f18]
/usr/lib/redis/modules/redisgraph.so(SIValue_StringJoin+0x6d)[0x7f2063ae60cd]
/usr/lib/redis/modules/redisgraph.so(SIValue_Add+0x283)[0x7f2063ae63e3]
/usr/lib/redis/modules/redisgraph.so(+0x1b20f7)[0x7f2063aed0f7]
/usr/lib/redis/modules/redisgraph.so(+0x1b1f12)[0x7f2063aecf12]
/usr/lib/redis/modules/redisgraph.so(AR_EXP_Evaluate+0x10)[0x7f2063aed5f0]
/usr/lib/redis/modules/redisgraph.so(+0x1c747c)[0x7f2063b0247c]
/usr/lib/redis/modules/redisgraph.so(+0x1cbb9c)[0x7f2063b06b9c]
/usr/lib/redis/modules/redisgraph.so(ExecutionPlan_Execute+0x58)[0x7f2063afc178]
/usr/lib/redis/modules/redisgraph.so(Graph_Query+0x351)[0x7f2063af6691]
/usr/lib/redis/modules/redisgraph.so(+0x1ebded)[0x7f2063b26ded]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7fa3)[0x7f2064cebfa3]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f2064c1c4cf]

------ INFO OUTPUT ------
# Server
redis_version:5.0.8
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:ce75a617c591114f
redis_mode:standalone
os:Linux 5.3.0-46-generic x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:atomic-builtin
gcc_version:8.3.0
process_id:1
run_id:098e8b2cb7b5d9c29ef681e0490021905a4dd17c
tcp_port:6379
uptime_in_seconds:45
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:9464812
executable:/data/redis-server
config_file:

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

# Memory
used_memory:2111368
used_memory_human:2.01M
used_memory_rss:12136448
used_memory_rss_human:11.57M
used_memory_peak:2302064
used_memory_peak_human:2.20M
used_memory_peak_perc:91.72%
used_memory_overhead:874470
used_memory_startup:824704
used_memory_dataset:1236898
used_memory_dataset_perc:96.13%
allocator_allocated:3593896
allocator_active:4358144
allocator_resident:14831616
total_system_memory:16704802816
total_system_memory_human:15.56G
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.21
allocator_frag_bytes:764248
allocator_rss_ratio:3.40
allocator_rss_bytes:10473472
rss_overhead_ratio:0.82
rss_overhead_bytes:-2695168
mem_fragmentation_ratio:6.18
mem_fragmentation_bytes:10173944
mem_not_counted_for_evict:0
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:49694
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:55
rdb_bgsave_in_progress:0
rdb_last_save_time:1586523071
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:3
total_commands_processed:61
instantaneous_ops_per_sec:0
total_net_input_bytes:7672
total_net_output_bytes:29761
instantaneous_input_kbps:0.01
instantaneous_output_kbps:7.13
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:112
keyspace_misses:1
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:e358737e73fbd2cc821aa15dcf7901dcbb9ad56b
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.141074
used_cpu_user:0.374729
used_cpu_sys_children:0.002434
used_cpu_user_children:0.003766

# Commandstats
cmdstat_graph.QUERY:calls=58,usec=1604,usec_per_call=27.66
cmdstat_command:calls=2,usec=7468,usec_per_call=3734.00
cmdstat_echo:calls=1,usec=1,usec_per_call=1.00

# Cluster
cluster_enabled:0

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

------ CLIENT LIST OUTPUT ------
id=120 addr=172.17.0.1:51944 fd=8 name= age=1 idle=0 flags=b db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=graph.QUERY

------ REGISTERS ------
1:M 10 Apr 2020 12:51:56.931 # 
RAX:0000000000000000 RBX:0000000000000000
RCX:0000000000000000 RDX:0000000000000000
RDI:0000000000000002 RSI:00007f2063136f30
RBP:00007f2064ca7ee0 RSP:00007f2063137050
R8 :0000000000000000 R9 :00007f2063136f30
R10:0000000000000008 R11:0000000000000246
R12:00007f2063fad000 R13:00007f2063fb03bc
R14:000000000000010b R15:0000000000000001
RIP:00007f2064b45611 EFL:0000000000010246
CSGSFS:002b000000000033
1:M 10 Apr 2020 12:51:56.931 # (00007f206313705f) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f206313705e) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f206313705d) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f206313705c) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f206313705b) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f206313705a) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f2063137059) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f2063137058) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f2063137057) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f2063137056) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f2063137055) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f2063137054) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f2063137053) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f2063137052) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f2063137051) -> 0000000000000000
1:M 10 Apr 2020 12:51:56.931 # (00007f2063137050) -> 0000000000000020

------ FAST MEMORY TEST ------
1:M 10 Apr 2020 12:51:56.931 # Bio thread for job type #0 terminated
1:M 10 Apr 2020 12:51:56.932 # Bio thread for job type #1 terminated
1:M 10 Apr 2020 12:51:56.932 # Bio thread for job type #2 terminated
*** Preparing to test memory region 56144e731000 (2248704 bytes)
*** Preparing to test memory region 561450897000 (135168 bytes)
*** Preparing to test memory region 7f2048000000 (2134016 bytes)
*** Preparing to test memory region 7f2050000000 (2134016 bytes)
*** Preparing to test memory region 7f2054000000 (3166208 bytes)
*** Preparing to test memory region 7f2058000000 (2142208 bytes)
*** Preparing to test memory region 7f205e680000 (20447232 bytes)
*** Preparing to test memory region 7f205fbb4000 (5767168 bytes)
*** Preparing to test memory region 7f2060135000 (8388608 bytes)
*** Preparing to test memory region 7f2060936000 (8388608 bytes)
*** Preparing to test memory region 7f2061137000 (8388608 bytes)
*** Preparing to test memory region 7f2061938000 (8388608 bytes)
*** Preparing to test memory region 7f2062139000 (8388608 bytes)
*** Preparing to test memory region 7f206293a000 (8388608 bytes)
*** Preparing to test memory region 7f206313b000 (8388608 bytes)
*** Preparing to test memory region 7f20641fd000 (12288 bytes)
*** Preparing to test memory region 7f2064200000 (8388608 bytes)
*** Preparing to test memory region 7f2064b1d000 (24576 bytes)
*** Preparing to test memory region 7f2064ce0000 (16384 bytes)
*** Preparing to test memory region 7f2064d01000 (16384 bytes)
*** Preparing to test memory region 7f2064e97000 (8192 bytes)
*** Preparing to test memory region 7f2064e9a000 (4096 bytes)
*** Preparing to test memory region 7f2064ec4000 (4096 bytes)
.O.O.O.O.O.O.O.O.O.O.O.O.O.

If you need my data to reproduce this, please contact me privately.

[dandago]

Update: I've reproduced it on a much simpler example.

From redis-cli:

First, create some data (example copied from my own blog post):

GRAPH.QUERY TomLovesJudy "CREATE (tom:Person {name: 'Tom'})-[:loves]->(judy:Person {name: 'Judy'})"

Then, just concatenate a string to a COUNT() function call:

GRAPH.QUERY TomLovesJudy "MATCH (p) RETURN p.name + COUNT(p)"

[jeffreylovitz]

Hi @dandago,

Thanks for the report, and sorry about the bug!

This is an issue with the mixing of aggregating functions (COUNT) with non-aggregating functions (+).

We will try to roll out a fix shortly, but for the moment you are able to use the following workaround:

GRAPH.QUERY TomLovesJudy "MATCH (p) WITH p.name AS name, COUNT(p) AS count RETURN name + count"
1) 1) "name + count"
2) 1) 1) "Judy1"
   2) 1) "Tom1"
3) 1) "Query internal execution time: 1974.351112 milliseconds"

GRAPH.QUERY DiseaseGraph "MATCH (p) WITH p.infectedDay AS day, COUNT(p) AS COUNT RETURN 'Infected on day ' + day + ': ' + count"

This puts the aggregation in a different scope than the concatenation function. It's a bit silly, but should be effective until we release a patch!

[jeffreylovitz]

As a quick note on this, while we haven't yet added a fix, this issue now emits a run-time error rather than crashing.