Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Redis 4.0 Crash using lua scripting and module redisearch #4127

Open
chameleonbr opened this issue Jul 17, 2017 · 24 comments
Open

Redis 4.0 Crash using lua scripting and module redisearch #4127

chameleonbr opened this issue Jul 17, 2017 · 24 comments

Comments

@chameleonbr
Copy link

chameleonbr commented Jul 17, 2017

Hello, I don't know if is redis bug or module bug, look the crash report:

=== REDIS BUG REPORT START: Cut & paste starting from here ===
25629:M 17 Jul 16:58:46.852 # Redis 4.0.0 crashed by signal: 11
25629:M 17 Jul 16:58:46.852 # Crashed running the instuction at: 0x7fcdd23cb9e4
25629:M 17 Jul 16:58:46.852 # Accessing address: (nil)
25629:M 17 Jul 16:58:46.852 # Failed assertion: <no assertion failed> (<no file>:0)

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

Backtrace:
./redis-4.0.0/src/redis-server *:6370(logStackTrace+0x45)[0x46ab45]
./redis-4.0.0/src/redis-server *:6370(sigsegvHandler+0xb9)[0x46b309]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11390)[0x7fcdd2707390]
/lib/x86_64-linux-gnu/libc.so.6(+0x9f9e4)[0x7fcdd23cb9e4]
./redis-4.0.0/src/redis-server *:6370(luaRedisGenericCommand+0x771)[0x47bb01]
./redis-4.0.0/src/redis-server *:6370[0x4a81b8]
./redis-4.0.0/src/redis-server *:6370[0x4b17b2]
./redis-4.0.0/src/redis-server *:6370[0x4a860d]
./redis-4.0.0/src/redis-server *:6370[0x4a791b]
./redis-4.0.0/src/redis-server *:6370[0x4a876b]
./redis-4.0.0/src/redis-server *:6370(lua_pcall+0x56)[0x4a5e16]
./redis-4.0.0/src/redis-server *:6370(evalGenericCommand+0x437)[0x4792f7]
./redis-4.0.0/src/redis-server *:6370(call+0xa6)[0x42ba26]
./redis-4.0.0/src/redis-server *:6370(processCommand+0x3a7)[0x42c127]
./redis-4.0.0/src/redis-server *:6370(processInputBuffer+0x105)[0x43bc15]
./redis-4.0.0/src/redis-server *:6370(aeProcessEvents+0x13e)[0x42586e]
./redis-4.0.0/src/redis-server *:6370(aeMain+0x2b)[0x425c9b]
./redis-4.0.0/src/redis-server *:6370(main+0x4a6)[0x422866]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf0)[0x7fcdd234c830]
./redis-4.0.0/src/redis-server *:6370(_start+0x29)[0x422b69]

------ INFO OUTPUT ------
# Server
redis_version:4.0.0
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:89346c4e9023f3d9
redis_mode:standalone
os:Linux 4.4.0-77-generic x86_64
arch_bits:64
multiplexing_api:epoll
atomicvar_api:atomic-builtin
gcc_version:5.4.0
process_id:25629
run_id:76a2a3484d45b93a015953e86f9fbf09063feffd
tcp_port:6370
uptime_in_seconds:130
uptime_in_days:0
hz:10
lru_clock:7149302
executable:/home/avila/Downloads/redis_tests/./redis-4.0.0/src/redis-server
config_file:

# Clients
connected_clients:3
client_longest_output_list:0
client_biggest_input_buf:0
blocked_clients:0

# Memory
used_memory:905128
used_memory_human:883.91K
used_memory_rss:14094336
used_memory_rss_human:13.44M
used_memory_peak:925424
used_memory_peak_human:903.73K
used_memory_peak_perc:97.81%
used_memory_overhead:849306
used_memory_startup:765888
used_memory_dataset:55822
used_memory_dataset_perc:40.09%
total_system_memory:12598317056
total_system_memory_human:11.73G
used_memory_lua:96256
used_memory_lua_human:94.00K
maxmemory:0
maxmemory_human:0B
maxmemory_policy:noeviction
mem_fragmentation_ratio:15.57
mem_allocator:jemalloc-4.0.3
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:1500321396
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:5
total_commands_processed:19089
instantaneous_ops_per_sec:0
total_net_input_bytes:5563777
total_net_output_bytes:1079524
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
evicted_keys:0
keyspace_hits:2
keyspace_misses:4
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:5b1f7d9452399af37dc43c220bb267c34f80ace5
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.26
used_cpu_user:0.35
used_cpu_sys_children:0.00
used_cpu_user_children:0.00

# Commandstats
cmdstat_info:calls=4,usec=449,usec_per_call=112.25
cmdstat_eval:calls=4629,usec=149822,usec_per_call=32.37
cmdstat_evalsha:calls=7225,usec=97239,usec_per_call=13.46
cmdstat_script:calls=4,usec=337,usec_per_call=84.25
cmdstat_georadius: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=4 addr=127.0.0.1:41024 fd=10 name= age=116 idle=37 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=FT.CREATE
id=5 addr=127.0.0.1:41088 fd=8 name= age=29 idle=29 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=info
id=6 addr=127.0.0.1:41134 fd=9 name= age=5 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=evalsha

------ CURRENT CLIENT INFO ------
id=6 addr=127.0.0.1:41134 fd=9 name= age=5 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=evalsha
argv[0]: 'evalsha'
argv[1]: '16041cf33267ce19364738e50ef07d96b2d92ca1'
argv[2]: '3'
argv[3]: 'desc'
argv[4]: 'local'
argv[5]: '0,50'
argv[6]: 'coca cola'
argv[7]: '-49.282130766659975,-25.43486732058227,20'
argv[8]: '0'

------ REGISTERS ------
25629:M 17 Jul 16:58:46.854 # 
RAX:0000000000000035 RBX:000000000000000c
RCX:0000000000000006 RDX:0000000000000003
RDI:0000000000000000 RSI:000000000235b538
RBP:000000000000000b RSP:00007ffcf96431c8
R8 :00000000023587e4 R9 :0000000000000001
R10:000000000235d2b0 R11:0000000000000007
R12:0000000000000058 R13:000000000233a540
R14:000000000000000f R15:00007fcdd1b0bc40
RIP:00007fcdd23cb9e4 EFL:0000000000010202
CSGSFS:0000000000000033
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431d7) -> 000000000233a540
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431d6) -> 3262cb72b4f1e100
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431d5) -> 0000000000000003
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431d4) -> 00000000004a5b64
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431d3) -> 000000000235d3d0
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431d2) -> 000000000233a540
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431d1) -> 00000000004a4f95
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431d0) -> 3262cb72b4f1e100
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431cf) -> 000000000235ca1c
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431ce) -> 0000000000000003
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431cd) -> 4008000000000000
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431cc) -> 0000000000000002
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431cb) -> 000000000235d3d0
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431ca) -> 00000001004aed78
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431c9) -> 000000000235ca34
25629:M 17 Jul 16:58:46.854 # (00007ffcf96431c8) -> 000000000047bb01

------ FAST MEMORY TEST ------
25629:M 17 Jul 16:58:46.855 # Bio thread for job type #0 terminated
25629:M 17 Jul 16:58:46.855 # Bio thread for job type #1 terminated
25629:M 17 Jul 16:58:46.855 # Bio thread for job type #2 terminated
*** Preparing to test memory region 757000 (98304 bytes)
*** Preparing to test memory region 2337000 (270336 bytes)
*** Preparing to test memory region 7fcd98000000 (135168 bytes)
*** Preparing to test memory region 7fcd9ce00000 (2097152 bytes)
*** Preparing to test memory region 7fcd9d1f2000 (8388608 bytes)
*** Preparing to test memory region 7fcd9df03000 (8388608 bytes)
*** Preparing to test memory region 7fcd9e704000 (8388608 bytes)
*** Preparing to test memory region 7fcd9ef05000 (8388608 bytes)
*** Preparing to test memory region 7fcd9f706000 (8388608 bytes)
*** Preparing to test memory region 7fcd9ff07000 (8388608 bytes)
*** Preparing to test memory region 7fcda0708000 (8388608 bytes)
*** Preparing to test memory region 7fcda0f09000 (8388608 bytes)
*** Preparing to test memory region 7fcda170a000 (8388608 bytes)
*** Preparing to test memory region 7fcda1f0b000 (8388608 bytes)
*** Preparing to test memory region 7fcda270c000 (8388608 bytes)
*** Preparing to test memory region 7fcda2f0d000 (8388608 bytes)
*** Preparing to test memory region 7fcda370e000 (8388608 bytes)
*** Preparing to test memory region 7fcda3f0f000 (8388608 bytes)
*** Preparing to test memory region 7fcda4710000 (8388608 bytes)
*** Preparing to test memory region 7fcda4f11000 (8388608 bytes)
*** Preparing to test memory region 7fcda5712000 (8388608 bytes)
*** Preparing to test memory region 7fcda5f13000 (8388608 bytes)
*** Preparing to test memory region 7fcda6714000 (8388608 bytes)
*** Preparing to test memory region 7fcda6f15000 (8388608 bytes)
*** Preparing to test memory region 7fcda7716000 (8388608 bytes)
*** Preparing to test memory region 7fcda7f17000 (8388608 bytes)
*** Preparing to test memory region 7fcda8718000 (8388608 bytes)
*** Preparing to test memory region 7fcda8f19000 (8388608 bytes)
*** Preparing to test memory region 7fcda971a000 (8388608 bytes)
*** Preparing to test memory region 7fcda9f1b000 (8388608 bytes)
*** Preparing to test memory region 7fcdaa71c000 (8388608 bytes)
*** Preparing to test memory region 7fcdaaf1d000 (8388608 bytes)
*** Preparing to test memory region 7fcdab71e000 (8388608 bytes)
*** Preparing to test memory region 7fcdabf1f000 (8388608 bytes)
*** Preparing to test memory region 7fcdac720000 (8388608 bytes)
*** Preparing to test memory region 7fcdacf21000 (8388608 bytes)
*** Preparing to test memory region 7fcdad722000 (8388608 bytes)
*** Preparing to test memory region 7fcdadf23000 (8388608 bytes)
*** Preparing to test memory region 7fcdae724000 (8388608 bytes)
*** Preparing to test memory region 7fcdaef25000 (8388608 bytes)
*** Preparing to test memory region 7fcdaf726000 (8388608 bytes)
*** Preparing to test memory region 7fcdaff27000 (8388608 bytes)
*** Preparing to test memory region 7fcdb0728000 (8388608 bytes)
*** Preparing to test memory region 7fcdb0f29000 (8388608 bytes)
*** Preparing to test memory region 7fcdb172a000 (8388608 bytes)
*** Preparing to test memory region 7fcdb1f2b000 (8388608 bytes)
*** Preparing to test memory region 7fcdb272c000 (8388608 bytes)
*** Preparing to test memory region 7fcdb2f2d000 (8388608 bytes)
*** Preparing to test memory region 7fcdb372e000 (8388608 bytes)
*** Preparing to test memory region 7fcdb3f2f000 (8388608 bytes)
*** Preparing to test memory region 7fcdb4730000 (8388608 bytes)
*** Preparing to test memory region 7fcdb4f31000 (8388608 bytes)
*** Preparing to test memory region 7fcdb5732000 (8388608 bytes)
*** Preparing to test memory region 7fcdb5f33000 (8388608 bytes)
*** Preparing to test memory region 7fcdb6734000 (8388608 bytes)
*** Preparing to test memory region 7fcdb6f35000 (8388608 bytes)
*** Preparing to test memory region 7fcdb7736000 (8388608 bytes)
*** Preparing to test memory region 7fcdb7f37000 (8388608 bytes)
*** Preparing to test memory region 7fcdb8738000 (8388608 bytes)
*** Preparing to test memory region 7fcdb8f39000 (8388608 bytes)
*** Preparing to test memory region 7fcdb973a000 (8388608 bytes)
*** Preparing to test memory region 7fcdb9f3b000 (8388608 bytes)
*** Preparing to test memory region 7fcdba73c000 (8388608 bytes)
*** Preparing to test memory region 7fcdbaf3d000 (8388608 bytes)
*** Preparing to test memory region 7fcdbb73e000 (8388608 bytes)
*** Preparing to test memory region 7fcdbbf3f000 (8388608 bytes)
*** Preparing to test memory region 7fcdbc740000 (8388608 bytes)
*** Preparing to test memory region 7fcdbcf41000 (8388608 bytes)
*** Preparing to test memory region 7fcdbd742000 (8388608 bytes)
*** Preparing to test memory region 7fcdbdf43000 (8388608 bytes)
*** Preparing to test memory region 7fcdbe744000 (8388608 bytes)
*** Preparing to test memory region 7fcdbef45000 (8388608 bytes)
*** Preparing to test memory region 7fcdbf746000 (8388608 bytes)
*** Preparing to test memory region 7fcdbff47000 (8388608 bytes)
*** Preparing to test memory region 7fcdc0748000 (8388608 bytes)
*** Preparing to test memory region 7fcdc0f49000 (8388608 bytes)
*** Preparing to test memory region 7fcdc174a000 (8388608 bytes)
*** Preparing to test memory region 7fcdc1f4b000 (8388608 bytes)
*** Preparing to test memory region 7fcdc274c000 (8388608 bytes)
*** Preparing to test memory region 7fcdc2f4d000 (8388608 bytes)
*** Preparing to test memory region 7fcdc374e000 (8388608 bytes)
*** Preparing to test memory region 7fcdc3f4f000 (8388608 bytes)
*** Preparing to test memory region 7fcdc4750000 (8388608 bytes)
*** Preparing to test memory region 7fcdc4f51000 (8388608 bytes)
*** Preparing to test memory region 7fcdc5752000 (8388608 bytes)
*** Preparing to test memory region 7fcdc5f53000 (8388608 bytes)
*** Preparing to test memory region 7fcdc6754000 (8388608 bytes)
*** Preparing to test memory region 7fcdc6f55000 (8388608 bytes)
*** Preparing to test memory region 7fcdc7756000 (8388608 bytes)
*** Preparing to test memory region 7fcdc7f57000 (8388608 bytes)
*** Preparing to test memory region 7fcdc8758000 (8388608 bytes)
*** Preparing to test memory region 7fcdc8f59000 (8388608 bytes)
*** Preparing to test memory region 7fcdc975a000 (8388608 bytes)
*** Preparing to test memory region 7fcdc9f5b000 (8388608 bytes)
*** Preparing to test memory region 7fcdca75c000 (8388608 bytes)
*** Preparing to test memory region 7fcdcaf5d000 (8388608 bytes)
*** Preparing to test memory region 7fcdcb75e000 (8388608 bytes)
*** Preparing to test memory region 7fcdcbf5f000 (8388608 bytes)
*** Preparing to test memory region 7fcdcc760000 (8388608 bytes)
*** Preparing to test memory region 7fcdccf61000 (8388608 bytes)
*** Preparing to test memory region 7fcdcd762000 (8388608 bytes)
*** Preparing to test memory region 7fcdcdf63000 (8388608 bytes)
*** Preparing to test memory region 7fcdce764000 (8388608 bytes)
*** Preparing to test memory region 7fcdcef65000 (8388608 bytes)
*** Preparing to test memory region 7fcdcf766000 (8388608 bytes)
*** Preparing to test memory region 7fcdd01fc000 (4096 bytes)
*** Preparing to test memory region 7fcdd01fe000 (8388608 bytes)
*** Preparing to test memory region 7fcdd09ff000 (8388608 bytes)
*** Preparing to test memory region 7fcdd1200000 (10485760 bytes)
*** Preparing to test memory region 7fcdd2000000 (2097152 bytes)
*** Preparing to test memory region 7fcdd26f2000 (16384 bytes)
*** Preparing to test memory region 7fcdd290f000 (16384 bytes)
*** Preparing to test memory region 7fcdd3017000 (16384 bytes)
*** Preparing to test memory region 7fcdd3043000 (8192 bytes)
*** Preparing to test memory region 7fcdd3047000 (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.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.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: /lib/x86_64-linux-gnu/libc.so.6 (base 0x7fcdd232c000)
$ 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. ===

@dvirsky
Copy link
Contributor

dvirsky commented Jul 17, 2017

hey @chameleonbr, can you share the lua script creating this crash? (I'm the author of the module. I've never tested them together but it might be an inherent problem with the execution model of redisearch)

@dvirsky
Copy link
Contributor

dvirsky commented Jul 17, 2017

@antirez I've managed to recreate it - calling redis searches from lua crashes redis. looks like something with the fact that the search blocks the client.

@chameleonbr
Copy link
Author

chameleonbr commented Jul 17, 2017

Yes.

-- key  produtos 
-- FT.CREATE produtos SCHEMA cnpj TEXT cditem TEXT unidade TEXT desc TEXT local GEO timestamp NUMERIC SORTABLE uf TEXT valor NUMERIC SORTABLE valor_tabela NUMERIC idnfe TEXT cdanp TEXT ncm TEXT nprot TEXT gtin TEXT valor_desconto NUMERIC

local function split(pString, pPattern)
   local Table = {}
   local fpat = "(.-)" .. pPattern
   local last_end = 1
   local s, e, cap = pString:find(fpat, 1)
   while s do
      if s ~= 1 or cap ~= "" then
     table.insert(Table,cap)
      end
      last_end = e+1
      s, e, cap = pString:find(fpat, last_end)
   end
   if last_end <= #pString then
      cap = pString:sub(last_end)
      table.insert(Table, cap)
   end
   return Table
end

local term1 = '@'..KEYS[1]..':'..ARGV[1]
local term2 = nil
local limit = nil
local order = nil
local result = nil

if KEYS[2] == "estab" then
    term2 = '@'..KEYS[2]..':'..ARGV[2]
end

if KEYS[3] then
    limit = split(KEYS[3],',')
end

if ARGV[3] then
    order = split(ARGV[3],',')
end

if KEYS[2] == "local" then
    local geo = split(ARGV[2],',')
    result = redis.call('FT.SEARCH','produtos',term1,'GEOFILTER','local',geo[1],geo[2],geo[3],'km','LIMIT',limit[1],limit[2], 'ORDERBY',order[1],order[2])
else
    result = redis.call('FT.SEARCH','produtos',term1,term2,'LIMIT',limit[1],limit[2], 'ORDERBY',order[1],order[2])
end

return result
-- or return cjson.encode(result)

@chameleonbr
Copy link
Author

Seizing the opportunity, is it in your plans to order by radius?

@dvirsky
Copy link
Contributor

dvirsky commented Jul 17, 2017

Doesn't seem to be directly related to redisearch actually. the crash is here:

in scripting.c

/* Try to use a cached object. */
   407 	        if (j < LUA_CMD_OBJCACHE_SIZE && cached_objects[j] &&
   408 	            cached_objects_len[j] >= obj_len)
   409 	        {
   410 	            sds s = cached_objects[j]->ptr;
   411 	            argv[j] = cached_objects[j];
   412 	            cached_objects[j] = NULL;
   413 	            ==========>>> memcpy(s,obj_s,obj_len+1);
   414 	            sdssetlen(s, obj_len);
   415 	        } else {
   416 	            argv[j] = createStringObject(obj_s, obj_len);
   417 	        }

now, from what I see, cached_objects_len[j] is 9, obj_len is 9, and redis is doing memcpy(s,obj_s,obj_len+1). Isn't this an an overflow of one? Or does cached_objects_len[j] not include the null terminator? Seems like something deeper, double free or something. Doesn't seem directly related to redisearch, but more of a general module thing I think.

and @chameleonbr no such plans currently, but you can write your own scoring function and extend redisearch with it!

PS full stack trace:

* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=2, address=0x1000de3a0)
  * frame #0: 0x00007fffab337f44 libsystem_platform.dylib`_platform_memmove$VARIANT$Haswell + 164
    frame #1: 0x00007fffab1e042e libsystem_c.dylib`__memcpy_chk + 22
    frame #2: 0x000000010007969f redis-server`luaRedisGenericCommand(lua=0x0000000100603600, raise_error=1) at scripting.c:413
    frame #3: 0x000000010007a3aa redis-server`luaRedisCallCommand(lua=0x0000000100603600) at scripting.c:635
    frame #4: 0x00000001000c0b84 redis-server`luaD_precall + 596
    frame #5: 0x00000001000cd542 redis-server`luaV_execute + 2690
    frame #6: 0x00000001000c1222 redis-server`luaD_call + 98
    frame #7: 0x00000001000c0675 redis-server`luaD_rawrunprotected + 85
    frame #8: 0x00000001000c153a redis-server`luaD_pcall + 58
    frame #9: 0x00000001000bc0e5 redis-server`lua_pcall + 277
    frame #10: 0x000000010007c17a redis-server`evalGenericCommand(c=0x000000012d92b800, evalsha=0) at scripting.c:1318
    frame #11: 0x000000010007c75f redis-server`evalCommand(c=0x000000012d92b800) at scripting.c:1401
    frame #12: 0x00000001000108b7 redis-server`call(c=0x000000012d92b800, flags=15) at server.c:2199
    frame #13: 0x000000010001164c redis-server`processCommand(c=0x000000012d92b800) at server.c:2479
    frame #14: 0x0000000100024f3b redis-server`processInputBuffer(c=0x000000012d92b800) at networking.c:1330

EDIT: Looks like something with blocking commands. the helloworld module worked fine with lua, the helloblock didn't.

@itamarhaber
Copy link
Member

Looks like someone else got smacked by this or similar: https://www.reddit.com/r/redis/comments/6on853/what_is_the_module_response_format_specifically/

@antirez
Copy link
Contributor

antirez commented Jul 23, 2017

HI all, any one-liner to reproduce it with clear instructions?

@dvirsky
Copy link
Contributor

dvirsky commented Jul 23, 2017

@antirez

  1. load your helloblock module
  2. call it using EVAL
127.0.0.1:6379> eval "redis.call('HELLO.BLOCK', 1, 1)" 0
(nil)
127.0.0.1:6379> eval "redis.call('HELLO.BLOCK', 1, 1)" 0
Could not connect to Redis at 127.0.0.1:6379: Connection refused

@antirez
Copy link
Contributor

antirez commented Jul 23, 2017

@dvirsky ok so it's a blocking thing? All the Redis blocking commands are flagged as "s", not executable in Lua scripts, so looks like the problem is that we are allowing to do that... There is no explicit blocking flag in the Redis command flag, but we can add a flag in the module API that will just map to the "s" flag (no scripting).

@dvirsky
Copy link
Contributor

dvirsky commented Jul 23, 2017

I wonder if there is now a case for actually doing it - the search query being the use case. it's blocking just for the sake of concurrency, it's not a long running command. Calling it from lua will just make it non concurrent, but will do no harm, it's not SUBSCRIBE or BLPOP. If it's possible technically maybe it's worth allowing this explicitly by the module author.

@antirez
Copy link
Contributor

antirez commented Jul 23, 2017

Not sure if it is possible to dynamically trap the fact that blockClient() is called in the context of a Lua script and try to recover from that. Looks hard-ish since the command cannot fail, but there are potentially things we could do actually. Like create a blocked client context with "client" set to NULL (this happens if a client is terminated between blocking and unblocking), and actually replying to the Lua client ASAP with "-ERR module blocking command called from Lua script". I can give it a try...

@antirez
Copy link
Contributor

antirez commented Jul 23, 2017

@dvirsky if we allow the command to sense a Lua script, it can just avoid blocking.

@dvirsky
Copy link
Contributor

dvirsky commented Jul 23, 2017

didn't @oranagra add this to his fork and suggest it as an addition?

@antirez
Copy link
Contributor

antirez commented Jul 23, 2017

yes, he suggested this addition, and I agree, via the RedisModule_GetClientFlags() API, so that multiple conditions are returned: lua, master, slave, ...

@dvirsky
Copy link
Contributor

dvirsky commented Jul 23, 2017

So immediate fix - fail in lua somehow? longer term fix - allow the module to know it's a lua script and avoid blocking if it can. right?

@antirez
Copy link
Contributor

antirez commented Jul 23, 2017

Yes, looks like it's the way to go. I'm trying to implement the first part so to release 4.0.1 between today and tomorrow with the other two important fixes (already inside).

@dvirsky
Copy link
Contributor

dvirsky commented Jul 23, 2017

Thanks. BTW in one of the cases of people calling search from lua it turned out the user wanted to implement in Lua stuff that redisearch already does, so a little guidance on advanced RS capabilities allowed them to achieve what they wanted initially.

@antirez
Copy link
Contributor

antirez commented Jul 23, 2017

Good, many things will likely be indeed false positives, and modules doc is not stellar... All the part about async contexts is missing (but is also marked as experimental). I'll try to make it better in the next weeks, but more likely I'll be able to improve it significantly after mid September.

@antirez
Copy link
Contributor

antirez commented Jul 23, 2017

Just pushed a fix, looks good and uses already built-in mechanisms so should not fail spectacularly I hope.

antirez added a commit that referenced this issue Jul 23, 2017
Lua scripting does not support calling blocking commands, however all
the native Redis commands are flagged as "s" (no scripting flag), so
this is not possible at all. With modules there is no such mechanism in
order to flag a command as non callable by the Lua scripting engine,
moreover we cannot trust the modules users from complying all the times:
it is likely that modules will be released to have blocking commands
without such commands being flagged correctly, even if we provide a way to
signal this fact.

This commit attempts to address the problem in a short term way, by
detecting that a module is trying to block in the context of the Lua
scripting engine client, and preventing to do this. The module will
actually believe to block as usually, but what happens is that the Lua
script receives an error immediately, and the background call is ignored
by the Redis engine (if not for the cleanup callbacks, once it
unblocks).

Long term, the more likely solution, is to introduce a new call called
RedisModule_GetClientFlags(), so that a command can detect if the caller
is a Lua script, and return an error, or avoid blocking at all.

Being the blocking API experimental right now, more work is needed in
this regard in order to reach a level well blocking module commands and
all the other Redis subsystems interact peacefully.

Now the effect is like the following:

    127.0.0.1:6379> eval "redis.call('hello.block',1,5000)" 0
    (error) ERR Error running script (call to
    f_b5ba35ff97bc1ef23debc4d6e9fd802da187ed53): @user_script:1: ERR
    Blocking module command called from Lua script

This commit fixes issue #4127 in the short term.
antirez added a commit that referenced this issue Jul 23, 2017
Lua scripting does not support calling blocking commands, however all
the native Redis commands are flagged as "s" (no scripting flag), so
this is not possible at all. With modules there is no such mechanism in
order to flag a command as non callable by the Lua scripting engine,
moreover we cannot trust the modules users from complying all the times:
it is likely that modules will be released to have blocking commands
without such commands being flagged correctly, even if we provide a way to
signal this fact.

This commit attempts to address the problem in a short term way, by
detecting that a module is trying to block in the context of the Lua
scripting engine client, and preventing to do this. The module will
actually believe to block as usually, but what happens is that the Lua
script receives an error immediately, and the background call is ignored
by the Redis engine (if not for the cleanup callbacks, once it
unblocks).

Long term, the more likely solution, is to introduce a new call called
RedisModule_GetClientFlags(), so that a command can detect if the caller
is a Lua script, and return an error, or avoid blocking at all.

Being the blocking API experimental right now, more work is needed in
this regard in order to reach a level well blocking module commands and
all the other Redis subsystems interact peacefully.

Now the effect is like the following:

    127.0.0.1:6379> eval "redis.call('hello.block',1,5000)" 0
    (error) ERR Error running script (call to
    f_b5ba35ff97bc1ef23debc4d6e9fd802da187ed53): @user_script:1: ERR
    Blocking module command called from Lua script

This commit fixes issue #4127 in the short term.
@itamarhaber
Copy link
Member

I would have thought of solving this with an explicit flag in command registration.

@antirez
Copy link
Contributor

antirez commented Jul 23, 2017

@itamarhaber as outlined in the commit message, you can't trust modules to behave, and if they do not flag commands appropriately, this resulting into a crash is unfortunate given that this can be avoided with such a small patch. So an additional mechanism (that will more likely be the ability to detect Lua scripts) is welcome but this fundamental check is needed as well in my opinion.

@itamarhaber
Copy link
Member

Both then - well-behaved modules can declare it and a failsafe check against anyone else is a perfect combo :)

GitHubMota pushed a commit to GitHubMota/redis that referenced this issue Jul 25, 2017
Lua scripting does not support calling blocking commands, however all
the native Redis commands are flagged as "s" (no scripting flag), so
this is not possible at all. With modules there is no such mechanism in
order to flag a command as non callable by the Lua scripting engine,
moreover we cannot trust the modules users from complying all the times:
it is likely that modules will be released to have blocking commands
without such commands being flagged correctly, even if we provide a way to
signal this fact.

This commit attempts to address the problem in a short term way, by
detecting that a module is trying to block in the context of the Lua
scripting engine client, and preventing to do this. The module will
actually believe to block as usually, but what happens is that the Lua
script receives an error immediately, and the background call is ignored
by the Redis engine (if not for the cleanup callbacks, once it
unblocks).

Long term, the more likely solution, is to introduce a new call called
RedisModule_GetClientFlags(), so that a command can detect if the caller
is a Lua script, and return an error, or avoid blocking at all.

Being the blocking API experimental right now, more work is needed in
this regard in order to reach a level well blocking module commands and
all the other Redis subsystems interact peacefully.

Now the effect is like the following:

    127.0.0.1:6379> eval "redis.call('hello.block',1,5000)" 0
    (error) ERR Error running script (call to
    f_b5ba35ff97bc1ef23debc4d6e9fd802da187ed53): @user_script:1: ERR
    Blocking module command called from Lua script

This commit fixes issue redis#4127 in the short term.
@antirez
Copy link
Contributor

antirez commented Jul 28, 2017

NOTE: This is fixed but left open for further considering what to do in the future.

JackieXie168 pushed a commit to JackieXie168/redis that referenced this issue Aug 20, 2017
Lua scripting does not support calling blocking commands, however all
the native Redis commands are flagged as "s" (no scripting flag), so
this is not possible at all. With modules there is no such mechanism in
order to flag a command as non callable by the Lua scripting engine,
moreover we cannot trust the modules users from complying all the times:
it is likely that modules will be released to have blocking commands
without such commands being flagged correctly, even if we provide a way to
signal this fact.

This commit attempts to address the problem in a short term way, by
detecting that a module is trying to block in the context of the Lua
scripting engine client, and preventing to do this. The module will
actually believe to block as usually, but what happens is that the Lua
script receives an error immediately, and the background call is ignored
by the Redis engine (if not for the cleanup callbacks, once it
unblocks).

Long term, the more likely solution, is to introduce a new call called
RedisModule_GetClientFlags(), so that a command can detect if the caller
is a Lua script, and return an error, or avoid blocking at all.

Being the blocking API experimental right now, more work is needed in
this regard in order to reach a level well blocking module commands and
all the other Redis subsystems interact peacefully.

Now the effect is like the following:

    127.0.0.1:6379> eval "redis.call('hello.block',1,5000)" 0
    (error) ERR Error running script (call to
    f_b5ba35ff97bc1ef23debc4d6e9fd802da187ed53): @user_script:1: ERR
    Blocking module command called from Lua script

This commit fixes issue redis#4127 in the short term.
JunHe77 pushed a commit to JunHe77/redis that referenced this issue Dec 1, 2017
Lua scripting does not support calling blocking commands, however all
the native Redis commands are flagged as "s" (no scripting flag), so
this is not possible at all. With modules there is no such mechanism in
order to flag a command as non callable by the Lua scripting engine,
moreover we cannot trust the modules users from complying all the times:
it is likely that modules will be released to have blocking commands
without such commands being flagged correctly, even if we provide a way to
signal this fact.

This commit attempts to address the problem in a short term way, by
detecting that a module is trying to block in the context of the Lua
scripting engine client, and preventing to do this. The module will
actually believe to block as usually, but what happens is that the Lua
script receives an error immediately, and the background call is ignored
by the Redis engine (if not for the cleanup callbacks, once it
unblocks).

Long term, the more likely solution, is to introduce a new call called
RedisModule_GetClientFlags(), so that a command can detect if the caller
is a Lua script, and return an error, or avoid blocking at all.

Being the blocking API experimental right now, more work is needed in
this regard in order to reach a level well blocking module commands and
all the other Redis subsystems interact peacefully.

Now the effect is like the following:

    127.0.0.1:6379> eval "redis.call('hello.block',1,5000)" 0
    (error) ERR Error running script (call to
    f_b5ba35ff97bc1ef23debc4d6e9fd802da187ed53): @user_script:1: ERR
    Blocking module command called from Lua script

This commit fixes issue redis#4127 in the short term.
JackieXie168 pushed a commit to JackieXie168/redis that referenced this issue Jan 13, 2018
Lua scripting does not support calling blocking commands, however all
the native Redis commands are flagged as "s" (no scripting flag), so
this is not possible at all. With modules there is no such mechanism in
order to flag a command as non callable by the Lua scripting engine,
moreover we cannot trust the modules users from complying all the times:
it is likely that modules will be released to have blocking commands
without such commands being flagged correctly, even if we provide a way to
signal this fact.

This commit attempts to address the problem in a short term way, by
detecting that a module is trying to block in the context of the Lua
scripting engine client, and preventing to do this. The module will
actually believe to block as usually, but what happens is that the Lua
script receives an error immediately, and the background call is ignored
by the Redis engine (if not for the cleanup callbacks, once it
unblocks).

Long term, the more likely solution, is to introduce a new call called
RedisModule_GetClientFlags(), so that a command can detect if the caller
is a Lua script, and return an error, or avoid blocking at all.

Being the blocking API experimental right now, more work is needed in
this regard in order to reach a level well blocking module commands and
all the other Redis subsystems interact peacefully.

Now the effect is like the following:

    127.0.0.1:6379> eval "redis.call('hello.block',1,5000)" 0
    (error) ERR Error running script (call to
    f_b5ba35ff97bc1ef23debc4d6e9fd802da187ed53): @user_script:1: ERR
    Blocking module command called from Lua script

This commit fixes issue redis#4127 in the short term.
@itamarhaber
Copy link
Member

@gkorland @swilly22 @MeirShpilraien - is there anything else left to discuss here, from your POVs?

pulllock pushed a commit to pulllock/redis that referenced this issue Jun 28, 2023
Lua scripting does not support calling blocking commands, however all
the native Redis commands are flagged as "s" (no scripting flag), so
this is not possible at all. With modules there is no such mechanism in
order to flag a command as non callable by the Lua scripting engine,
moreover we cannot trust the modules users from complying all the times:
it is likely that modules will be released to have blocking commands
without such commands being flagged correctly, even if we provide a way to
signal this fact.

This commit attempts to address the problem in a short term way, by
detecting that a module is trying to block in the context of the Lua
scripting engine client, and preventing to do this. The module will
actually believe to block as usually, but what happens is that the Lua
script receives an error immediately, and the background call is ignored
by the Redis engine (if not for the cleanup callbacks, once it
unblocks).

Long term, the more likely solution, is to introduce a new call called
RedisModule_GetClientFlags(), so that a command can detect if the caller
is a Lua script, and return an error, or avoid blocking at all.

Being the blocking API experimental right now, more work is needed in
this regard in order to reach a level well blocking module commands and
all the other Redis subsystems interact peacefully.

Now the effect is like the following:

    127.0.0.1:6379> eval "redis.call('hello.block',1,5000)" 0
    (error) ERR Error running script (call to
    f_b5ba35ff97bc1ef23debc4d6e9fd802da187ed53): @user_script:1: ERR
    Blocking module command called from Lua script

This commit fixes issue redis#4127 in the short term.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants