I'm trying to chain timers to create a background thread. Timers work just fine when created via commands but cause a segfault when being created in OnLoad. Tested on both OSX and Linux (5.0.0).
hellotimer.c
#define REDISMODULE_EXPERIMENTAL_API
#include "../redismodule.h"
void timerHandler(RedisModuleCtx *ctx, void *data) {
REDISMODULE_NOT_USED(ctx);
REDISMODULE_NOT_USED(data);
}
int RedisModule_OnLoad(RedisModuleCtx *ctx, RedisModuleString **argv, int argc) {
REDISMODULE_NOT_USED(argv);
REDISMODULE_NOT_USED(argc);
if (RedisModule_Init(ctx, "hellotimer", 1, REDISMODULE_APIVER_1) == REDISMODULE_ERR) return REDISMODULE_ERR;
// Crash
RedisModule_CreateTimer(ctx, 1000, timerHandler, NULL);
return REDISMODULE_OK;
}
$ redis-server --loadmodule ./hellotimer.so
17998:C 30 Oct 2018 17:31:34.263 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
17998:C 30 Oct 2018 17:31:34.263 # Redis version=5.0.0, bits=64, commit=00000000, modified=0, pid=17998, just started
17998:C 30 Oct 2018 17:31:34.263 # Configuration loaded
17998:M 30 Oct 2018 17:31:34.264 * Increased maximum number of open files to 10032 (it was originally set to 7168).
_._
_.-``__ ''-._
_.-`` `. `_. ''-._ Redis 5.0.0 (00000000/0) 64 bit
.-`` .-```. ```\/ _.,_ ''-._
( ' , .-` | `, ) Running in standalone mode
|`-._`-...-` __...-.``-._|'` _.-'| Port: 6379
| `-._ `._ / _.-' | PID: 17998
`-._ `-._ `-./ _.-' _.-'
|`-._`-._ `-.__.-' _.-'_.-'|
| `-._`-._ _.-'_.-' | http://redis.io
`-._ `-._`-.__.-'_.-' _.-'
|`-._`-._ `-.__.-' _.-'_.-'|
| `-._`-._ _.-'_.-' |
`-._ `-._`-.__.-'_.-' _.-'
`-._ `-.__.-' _.-'
`-._ _.-'
`-.__.-'
17998:M 30 Oct 2018 17:31:34.265 # Server initialized
=== REDIS BUG REPORT START: Cut & paste starting from here ===
17998:M 30 Oct 2018 17:31:34.265 # Redis 5.0.0 crashed by signal: 11
17998:M 30 Oct 2018 17:31:34.265 # Crashed running the instruction at: 0x108f2d486
17998:M 30 Oct 2018 17:31:34.265 # Accessing address: 0x10
17998:M 30 Oct 2018 17:31:34.265 # Failed assertion: <no assertion failed> (<no file>:0)
------ STACK TRACE ------
EIP:
0 redis-server 0x0000000108f2d486 RM_CreateTimer + 78
Backtrace:
0 redis-server 0x0000000108f039da logStackTrace + 110
1 redis-server 0x0000000108f03d67 sigsegvHandler + 236
2 libsystem_platform.dylib 0x00007fffc3854b3a _sigtramp + 26
3 ??? 0x00000001188b5978 0x0 + 4706752888
4 hellotimer.so 0x000000010914afde RedisModule_OnLoad + 3118
5 redis-server 0x0000000108f2ef17 moduleLoad + 141
6 redis-server 0x0000000108f2ee5c moduleLoadFromQueue + 69
7 redis-server 0x0000000108ec9d3a main + 1224
8 libdyld.dylib 0x00007fffc3645235 start + 1
9 ??? 0x0000000000000003 0x0 + 3
------ INFO OUTPUT ------
# Server
redis_version:5.0.0
redis_git_sha1:00000000
redis_git_dirty:0
redis_build_id:143ff2006b3719c8
redis_mode:standalone
os:Darwin 16.7.0 x86_64
arch_bits:64
multiplexing_api:kqueue
atomicvar_api:atomic-builtin
gcc_version:4.2.1
process_id:17998
run_id:fc5ed29019ec01298efacd2f4b8b2a3cff005b06
tcp_port:6379
uptime_in_seconds:0
uptime_in_days:0
hz:10
configured_hz:10
lru_clock:14219238
executable:~/redis/src/modules/redis-server
config_file:
# Clients
connected_clients:0
client_recent_max_input_buffer:0
client_recent_max_output_buffer:0
blocked_clients:0
# Memory
used_memory:988096
used_memory_human:964.94K
used_memory_rss:0
used_memory_rss_human:0B
used_memory_peak:988096
used_memory_peak_human:964.94K
used_memory_peak_perc:inf%
used_memory_overhead:988000
used_memory_startup:988000
used_memory_dataset:96
used_memory_dataset_perc:100.00%
allocator_allocated:0
allocator_active:0
allocator_resident:0
total_system_memory:17179869184
total_system_memory_human:16.00G
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:nan
allocator_frag_bytes:0
allocator_rss_ratio:nan
allocator_rss_bytes:0
rss_overhead_ratio:nan
rss_overhead_bytes:0
mem_fragmentation_ratio:nan
mem_fragmentation_bytes:0
mem_not_counted_for_evict:0
mem_replication_backlog:0
mem_clients_slaves:0
mem_clients_normal:0
mem_aof_buffer:0
mem_allocator:libc
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:1540945894
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:0
total_commands_processed:0
instantaneous_ops_per_sec:0
total_net_input_bytes:0
total_net_output_bytes:0
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
evicted_keys:0
keyspace_hits:0
keyspace_misses:0
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:f9a178e8567fc6556ed194efaa4da98ee688d2d4
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.006144
used_cpu_user:0.005941
used_cpu_sys_children:0.000000
used_cpu_user_children:0.000000
# Commandstats
# Cluster
cluster_enabled:0
# Keyspace
------ CLIENT LIST OUTPUT ------
------ REGISTERS ------
17998:M 30 Oct 2018 17:31:34.266 #
RAX:0000000000000000 RBX:00007fff56d438c8
RCX:0000000000000000 RDX:02a92ae800000000
RDI:0000000108fc0000 RSI:00007ff412638be0
RBP:00007fff56d43880 RSP:00007fff56d43660
R8 :0000000000000002 R9 :000000000000038a
R10:00007ff412600000 R11:0000000000000001
R12:0000000000000000 R13:000000010914a3a0
R14:00000000000003e8 R15:00007ff412638be0
RIP:0000000108f2d486 EFL:0000000000010202
CS :000000000000002b FS:0000000000000000 GS:0000000000000000
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d4366f) -> 0000000109080600
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d4366e) -> 000000010907ca00
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d4366d) -> 0000000000000003
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d4366c) -> 0000000108fc0000
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d4366b) -> 0000000000000003
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d4366a) -> 0000000000000000
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d43669) -> 00007fffc37c891f
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d43668) -> 00007fff56d436e0
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d43667) -> 00000000bedcfeef
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d43666) -> 0000000000000000
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d43665) -> 0000000000000000
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d43664) -> 0000000000000000
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d43663) -> 0000000118885b69
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d43662) -> 00007fff56d43800
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d43661) -> 00007fff56d43810
17998:M 30 Oct 2018 17:31:34.266 # (00007fff56d43660) -> 00007fff56d43848
------ DUMPING CODE AROUND EIP ------
Symbol: RM_CreateTimer (base: 0x108f2d438)
Module: /usr/local/bin/redis-server (base 0x108ebc000)
$ xxd -r -p /tmp/dump.hex /tmp/dump.bin
$ objdump --adjust-vma=0x108f2d438 -D -b binary -m i386:x86-64 /tmp/dump.bin
------
17998:M 30 Oct 2018 17:31:34.266 # dump of function (hexdump of 206 bytes):
554889e54157415641554154534881ecf80100004989cc4989d54989f64889fb488b05a9ab0400488b00488945d0bf20000000e80ff1f9ff4989c7488b43084989074d896f084d896710488b4310488b40108b402841894718e8b35cf9ff4969dee80300004801c34c8da5e8fdffff4c8d2df21705004889dfe86723feff488985e8fdffff488b3d54300500ba080000004c89e6e8ca64000048ffc3493b450075d4488b3d37300500488db5e8fdffffba080000004531c04c89f9e88664000048833d38170500ff7479488b350f
Function at 0x108ecc57f is zmalloc
Function at 0x108ec3149 is ustime
Function at 0x108f0f81d is intrev64
Function at 0x108f3399b is raxFind
Function at 0x108f3397e is raxInsert
=== REDIS BUG REPORT END. Make sure to include from START to END. ===
Please report the crash by opening an issue on github:
http://github.com/antirez/redis/issues
Suspect RAM error? Use redis-server --test-memory to verify it.
Segmentation fault: 11
Comment From: itamarhaber
The problem is easy to spot - the ctx's client does not exist during onload so RM_CreateTimer fails trying to read its db id. The fix is harder - @antirez?
Comment From: yossigo
Looks like this was fixed by 096592506e.