antirez / disque

Disque is a distributed message broker
BSD 3-Clause "New" or "Revised" License
8.01k stars 537 forks source link

Segfault when CONFIG SET maxmemory #123

Closed mp911de closed 8 years ago

mp911de commented 9 years ago

Running into segfaults when trying to change the maxmemory param using CONFIG SET. This happens presumably in cases of increasing and reducing memory.

Decrease

28741:P 25 Sep 12:56:18.505 * Increased maximum number of open files to 10032 (it was originally set to 256).
28741:P 25 Sep 12:56:18.506 * Node configuration loaded, I'm a4774e27851a6fc1c8fdaf68cf5a9b0d40dd6788
                                        Disque 0.0.1 (338561bc/0) 64 bit
          _ -                                                        
        .                               Port: 7711
        .    o    .                     PID: 28741
                 .                                                   
               -                              http://disque.io       

28741:P 25 Sep 12:56:18.507 # Server started, Disque version 0.0.1
28741:P 25 Sep 12:56:18.507 * The server is now ready to accept connections on port 7711
28741:P 25 Sep 12:56:18.507 * The server is now ready to accept connections at /Users/mpaluch/git/spinach/work/disque-7711/socket
28741:P 25 Sep 12:56:22.882 # WARNING: the new maxmemory value set via CONFIG SET is smaller than the current memory usage. This will result in keys eviction and/or inability to accept new write commands depending on the maxmemory-policy.
28741:P 25 Sep 12:56:22.882 # 

=== DISQUE BUG REPORT START: Cut & paste starting from here ===
28741:P 25 Sep 12:56:22.882 #     Disque 0.0.1 crashed by signal: 11
28741:P 25 Sep 12:56:22.882 #     Failed assertion: <no assertion failed> (<no file>:0)
28741:P 25 Sep 12:56:22.882 # --- STACK TRACE
0   disque-server                       0x0000000105d8c427 logStackTrace + 103
1   disque-server                       0x0000000105d75b87 freeMemoryIfNeeded + 263
2   libsystem_platform.dylib            0x00007fff84446f1a _sigtramp + 26
3   ???                                 0x00007fff59e91de0 0x0 + 140734701837792
4   disque-server                       0x0000000105d85f63 configSetCommand + 2531
5   disque-server                       0x0000000105d757f4 call + 116
6   disque-server                       0x0000000105d75a2f processCommand + 367
7   disque-server                       0x0000000105d80c55 processInputBuffer + 293
8   disque-server                       0x0000000105d6f1a6 aeProcessEvents + 678
9   disque-server                       0x0000000105d6f49b aeMain + 43
10  disque-server                       0x0000000105d777a2 main + 914
11  libdyld.dylib                       0x00007fff8f5275c9 start + 1
12  ???                                 0x0000000000000002 0x0 + 2
28741:P 25 Sep 12:56:22.883 # --- INFO OUTPUT
28741:P 25 Sep 12:56:22.883 # # Server
disque_version:0.0.1
disque_git_sha1:338561bc
disque_git_dirty:0
disque_build_id:9c90a64d1bc33a43
os:Darwin 14.5.0 x86_64
arch_bits:64
multiplexing_api:kqueue
gcc_version:4.2.1
process_id:28741
run_id:df2bd41f256d9f1db187f93ccb63b7748fa752f1
tcp_port:7711
uptime_in_seconds:4
uptime_in_days:0
hz:10
config_file:/Users/mpaluch/git/spinach/work/disque-7711/disque.conf

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

# Memory
used_memory:959088
used_memory_human:936.61K
used_memory_rss:1425408
used_memory_peak:959088
used_memory_peak_human:936.61K
mem_fragmentation_ratio:1.49
mem_allocator:libc

# Jobs
registered_jobs:0

# Queues
registered_queues:0

# Persistence
loading:0
aof_enabled:0
aof_state:off
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

# Stats
total_connections_received:2
total_commands_processed:3
instantaneous_ops_per_sec:0
total_net_input_bytes:170
total_net_output_bytes:46
instantaneous_input_kbps:0.00
instantaneous_output_kbps:0.00
rejected_connections:0
latest_fork_usec:0

# CPU
used_cpu_sys:0.00
used_cpu_user:0.00
used_cpu_sys_children:0.00
used_cpu_user_children:0.00

# Commandstats
cmdstat_debug:calls=1,usec=8,usec_per_call=8.00
cmdstat_config:calls=1,usec=21,usec_per_call=21.00
cmdstat_cluster:calls=1,usec=21,usec_per_call=21.00
hash_init_value: 1443022560

28741:P 25 Sep 12:56:22.883 # --- CLIENT LIST OUTPUT
28741:P 25 Sep 12:56:22.883 # id=2 addr=127.0.0.1:55290 fd=11 name= age=0 idle=0 flags=N qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=config

28741:P 25 Sep 12:56:22.883 # --- CURRENT CLIENT INFO
28741:P 25 Sep 12:56:22.883 # client: id=2 addr=127.0.0.1:55290 fd=11 name= age=0 idle=0 flags=N qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=config
28741:P 25 Sep 12:56:22.883 # argv[0]: 'CONFIG'
28741:P 25 Sep 12:56:22.883 # argv[1]: 'SET'
28741:P 25 Sep 12:56:22.883 # argv[2]: 'maxmemory'
28741:P 25 Sep 12:56:22.883 # argv[3]: '100'
28741:P 25 Sep 12:56:22.883 # --- REGISTERS
28741:P 25 Sep 12:56:22.883 # 
RAX:00000000000e9f50 RBX:0000000000000000
RCX:0000000000000000 RDX:0000000000000001
RDI:00007ff96b528290 RSI:00001a0000001a00
RBP:00007fff59e92220 RSP:00007fff59e921e0
R8 :00007fff59e91c30 R9 :00007fff73c72300
R10:0000000105dd8668 R11:0000000000000040
R12:00000000000e9ef1 R13:00000000000e9f50
R14:0000000000000000 R15:0000000000000000
RIP:0000000105d75b87 EFL:0000000000010246
CS :000000000000002b FS:0000000000000000  GS:0000000000000000
28741:P 25 Sep 12:56:22.883 # (00007fff59e921ef) -> fffadf6fcd45be80
28741:P 25 Sep 12:56:22.883 # (00007fff59e921ee) -> 0000000000000064
28741:P 25 Sep 12:56:22.883 # (00007fff59e921ed) -> 00000000000d773b
28741:P 25 Sep 12:56:22.883 # (00007fff59e921ec) -> 0000000105da6a10
28741:P 25 Sep 12:56:22.883 # (00007fff59e921eb) -> 00007ff96b406b93
28741:P 25 Sep 12:56:22.884 # (00007fff59e921ea) -> 0000000000000000
28741:P 25 Sep 12:56:22.884 # (00007fff59e921e9) -> 0000000105d85f63
28741:P 25 Sep 12:56:22.884 # (00007fff59e921e8) -> 00007fff59e92280
28741:P 25 Sep 12:56:22.884 # (00007fff59e921e7) -> 00007ff96b406bc0
28741:P 25 Sep 12:56:22.884 # (00007fff59e921e6) -> 0000000000000007
28741:P 25 Sep 12:56:22.884 # (00007fff59e921e5) -> 00007ff96e800000
28741:P 25 Sep 12:56:22.884 # (00007fff59e921e4) -> 0000000105da6a10
28741:P 25 Sep 12:56:22.884 # (00007fff59e921e3) -> 0000000000000064
28741:P 25 Sep 12:56:22.884 # (00007fff59e921e2) -> 00007fff59e91d30
28741:P 25 Sep 12:56:22.884 # (00007fff59e921e1) -> 00007fff59e92230
28741:P 25 Sep 12:56:22.884 # (00007fff59e921e0) -> 0000000000000000
28741:P 25 Sep 12:56:22.884 # 
=== DISQUE 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/disque/issues

  Suspect RAM error? Use disque-server --test-memory to verify it.

Increase:

28794:P 25 Sep 12:56:47.118 * Increased maximum number of open files to 10032 (it was originally set to 256).
28794:P 25 Sep 12:56:47.119 * Node configuration loaded, I'm a4774e27851a6fc1c8fdaf68cf5a9b0d40dd6788
                                        Disque 0.0.1 (338561bc/0) 64 bit
          _ -                                                        
        .                               Port: 7711
        .    o    .                     PID: 28794
                 .                                                   
               -                              http://disque.io       

28794:P 25 Sep 12:56:47.120 # Server started, Disque version 0.0.1
28794:P 25 Sep 12:56:47.120 * The server is now ready to accept connections on port 7711
28794:P 25 Sep 12:56:47.120 * The server is now ready to accept connections at /Users/mpaluch/git/spinach/work/disque-7711/socket
28794:P 25 Sep 12:56:52.263 # 

=== DISQUE BUG REPORT START: Cut & paste starting from here ===
28794:P 25 Sep 12:56:52.263 #     Disque 0.0.1 crashed by signal: 11
28794:P 25 Sep 12:56:52.263 #     Failed assertion: <no assertion failed> (<no file>:0)
28794:P 25 Sep 12:56:52.263 # --- STACK TRACE
0   disque-server                       0x00000001029ee427 logStackTrace + 103
1   disque-server                       0x00000001029d7b87 freeMemoryIfNeeded + 263
2   libsystem_platform.dylib            0x00007fff84446f1a _sigtramp + 26
3   ???                                 0x00007fff6244a598 0x0 + 140734842054040
4   disque-server                       0x00000001029e7f63 configSetCommand + 2531
5   disque-server                       0x00000001029d77f4 call + 116
6   disque-server                       0x00000001029d7a2f processCommand + 367
7   disque-server                       0x00000001029e2c55 processInputBuffer + 293
8   disque-server                       0x00000001029d11a6 aeProcessEvents + 678
9   disque-server                       0x00000001029d149b aeMain + 43
10  disque-server                       0x00000001029d97a2 main + 914
11  libdyld.dylib                       0x00007fff8f5275c9 start + 1
12  ???                                 0x0000000000000002 0x0 + 2
28794:P 25 Sep 12:56:52.264 # --- INFO OUTPUT
28794:P 25 Sep 12:56:52.264 # # Server
disque_version:0.0.1
disque_git_sha1:338561bc
disque_git_dirty:0
disque_build_id:9c90a64d1bc33a43
os:Darwin 14.5.0 x86_64
arch_bits:64
multiplexing_api:kqueue
gcc_version:4.2.1
process_id:28794
run_id:529026f25826e4a1a7316ecf5f5ec79f34e97f3c
tcp_port:7711
uptime_in_seconds:5
uptime_in_days:0
hz:10
config_file:/Users/mpaluch/git/spinach/work/disque-7711/disque.conf

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

# Memory
used_memory:959296
used_memory_human:936.81K
used_memory_rss:1384448
used_memory_peak:959296
used_memory_peak_human:936.81K
mem_fragmentation_ratio:1.44
mem_allocator:libc

# Jobs
registered_jobs:0

# Queues
registered_queues:0

# Persistence
loading:0
aof_enabled:0
aof_state:off
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

# Stats
total_connections_received:2
total_commands_processed:3
instantaneous_ops_per_sec:0
total_net_input_bytes:173
total_net_output_bytes:46
instantaneous_input_kbps:0.00
instantaneous_output_kbps:0.00
rejected_connections:0
latest_fork_usec:0

# CPU
used_cpu_sys:0.00
used_cpu_user:0.00
used_cpu_sys_children:0.00
used_cpu_user_children:0.00

# Commandstats
cmdstat_debug:calls=1,usec=9,usec_per_call=9.00
cmdstat_config:calls=1,usec=23,usec_per_call=23.00
cmdstat_cluster:calls=1,usec=28,usec_per_call=28.00
hash_init_value: 1443165731

28794:P 25 Sep 12:56:52.264 # --- CLIENT LIST OUTPUT
28794:P 25 Sep 12:56:52.264 # id=2 addr=127.0.0.1:55542 fd=11 name= age=0 idle=0 flags=N qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=config

28794:P 25 Sep 12:56:52.264 # --- CURRENT CLIENT INFO
28794:P 25 Sep 12:56:52.264 # client: id=2 addr=127.0.0.1:55542 fd=11 name= age=0 idle=0 flags=N qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=config
28794:P 25 Sep 12:56:52.264 # argv[0]: 'CONFIG'
28794:P 25 Sep 12:56:52.264 # argv[1]: 'SET'
28794:P 25 Sep 12:56:52.264 # argv[2]: 'maxmemory'
28794:P 25 Sep 12:56:52.264 # argv[3]: '999088'
28794:P 25 Sep 12:56:52.264 # --- REGISTERS
28794:P 25 Sep 12:56:52.264 # 
RAX:00000000000ea020 RBX:0000000000000000
RCX:0000000000000000 RDX:0000000000002706
RDI:00007f8264c001d0 RSI:000000000000000a
RBP:00007fff5d230220 RSP:00007fff5d2301e0
R8 :000000000000000a R9 :0000000000000000
R10:7fffffffffffffff R11:00007fff750d9e80
R12:00000000000024e6 R13:00000000000ea020
R14:0000000000000000 R15:0000000000000000
RIP:00000001029d7b87 EFL:0000000000010246
CS :000000000000002b FS:0000000000000000  GS:0000000000000000
28794:P 25 Sep 12:56:52.264 # (00007fff5d2301ef) -> fffadf6fcb7bfb00
28794:P 25 Sep 12:56:52.264 # (00007fff5d2301ee) -> 00000000000f3eb0
28794:P 25 Sep 12:56:52.264 # (00007fff5d2301ed) -> 00000000000405cf
28794:P 25 Sep 12:56:52.265 # (00007fff5d2301ec) -> 0000000102a08a10
28794:P 25 Sep 12:56:52.265 # (00007fff5d2301eb) -> 00007f82624048f3
28794:P 25 Sep 12:56:52.265 # (00007fff5d2301ea) -> 0000000000000000
28794:P 25 Sep 12:56:52.265 # (00007fff5d2301e9) -> 00000001029e7f63
28794:P 25 Sep 12:56:52.265 # (00007fff5d2301e8) -> 00007fff5d230280
28794:P 25 Sep 12:56:52.265 # (00007fff5d2301e7) -> 00007f8262404920
28794:P 25 Sep 12:56:52.265 # (00007fff5d2301e6) -> 0000000000000007
28794:P 25 Sep 12:56:52.265 # (00007fff5d2301e5) -> 00007f8262812600
28794:P 25 Sep 12:56:52.265 # (00007fff5d2301e4) -> 0000000102a08a10
28794:P 25 Sep 12:56:52.265 # (00007fff5d2301e3) -> 00000000000f3eb0
28794:P 25 Sep 12:56:52.265 # (00007fff5d2301e2) -> 8d00f0845ea62504
28794:P 25 Sep 12:56:52.265 # (00007fff5d2301e1) -> 000000000000001a
28794:P 25 Sep 12:56:52.265 # (00007fff5d2301e0) -> 0000000000000000
28794:P 25 Sep 12:56:52.265 # 
=== DISQUE 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/disque/issues

  Suspect RAM error? Use disque-server --test-memory to verify it.
sunheehnus commented 9 years ago

Looks like you have no jobs in disque-server. And the dictGetKey(NULL) cause this trouble. :-)

antirez commented 8 years ago

Thanks both, I fixed in a simpler way compared to @sunheehnus patch. Probably @sunheehnus approach is going to be needed in the future if we release other things and not just jobs, but perhaps for now it's better to have the simplest possible code. Thanks!