Restarting process with USR2 doesn't always work

[grk]

I've deployed Puma on production a few days ago, and noticed that after some deploys we have to kill -9 puma processes and start a new master.

Our setup is the following:

• ruby 1.9.3p374 from rvm
• rails 3.2.12
• puma 2.0.0.b6

We're running Puma with bundle exec puma -C /path/to/config -e production --dir /path/to/current -p 8888 --pidfile /path/to/pidfile -d 2>&1 >> /path/to/log

config is:

threads 5, 20
workers 20
activate_control_app 'tcp://127.0.0.1:8889'

On some restarts with USR2, I get a few worker processes failling to close. I ran strace on them, some are looped in sched_yield, and some give this output:

Process 7374 attached - interrupt to quit
futex(0x23ff5b4, FUTEX_WAIT_PRIVATE, 3, NULL

I also observed strange behaviour on those restarts that seem to succeed. There are 'waves' of requests that show up in log, then they stop, and after a few seconds I get ActiveRecord messages that db connection was established.

What would be next steps for debugging this? I should probably have something in the on_restart hook, but not sure what.

[evanphx]

Can you break into a stuck worker with gdb and run "bt"? Perhaps I need to ungracefully kill workers that don't stop after a timeout...

[phemmer]

I'm having this exact same issue as well. It also occurs on shutdown (SIGTERM to master). It's completely random. Sometimes all workers shut down, sometimes just one of them.

• Ruby 1.9.3p0 from ubuntu 12.04
• Rails 3.2.13
• Puma 2.0.1

Executing with bundle exec puma --daemon --bind tcp://127.0.0.1:3000 --pidfile /path/to/pidfile -w 3

Here is a backtrace of one of the workers that didn't shut down after a SIGTERM stuck in the futex call:

0x00007f2394cebd84 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
(gdb) bt
#0  0x00007f2394cebd84 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  0x00007f23954121a9 in native_cond_wait (cond=, mutex=) at thread_pthread.c:307
#2  0x00007f2395415f90 in native_sleep (th=0x603520, timeout_tv=0x0) at thread_pthread.c:908
#3  0x00007f239541782b in sleep_forever (th=0x603520, deadlockable=1) at thread.c:855
#4  0x00007f239541789d in thread_join_sleep (arg=140733465907824) at thread.c:688
#5  0x00007f239531844b in rb_ensure (b_proc=0x7f2395417860 , data1=140733465907824, e_proc=0x7f2395411fa0 , data2=140733465907824)
    at eval.c:736
#6  0x00007f2395414078 in thread_join (target_th=0x2d9ad40, delay=) at thread.c:721
#7  0x00007f23954141a2 in thread_join_m (argc=0, argv=0x7f239429e208, self=) at thread.c:802
#8  0x00007f239540abe1 in vm_call_cfunc (me=0x719170, blockptr=0x0, recv=, num=0, reg_cfp=0x7f239439da90, th=) at vm_insnhelper.c:404
#9  vm_call_method (th=, cfp=0x7f239439da90, num=, blockptr=0x0, flag=, id=, me=0x719170, recv=58423080)
    at vm_insnhelper.c:534
#10 0x00007f2395401b52 in vm_exec_core (th=, initial=) at insns.def:1015
#11 0x00007f239540755d in vm_exec (th=0x603520) at vm.c:1220
#12 0x00007f239540d385 in invoke_block_from_c (cref=0x0, blockptr=0x0, argv=0x0, argc=0, self=10399800, block=0x7f239439dc18, th=0x603520) at vm.c:624
#13 vm_yield (th=0x603520, argv=0x0, argc=0) at vm.c:654
#14 rb_yield_0 (argv=0x0, argc=0) at vm_eval.c:740
#15 rb_yield (val=6) at vm_eval.c:747
#16 0x00007f239531820a in rb_protect (proc=0x7f239540cef0 , data=6, state=0x7fff103e581c) at eval.c:711
#17 0x00007f239537dd02 in rb_f_fork (obj=) at process.c:2792
#18 rb_f_fork (obj=) at process.c:2780
#19 0x00007f239540abe1 in vm_call_cfunc (me=0x6fab40, blockptr=0x7f239439dc18, recv=, num=0, reg_cfp=0x7f239439dbf0, th=) at vm_insnhelper.c:404
#20 vm_call_method (th=, cfp=0x7f239439dbf0, num=, blockptr=0x7f239439dc18, flag=, id=, me=0x6fab40, recv=10399800)
    at vm_insnhelper.c:534
#21 0x00007f2395401b52 in vm_exec_core (th=, initial=) at insns.def:1015
#22 0x00007f239540755d in vm_exec (th=0x603520) at vm.c:1220
#23 0x00007f239540d15e in invoke_block_from_c (cref=0x0, blockptr=0x0, argv=0x7fff103e5b08, argc=1, self=10399800, block=0x7f239439dd20, th=0x603520) at vm.c:624
#24 vm_yield (th=0x603520, argv=0x7fff103e5b08, argc=1) at vm.c:654
#25 rb_yield_0 (argv=0x7fff103e5b08, argc=1) at vm_eval.c:740
#26 rb_yield (val=3) at vm_eval.c:750
#27 0x00007f2395351891 in int_dotimes (num=7) at numeric.c:3290
#28 0x00007f239540abe1 in vm_call_cfunc (me=0x6978a0, blockptr=0x7f239439dd20, recv=, num=0, reg_cfp=0x7f239439dcf8, th=) at vm_insnhelper.c:404
#29 vm_call_method (th=, cfp=0x7f239439dcf8, num=, blockptr=0x7f239439dd20, flag=, id=, me=0x6978a0, recv=7)
    at vm_insnhelper.c:534
#30 0x00007f2395401b52 in vm_exec_core (th=, initial=) at insns.def:1015
#31 0x00007f239540755d in vm_exec (th=0x603520) at vm.c:1220
#32 0x00007f239540e7f8 in rb_iseq_eval (iseqval=17853160) at vm.c:1447
#33 0x00007f2395319d35 in rb_load_internal (fname=17855800, wrap=) at load.c:310
#34 0x00007f2395319e98 in rb_f_load (argc=, argv=) at load.c:383
#35 0x00007f239540abe1 in vm_call_cfunc (me=0x706da0, blockptr=0x0, recv=, num=1, reg_cfp=0x7f239439df08, th=) at vm_insnhelper.c:404
#36 vm_call_method (th=, cfp=0x7f239439df08, num=, blockptr=0x0, flag=, id=, me=0x706da0, recv=6719200)
    at vm_insnhelper.c:534
#37 0x00007f2395401b52 in vm_exec_core (th=, initial=) at insns.def:1015
#38 0x00007f239540755d in vm_exec (th=0x603520) at vm.c:1220
#39 0x00007f239540e8df in rb_iseq_eval_main (iseqval=17840040) at vm.c:1461
#40 0x00007f23953170b2 in ruby_exec_internal (n=0x11037a8) at eval.c:204
#41 0x00007f2395317b9d in ruby_exec_node (n=0x11037a8) at eval.c:251
#42 0x00007f239531974e in ruby_run_node (n=0x11037a8) at eval.c:244
#43 0x00000000004007db in main (argc=11, argv=0x7fff103e6508) at main.c:38

Here's info threads

(gdb) info threads
  Id   Target Id         Frame 
  15   Thread 0x7f23958ef700 (LWP 4290) "ruby1.9.1" 0x00007f2394fea033 in select () from /lib/x86_64-linux-gnu/libc.so.6
  14   Thread 0x7f2391640700 (LWP 4291) "ruby1.9.1" 0x00007f2394cebd84 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
  13   Thread 0x7f2390084700 (LWP 4705) "ruby1.9.1" 0x00007f2394cebd84 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
  12   Thread 0x7f2386807700 (LWP 4706) "ruby1.9.1" 0x00007f2394cebd84 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
  11   Thread 0x7f2386685700 (LWP 4707) "ruby1.9.1" 0x00007f2394cebd84 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
  10   Thread 0x7f2386503700 (LWP 4708) "ruby1.9.1" 0x00007f2394cebd84 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
  9    Thread 0x7f2386381700 (LWP 4709) "ruby1.9.1" 0x00007f2394cebd84 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
  8    Thread 0x7f23861ff700 (LWP 4710) "ruby1.9.1" 0x00007f2394cee89c in __lll_lock_wait () from /lib/x86_64-linux-gnu/libpthread.so.0
  7    Thread 0x7f238607d700 (LWP 4711) "ruby1.9.1" 0x00007f2394cebd84 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
  6    Thread 0x7f2385efb700 (LWP 4712) "ruby1.9.1" 0x00007f2394cebd84 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
  5    Thread 0x7f2385d79700 (LWP 4713) "ruby1.9.1" 0x00007f2394cebd84 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
  4    Thread 0x7f2385bf7700 (LWP 4720) "ruby1.9.1" 0x00007f2394cebd84 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
  3    Thread 0x7f2385a75700 (LWP 4727) "ruby1.9.1" 0x00007f2394cebd84 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
  2    Thread 0x7f23859f4700 (LWP 4728) "SignalSender" 0x00007f2394cedfd0 in sem_wait () from /lib/x86_64-linux-gnu/libpthread.so.0
* 1    Thread 0x7f23958e5700 (LWP 4288) "ruby1.9.1" 0x00007f2394cebd84 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0

I can reproduce this fairly easily if you need more info.

[evanphx]

Yes, I need a way to reproduce this issue. Can you provide a way to do that?

[leifcr]

@evanphx I seem to experience this when using this testing application: https://github.com/leifcr/capistrano-testing

The paths for the deployment script is horrible, as it is used for devel/testing.

I am running puma under runit, but it seems to happen occasionally when running puma manually as well.

I still haven't found a way to reproduce it consistantly, but I do think a "kill after timeout x" is the best option, as that should take care of workers that are just hanging.

Could this be triggering if db connections and or logs are not properly closed?

It seems to trigger more often if I am reloading the app (curl) just when the phased restart is going to happen

Seems to do the same for restart and phased restart

[schneems]

No activity in 7 months. Is this still an ongoing issue? Can you build a run-able script that reproduces the problem?

[evanphx]

This could very well have been the Process.daemon issue. Let's close and reopen if someone has the issue still.

[ahayworth]

Hi all -

We're starting to run Puma in production, and I think we're running into this bug. I've attached a backtrace, a thread-level backtrace, and a ruby backtrace. They're unfortunately each from different processes, as we're running in cluster mode and the master started killing timed-out workers while I investigated. We're running ruby 1.9.3-p484, and puma 2.8.1. We've not yet found a reliable way to reproduce:

hayworth@sdg24:~$ sudo strace -p 1486
[sudo] password for hayworth: 
Process 1486 attached - interrupt to quit
futex(0x87a83b0, FUTEX_WAIT_PRIVATE, 1113, NULL^C <unfinished ...>
Process 1486 detached
hayworth@sdg24:~$ sudo strace -p 4364
Process 4364 attached - interrupt to quit
futex(0x87a83b0, FUTEX_WAIT_PRIVATE, 1129, NULL^C <unfinished ...>
Process 4364 detached
hayworth@sdg24:~$ sudo strace -p 21879
Process 21879 attached - interrupt to quit
futex(0x87a83b0, FUTEX_WAIT_PRIVATE, 1179, NULL^C <unfinished ...>
Process 21879 detached
hayworth@sdg24:~$ 

(gdb) bt
#0  0xf7759430 in __kernel_vsyscall ()
#1  0xf773bfcf in __pthread_cond_wait (cond=0x8aa23ac, mutex=0x8aa23f8) at pthread_cond_wait.c:153
#2  0x08168fe2 in native_cond_wait (cond=0xfffffe00, mutex=0x6b) at thread_pthread.c:309
#3  0x0816e78f in native_sleep (th=0x8aa2358, timeout_tv=<value optimized out>) at thread_pthread.c:909
#4  0x0816ecbe in sleep_forever (arg=4288293932) at thread.c:868
#5  thread_join_sleep (arg=4288293932) at thread.c:701
#6  0x0805bc91 in rb_ensure (b_proc=0x816ec20 <thread_join_sleep>, data1=4288293932, e_proc=0x8168c30 <remove_from_join_list>, data2=4288293932) at eval.c:744
#7  0x0816c8ed in thread_join (target_th=0xe178f58, delay=1e+30) at thread.c:734
#8  0x0816ca50 in thread_join_m (argc=0, argv=0xf7502128, self=219428620) at thread.c:815
#9  0x081535f5 in call_cfunc (func=0x816c9e0 <thread_join_m>, recv=107, len=128, argc=0, argv=0xfffffe00) at vm_insnhelper.c:317
#10 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf7581d1c, num=0, blockptr=0x0, flag=0, id=4744, me=0x8b33338, recv=219428620) at vm_insnhelper.c:404
#11 vm_call_method (th=<value optimized out>, cfp=0xf7581d1c, num=0, blockptr=0x0, flag=0, id=4744, me=0x8b33338, recv=219428620) at vm_insnhelper.c:530
#12 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#13 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#14 0x08165f45 in invoke_block_from_c (val=6) at vm.c:640
#15 vm_yield (val=6) at vm.c:670
#16 rb_yield_0 (val=6) at vm_eval.c:777
#17 rb_yield (val=6) at vm_eval.c:784
#18 0x0805be08 in rb_protect (proc=0x8165d10 <rb_yield>, data=6, state=0xff9a31bc) at eval.c:719
#19 0x080bf6d5 in rb_f_fork (obj=149192700) at process.c:2814
#20 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf7581dcc, num=0, blockptr=0xf7581de0, flag=8, id=8288, me=0x8b238f0, recv=149192700) at vm_insnhelper.c:404
#21 vm_call_method (th=<value optimized out>, cfp=0xf7581dcc, num=0, blockptr=0xf7581de0, flag=8, id=8288, me=0x8b238f0, recv=149192700) at vm_insnhelper.c:530
#22 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#23 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#24 0x08165d60 in vm_yield (val=1) at vm.c:670
#25 rb_yield_0 (val=1) at vm_eval.c:777
#26 rb_yield (val=1) at vm_eval.c:787
#27 0x0808e301 in int_dotimes (num=3) at numeric.c:3328
#28 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf7581e50, num=0, blockptr=0xf7581e64, flag=0, id=3352, me=0x8af03e8, recv=3) at vm_insnhelper.c:404
#29 vm_call_method (th=<value optimized out>, cfp=0xf7581e50, num=0, blockptr=0xf7581e64, flag=0, id=3352, me=0x8af03e8, recv=3) at vm_insnhelper.c:530
#30 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#31 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#32 0x0815f2c5 in rb_iseq_eval (iseqval=147564920) at vm.c:1464
#33 0x081afaff in rb_load_internal (fname=<value optimized out>, wrap=<value optimized out>) at load.c:310
#34 0x081afc48 in rb_f_load (argc=1, argv=0xf750202c) at load.c:384
#35 0x081535f5 in call_cfunc (func=0x81afbd0 <rb_f_load>, recv=107, len=128, argc=1, argv=0xfffffe00) at vm_insnhelper.c:317
#36 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf7581f84, num=1, blockptr=0x0, flag=8, id=6048, me=0x8b29bc8, recv=145578700) at vm_insnhelper.c:404
#37 vm_call_method (th=<value optimized out>, cfp=0xf7581f84, num=1, blockptr=0x0, flag=8, id=6048, me=0x8b29bc8, recv=145578700) at vm_insnhelper.c:530
#38 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#39 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#40 0x0815f162 in rb_iseq_eval_main (iseqval=146688500) at vm.c:1478
#41 0x0805c192 in ruby_exec_internal (n=<value optimized out>) at eval.c:204
#42 0x0805de72 in ruby_exec_node (n=0x8be49f4) at eval.c:251
#43 ruby_run_node (n=0x8be49f4) at eval.c:244
#44 0x0805b3ea in main (argc=8, argv=0xff9a3ed4) at main.c:38
(gdb) 





Thread 9 (Thread 0xf703db70 (LWP 10806)):
#0  0xf7759430 in __kernel_vsyscall ()
#1  0xf764a361 in select () at ../sysdeps/unix/syscall-template.S:82
#2  0x081706d4 in rb_fd_select (max=9, read=0xf703ce24, write=0x0, except=0x0, timeout=0x0) at thread.c:2446
#3  do_select (max=9, read=0xf703ce24, write=0x0, except=0x0, timeout=0x0) at thread.c:2640
#4  rb_thread_fd_select (max=9, read=0xf703ce24, write=0x0, except=0x0, timeout=0x0) at thread.c:2788
#5  0x080821ef in select_internal (arg=4144221716) at io.c:7709
#6  select_call (arg=4144221716) at io.c:7779
#7  0x0805bc91 in rb_ensure (b_proc=0x8081d80 <select_call>, data1=4144221716, e_proc=0x8071fb0 <select_end>, data2=4144221716) at eval.c:744
#8  0x08072211 in rb_f_select (argc=1, argv=0xf6ece024, obj=145555180) at io.c:8033
#9  0x081535f5 in call_cfunc (func=0x8072160 <rb_f_select>, recv=0, len=-153809056, argc=1, argv=0xfffffdfe) at vm_insnhelper.c:317
#10 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf6f4df84, num=1, blockptr=0x0, flag=0, id=1552, me=0x8b15398, recv=145555180) at vm_insnhelper.c:404
#11 vm_call_method (th=<value optimized out>, cfp=0xf6f4df84, num=1, blockptr=0x0, flag=0, id=1552, me=0x8b15398, recv=145555180) at vm_insnhelper.c:530
#12 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#13 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#14 0x0815ffa6 in rb_vm_invoke_proc (th=0x91a3580, proc=0x8e73448, self=149192700, argc=0, argv=0x8fb8ad8, blockptr=0x0) at vm.c:686
#15 0x0816f6a5 in thread_start_func_2 (th=<value optimized out>, stack_start=<value optimized out>) at thread.c:466
#16 0x0816f78e in thread_start_func_1 (th_ptr=0x91a3580) at thread_pthread.c:657
#17 0xf7737955 in start_thread (arg=0xf703db70) at pthread_create.c:300
#18 0xf76511de in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130

Thread 8 (Thread 0xf713fb70 (LWP 10935)):
#0  0xf7759430 in __kernel_vsyscall ()
#1  0xf773c4d2 in pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/i386/i686/../i486/pthread_cond_timedwait.S:179
#2  0x0816e71e in native_cond_timedwait (th=0x9c36198, timeout_tv=0x53) at thread_pthread.c:327
#3  native_sleep (th=0x9c36198, timeout_tv=0x53) at thread_pthread.c:911
#4  0x0816e88c in sleep_timeval (th=0x9c36198, tv=...) at thread.c:908
#5  0x080b8b7b in rb_f_sleep (argc=1, argv=0xf692f084) at process.c:3472
#6  0x081535f5 in call_cfunc (func=0x80b8b30 <rb_f_sleep>, recv=83, len=128, argc=1, argv=0xfffffdfc) at vm_insnhelper.c:317
#7  0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf69aee50, num=1, blockptr=0x0, flag=8, id=8320, me=0x8b23c70, recv=162798840) at vm_insnhelper.c:404
#8  vm_call_method (th=<value optimized out>, cfp=0xf69aee50, num=1, blockptr=0x0, flag=8, id=8320, me=0x8b23c70, recv=162798840) at vm_insnhelper.c:530
#9  0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#10 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#11 0x0815ffa6 in rb_vm_invoke_proc (th=0x9c36198, proc=0xa0caa50, self=163039300, argc=1, argv=0x9b76fb4, blockptr=0x0) at vm.c:686
#12 0x0816f6a5 in thread_start_func_2 (th=<value optimized out>, stack_start=<value optimized out>) at thread.c:466
#13 0x0816f78e in thread_start_func_1 (th_ptr=0x9c36198) at thread_pthread.c:657
#14 0xf7737955 in start_thread (arg=0xf713fb70) at pthread_create.c:300
#15 0xf76511de in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130

Thread 7 (Thread 0xf7756b70 (LWP 11022)):
#0  0xf7759430 in __kernel_vsyscall ()
#1  0xf764a361 in select () at ../sysdeps/unix/syscall-template.S:82
#2  0x081712b4 in thread_timer (p=0x8aa200c) at thread_pthread.c:1159
#3  0xf7737955 in start_thread (arg=0xf7756b70) at pthread_create.c:300
#4  0xf76511de in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130

Thread 6 (Thread 0xf7241b70 (LWP 11393)):
#0  0xf7759430 in __kernel_vsyscall ()
#1  0xf773c4d2 in pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/i386/i686/../i486/pthread_cond_timedwait.S:179
#2  0x0816e71e in native_cond_timedwait (th=0xe259170, timeout_tv=0x9d) at thread_pthread.c:327
#3  native_sleep (th=0xe259170, timeout_tv=0x9d) at thread_pthread.c:911
#4  0x0816e88c in sleep_timeval (th=0xe259170, tv=...) at thread.c:908
#5  0x080b8b7b in rb_f_sleep (argc=1, argv=0xf68ae02c) at process.c:3472
#6  0x081535f5 in call_cfunc (func=0x80b8b30 <rb_f_sleep>, recv=157, len=128, argc=1, argv=0xfffffdfc) at vm_insnhelper.c:317
#7  0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf692df84, num=1, blockptr=0x0, flag=8, id=8320, me=0x8b23c70, recv=149192700) at vm_insnhelper.c:404
#8  vm_call_method (th=<value optimized out>, cfp=0xf692df84, num=1, blockptr=0x0, flag=8, id=8320, me=0x8b23c70, recv=149192700) at vm_insnhelper.c:530
#9  0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#10 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#11 0x0815ffa6 in rb_vm_invoke_proc (th=0xe259170, proc=0xd86c3f0, self=149192700, argc=1, argv=0xd2d7878, blockptr=0x0) at vm.c:686
#12 0x0816f6a5 in thread_start_func_2 (th=<value optimized out>, stack_start=<value optimized out>) at thread.c:466
#13 0x0816f78e in thread_start_func_1 (th_ptr=0xe259170) at thread_pthread.c:657
#14 0xf7737955 in start_thread (arg=0xf7241b70) at pthread_create.c:300
#15 0xf76511de in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130

Thread 5 (Thread 0xf6ecdb70 (LWP 11394)):
#0  0x080fe8d9 in st_foreach (table=0xb401548, func=0x80668f0 <mark_keyvalue>, arg=4142701396) at st.c:825
#1  0x08067f09 in mark_hash (objspace=0x8aa25c0) at gc.c:1630
#2  gc_mark_children (objspace=0x8aa25c0) at gc.c:1951
#3  gc_mark_stacked_objects (objspace=0x8aa25c0) at gc.c:1506
#4  gc_marks (objspace=0x8aa25c0) at gc.c:2578
#5  0x080684ca in garbage_collect (objspace=0x8aa25c0) at gc.c:2602
#6  0x08068fdf in garbage_collect_with_gvl (objspace=0x8aa25c0, size=129) at gc.c:731
#7  vm_malloc_prepare (objspace=0x8aa25c0, size=129) at gc.c:761
#8  vm_xmalloc (objspace=0x8aa25c0, size=129) at gc.c:795
#9  0x08104c9f in rb_str_buf_new (capa=128) at string.c:745
#10 0x080fe0c5 in rb_enc_vsprintf (enc=0x8aa4918, format=0x81c9891 "%s:%d:in `%s'") at sprintf.c:1170
#11 rb_enc_sprintf (enc=0x8aa4918, format=0x81c9891 "%s:%d:in `%s'") at sprintf.c:1190
#12 0x08154220 in vm_backtrace_push (arg=0xf6ec9d7c, file=158623600, line_no=68, name=156549120) at vm.c:849
#13 0x0815544b in vm_backtrace_each (th=<value optimized out>, lev=<value optimized out>, init=<value optimized out>, iter=0x81541c0 <vm_backtrace_push>, arg=0xf6ec9d7c) at vm.c:815
#14 0x08155d2b in vm_backtrace () at vm.c:868
#15 rb_make_backtrace () at vm_eval.c:1659
#16 0x0805e2cd in setup_exception (th=<value optimized out>, tag=<value optimized out>, mesg=240983040) at eval.c:390
#17 0x0805e838 in rb_longjmp (mesg=240983040) at eval.c:452
#18 rb_exc_raise (mesg=240983040) at eval.c:465
#19 0x08158a28 in raise_method_missing (th=0xe2adf58, argc=<value optimized out>, argv=<value optimized out>, obj=4, last_call_status=<value optimized out>) at vm_eval.c:559
#20 0x08158af6 in rb_method_missing (argc=1, argv=0xf5635a04, obj=4) at vm_eval.c:499
#21 0x081535f5 in call_cfunc (func=0x8158ad0 <rb_method_missing>, recv=4142701396, len=34, argc=1, argv=0x4908b9e9) at vm_insnhelper.c:317
#22 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf56b3a34, num=1, blockptr=0x0, flag=136, id=384, me=0x8aed740, recv=4) at vm_insnhelper.c:404
#23 vm_call_method (th=<value optimized out>, cfp=0xf56b3a34, num=1, blockptr=0x0, flag=136, id=384, me=0x8aed740, recv=4) at vm_insnhelper.c:530
#24 0x0815c842 in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1054
#25 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#26 0x081604dc in vm_call0 (th=0xe2adf58, recv=<value optimized out>, id=<value optimized out>, argc=1, argv=0xe5d1c6c, me=0x9d3a920) at vm_eval.c:66
#27 0x081610b7 in rb_call0 (recv=4, mid=384, argc=<value optimized out>, argv=0xe5d1c6c, scope=CALL_FCALL, self=6) at vm_eval.c:236
#28 0x08161813 in rb_call (args=0xf6eca574) at vm_eval.c:456
#29 rb_funcall2 (args=0xf6eca574) at vm_eval.c:671
#30 check_funcall_exec (args=0xf6eca574) at vm_eval.c:253
#31 0x0805bf61 in rb_rescue2 (b_proc=0x81617b0 <check_funcall_exec>, data1=4142703988, r_proc=0x8166580 <check_funcall_failed>, data2=4142703988) at eval.c:647
#32 0x08160d4e in check_funcall (recv=4, mid=<value optimized out>, argc=<value optimized out>, argv=0x0) at vm_eval.c:302
#33 0x08098b3f in convert_type (val=4, type=7, tname=0x81cb54d "Array", method=0x81cb546 "to_ary") at object.c:2063
#34 rb_check_convert_type (val=4, type=7, tname=0x81cb54d "Array", method=0x81cb546 "to_ary") at object.c:2100
#35 0x081837d7 in rb_check_array_type (ary=240983200, level=<value optimized out>, modified=<value optimized out>) at array.c:474
#36 flatten (ary=240983200, level=<value optimized out>, modified=<value optimized out>) at array.c:3740
#37 0x08183a57 in rb_ary_flatten (argc=0, argv=0xf56359d4, ary=240983200) at array.c:3846
#38 0x081535f5 in call_cfunc (func=0x81839d0 <rb_ary_flatten>, recv=4142701396, len=34, argc=0, argv=0x4908b9e9) at vm_insnhelper.c:317
#39 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf56b3ab8, num=0, blockptr=0x0, flag=0, id=4912, me=0x8b0a4c8, recv=240983200) at vm_insnhelper.c:404
#40 vm_call_method (th=<value optimized out>, cfp=0xf56b3ab8, num=0, blockptr=0x0, flag=0, id=4912, me=0x8b0a4c8, recv=240983200) at vm_insnhelper.c:530
#41 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#42 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#43 0x08165d60 in vm_yield (val=168864160) at vm.c:670
#44 rb_yield_0 (val=168864160) at vm_eval.c:777
#45 rb_yield (val=168864160) at vm_eval.c:787
#46 0x0817b35d in rb_ary_each (array=240983260) at array.c:1495
#47 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf56b3b94, num=0, blockptr=0xf56b3ba8, flag=264, id=424, me=0x8b08f30, recv=240983260) at vm_insnhelper.c:404
#48 vm_call_method (th=<value optimized out>, cfp=0xf56b3b94, num=0, blockptr=0xf56b3ba8, flag=264, id=424, me=0x8b08f30, recv=240983260) at vm_insnhelper.c:530
#49 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#50 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#51 0x081604dc in vm_call0 (th=0xe2adf58, recv=<value optimized out>, id=<value optimized out>, argc=1, argv=0xf6ecadf0, me=0xa7232c8) at vm_eval.c:66
#52 0x081610b7 in rb_call0 (recv=219243760, mid=384, argc=<value optimized out>, argv=0xf6ecadf0, scope=CALL_FCALL, self=6) at vm_eval.c:236
#53 0x08161475 in rb_call (th=0xe2adf58, id=<value optimized out>, recv=<value optimized out>, num=0, blockptr=0x0, opt=0) at vm_eval.c:456
#54 rb_funcall2 (th=0xe2adf58, id=<value optimized out>, recv=<value optimized out>, num=0, blockptr=0x0, opt=0) at vm_eval.c:671
#55 vm_method_missing (th=0xe2adf58, id=<value optimized out>, recv=<value optimized out>, num=0, blockptr=0x0, opt=0) at vm_insnhelper.c:454
#56 0x08158e84 in vm_call_method (th=<value optimized out>, cfp=0xf56b3c9c, num=0, blockptr=0x0, flag=<value optimized out>, id=38255, me=0x0, recv=219243760) at vm_insnhelper.c:673
#57 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#58 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#59 0x0815ffa6 in rb_vm_invoke_proc (th=0xe2adf58, proc=0xbd70620, self=220747560, argc=0, argv=0xf6ecb240, blockptr=0x0) at vm.c:686
#60 0x0816004e in vm_call_bmethod (th=0xe2adf58, recv=220747560, argc=34, argv=0xf6ecb240, blockptr=0x0, me=0xbd70650) at vm_insnhelper.c:429
#61 0x08159020 in vm_call_method (th=<value optimized out>, cfp=0xf56b3d4c, num=0, blockptr=0x0, flag=270, id=242712, me=0xbd70650, recv=220747560) at vm_insnhelper.c:562
#62 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#63 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#64 0x08165d60 in vm_yield (val=196449880) at vm.c:670
#65 rb_yield_0 (val=196449880) at vm_eval.c:777
#66 rb_yield (val=196449880) at vm_eval.c:787
#67 0x0817b35d in rb_ary_each (array=238700660) at array.c:1495
#68 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf56b3e28, num=0, blockptr=0xf56b3e3c, flag=264, id=424, me=0x8b08f30, recv=238700660) at vm_insnhelper.c:404
#69 vm_call_method (th=<value optimized out>, cfp=0xf56b3e28, num=0, blockptr=0xf56b3e3c, flag=264, id=424, me=0x8b08f30, recv=238700660) at vm_insnhelper.c:530
#70 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#71 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#72 0x081604dc in vm_call0 (th=0xe2adf58, recv=<value optimized out>, id=<value optimized out>, argc=1, argv=0xf563573c, me=0xe191fd8) at vm_eval.c:66
#73 0x0805f6b4 in rb_method_call_with_block (argc=1, argv=0xf563573c, method=240178920, pass_procval=4) at proc.c:1444
#74 0x08061fef in rb_method_call (argc=1, argv=0xf563573c, method=240178920) at proc.c:1411
#75 0x081535f5 in call_cfunc (func=0x8061fb0 <rb_method_call>, recv=4142701396, len=34, argc=1, argv=0x4908b9e9) at vm_insnhelper.c:317
#76 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf56b4140, num=1, blockptr=0x0, flag=2, id=6016, me=0x8b2b530, recv=240178920) at vm_insnhelper.c:404
#77 vm_call_method (th=<value optimized out>, cfp=0xf56b4140, num=1, blockptr=0x0, flag=2, id=6016, me=0x8b2b530, recv=240178920) at vm_insnhelper.c:530
#78 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#79 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#80 0x0815ffa6 in rb_vm_invoke_proc (th=0xe2adf58, proc=0xbd577d0, self=220747560, argc=1, argv=0xf6ecbe10, blockptr=0x0) at vm.c:686
#81 0x0816004e in vm_call_bmethod (th=0xe2adf58, recv=220747560, argc=34, argv=0xf6ecbe10, blockptr=0x0, me=0xbd57810) at vm_insnhelper.c:429
#82 0x08159020 in vm_call_method (th=<value optimized out>, cfp=0xf56b4198, num=1, blockptr=0x0, flag=0, id=238056, me=0xbd57810, recv=220747560) at vm_insnhelper.c:562
#83 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#84 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#85 0x0815ffa6 in rb_vm_invoke_proc (th=0xe2adf58, proc=0xd6b7ef8, self=220334340, argc=0, argv=0xf56354a0, blockptr=0x0) at vm.c:686
#86 0x08062054 in proc_call (argc=0, argv=0xf56354a0, procval=220457780) at proc.c:555
#87 0x081535f5 in call_cfunc (func=0x8062000 <proc_call>, recv=4142701396, len=34, argc=0, argv=0x4908b9e9) at vm_insnhelper.c:317
#88 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf56b46c0, num=0, blockptr=0x0, flag=0, id=6016, me=0x8b2a3a0, recv=220457780) at vm_insnhelper.c:404
#89 vm_call_method (th=<value optimized out>, cfp=0xf56b46c0, num=0, blockptr=0x0, flag=0, id=6016, me=0x8b2a3a0, recv=220457780) at vm_insnhelper.c:530
#90 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#91 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#92 0x0815ffa6 in rb_vm_invoke_proc (th=0xe2adf58, proc=0xcfb2dd8, self=212351180, argc=2, argv=0xf5635454, blockptr=0x0) at vm.c:686
#93 0x08062054 in proc_call (argc=2, argv=0xf5635454, procval=173672680) at proc.c:555
#94 0x081535f5 in call_cfunc (func=0x8062000 <proc_call>, recv=4142701396, len=34, argc=2, argv=0x4908b9e9) at vm_insnhelper.c:317
#95 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf56b4770, num=2, blockptr=0x0, flag=6, id=6016, me=0x8b2a3a0, recv=173672680) at vm_insnhelper.c:404
#96 vm_call_method (th=<value optimized out>, cfp=0xf56b4770, num=2, blockptr=0x0, flag=6, id=6016, me=0x8b2a3a0, recv=173672680) at vm_insnhelper.c:530
#97 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#98 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#99 0x0815ffa6 in rb_vm_invoke_proc (th=0xe2adf58, proc=0xe21b1b8, self=221925740, argc=1, argv=0xf5635270, blockptr=0x0) at vm.c:686
#100 0x08062054 in proc_call (argc=1, argv=0xf5635270, procval=221925700) at proc.c:555
#101 0x081535f5 in call_cfunc (func=0x8062000 <proc_call>, recv=4142701396, len=34, argc=1, argv=0x4908b9e9) at vm_insnhelper.c:317
#102 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf56b4b64, num=1, blockptr=0x0, flag=0, id=6016, me=0x8b2a3a0, recv=221925700) at vm_insnhelper.c:404
#103 vm_call_method (th=<value optimized out>, cfp=0xf56b4b64, num=1, blockptr=0x0, flag=0, id=6016, me=0x8b2a3a0, recv=221925700) at vm_insnhelper.c:530
#104 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#105 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#106 0x0815ffa6 in rb_vm_invoke_proc (th=0xe2adf58, proc=0xdd67568, self=221085720, argc=2, argv=0xf5635040, blockptr=0x0) at vm.c:686
#107 0x08062054 in proc_call (argc=2, argv=0xf5635040, procval=221083460) at proc.c:555
#108 0x081535f5 in call_cfunc (func=0x8062000 <proc_call>, recv=4142701396, len=34, argc=2, argv=0x4908b9e9) at vm_insnhelper.c:317
#109 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf56b4f84, num=2, blockptr=0x0, flag=2, id=6016, me=0x8b2a3a0, recv=221083460) at vm_insnhelper.c:404
#110 vm_call_method (th=<value optimized out>, cfp=0xf56b4f84, num=2, blockptr=0x0, flag=2, id=6016, me=0x8b2a3a0, recv=221083460) at vm_insnhelper.c:530
#111 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#112 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#113 0x0815ffa6 in rb_vm_invoke_proc (th=0xe2adf58, proc=0xda7c628, self=221083700, argc=0, argv=0xd2d7454, blockptr=0x0) at vm.c:686
#114 0x0816f6a5 in thread_start_func_2 (th=<value optimized out>, stack_start=<value optimized out>) at thread.c:466
#115 0x0816f78e in thread_start_func_1 (th_ptr=0xe2adf58) at thread_pthread.c:657
#116 0xf7737955 in start_thread (arg=0xf6ecdb70) at pthread_create.c:300
#117 0xf76511de in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130

Thread 4 (Thread 0xf55b3b70 (LWP 11395)):
#0  0xf7759430 in __kernel_vsyscall ()
#1  0xf764a361 in select () at ../sysdeps/unix/syscall-template.S:82
#2  0x081706d4 in rb_fd_select (max=19, read=0xf55b2e24, write=0x0, except=0x0, timeout=0xf55b2c48) at thread.c:2446
#3  do_select (max=19, read=0xf55b2e24, write=0x0, except=0x0, timeout=0xf55b2c48) at thread.c:2640
#4  rb_thread_fd_select (max=19, read=0xf55b2e24, write=0x0, except=0x0, timeout=0xf55b2c48) at thread.c:2788
#5  0x080821ef in select_internal (arg=4116393492) at io.c:7709
#6  select_call (arg=4116393492) at io.c:7779
#7  0x0805bc91 in rb_ensure (b_proc=0x8081d80 <select_call>, data1=4116393492, e_proc=0x8071fb0 <select_end>, data2=4116393492) at eval.c:744
#8  0x08072211 in rb_f_select (argc=4, argv=0xf55b4044, obj=145555180) at io.c:8033
#9  0x081535f5 in call_cfunc (func=0x8072160 <rb_f_select>, recv=0, len=235994800, argc=4, argv=0xfffffdfe) at vm_insnhelper.c:317
#10 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf5633f58, num=4, blockptr=0x0, flag=0, id=1552, me=0x8b15398, recv=145555180) at vm_insnhelper.c:404
#11 vm_call_method (th=<value optimized out>, cfp=0xf5633f58, num=4, blockptr=0x0, flag=0, id=1552, me=0x8b15398, recv=145555180) at vm_insnhelper.c:530
#12 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#13 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#14 0x0815ffa6 in rb_vm_invoke_proc (th=0xd8b9c40, proc=0xdf766b8, self=221082420, argc=0, argv=0xd2d71ac, blockptr=0x0) at vm.c:686
#15 0x0816f6a5 in thread_start_func_2 (th=<value optimized out>, stack_start=<value optimized out>) at thread.c:466
#16 0x0816f78e in thread_start_func_1 (th_ptr=0xd8b9c40) at thread_pthread.c:657
#17 0xf7737955 in start_thread (arg=0xf55b3b70) at pthread_create.c:300
#18 0xf76511de in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130

Thread 3 (Thread 0xf54b1b70 (LWP 11396)):
#0  0xf7759430 in __kernel_vsyscall ()
#1  0xf773c4d2 in pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/i386/i686/../i486/pthread_cond_timedwait.S:179
#2  0x0816e71e in native_cond_timedwait (th=0xdfd78b8, timeout_tv=0x2f3) at thread_pthread.c:327
#3  native_sleep (th=0xdfd78b8, timeout_tv=0x2f3) at thread_pthread.c:911
#4  0x0816e88c in sleep_timeval (th=0xdfd78b8, tv=...) at thread.c:908
#5  0x080b8b7b in rb_f_sleep (argc=1, argv=0xf54b2024) at process.c:3472
#6  0x081535f5 in call_cfunc (func=0x80b8b30 <rb_f_sleep>, recv=755, len=128, argc=1, argv=0xfffffdfc) at vm_insnhelper.c:317
#7  0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf5531f84, num=1, blockptr=0x0, flag=8, id=8320, me=0x8b23c70, recv=221081720) at vm_insnhelper.c:404
#8  vm_call_method (th=<value optimized out>, cfp=0xf5531f84, num=1, blockptr=0x0, flag=8, id=8320, me=0x8b23c70, recv=221081720) at vm_insnhelper.c:530
#9  0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#10 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#11 0x0815ffa6 in rb_vm_invoke_proc (th=0xdfd78b8, proc=0xe270180, self=221081720, argc=0, argv=0xd2d6f40, blockptr=0x0) at vm.c:686
#12 0x0816f6a5 in thread_start_func_2 (th=<value optimized out>, stack_start=<value optimized out>) at thread.c:466
#13 0x0816f78e in thread_start_func_1 (th_ptr=0xdfd78b8) at thread_pthread.c:657
#14 0xf7737955 in start_thread (arg=0xf54b1b70) at pthread_create.c:300
#15 0xf76511de in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130

Thread 2 (Thread 0xf53afb70 (LWP 11397)):
#0  0xf7759430 in __kernel_vsyscall ()
#1  0xf773bfcf in __pthread_cond_wait (cond=0x8aa202c, mutex=0x8aa2010) at pthread_cond_wait.c:153
#2  0x0816dc2c in native_cond_wait (vm=0x8aa2008, th=<value optimized out>) at thread_pthread.c:309
#3  gvl_acquire_common (vm=0x8aa2008, th=<value optimized out>) at thread_pthread.c:64
#4  gvl_acquire (vm=0x8aa2008, th=<value optimized out>) at thread_pthread.c:82
#5  0x0816feb7 in blocking_region_end (th=0xe41f068, region=0xf53aec2c) at thread.c:1060
#6  0x081706f9 in do_select (max=17, read=0xf53aee24, write=0x0, except=0x0, timeout=0x0) at thread.c:2640
#7  rb_thread_fd_select (max=17, read=0xf53aee24, write=0x0, except=0x0, timeout=0x0) at thread.c:2788
#8  0x080821ef in select_internal (arg=4114279956) at io.c:7709
#9  select_call (arg=4114279956) at io.c:7779
#10 0x0805bc91 in rb_ensure (b_proc=0x8081d80 <select_call>, data1=4114279956, e_proc=0x8071fb0 <select_end>, data2=4114279956) at eval.c:744
#11 0x08072211 in rb_f_select (argc=1, argv=0xf53b0044, obj=145555180) at io.c:8033
#12 0x081535f5 in call_cfunc (func=0x8072160 <rb_f_select>, recv=7989, len=128, argc=1, argv=0xfffffe00) at vm_insnhelper.c:317
#13 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf542ff58, num=1, blockptr=0x0, flag=0, id=1552, me=0x8b15398, recv=145555180) at vm_insnhelper.c:404
#14 vm_call_method (th=<value optimized out>, cfp=0xf542ff58, num=1, blockptr=0x0, flag=0, id=1552, me=0x8b15398, recv=145555180) at vm_insnhelper.c:530
#15 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#16 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#17 0x0815ffa6 in rb_vm_invoke_proc (th=0xe41f068, proc=0xe150fd8, self=221085720, argc=0, argv=0xd2d6d4c, blockptr=0x0) at vm.c:686
#18 0x0816f6a5 in thread_start_func_2 (th=<value optimized out>, stack_start=<value optimized out>) at thread.c:466
#19 0x0816f78e in thread_start_func_1 (th_ptr=0xe41f068) at thread_pthread.c:657
#20 0xf7737955 in start_thread (arg=0xf53afb70) at pthread_create.c:300
#21 0xf76511de in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130

Thread 1 (Thread 0xf75836c0 (LWP 10803)):
#0  0xf7759430 in __kernel_vsyscall ()
#1  0xf773bfcf in __pthread_cond_wait (cond=0x8aa23ac, mutex=0x8aa23f8) at pthread_cond_wait.c:153
#2  0x08168fe2 in native_cond_wait (cond=0xfffffe00, mutex=0x8b) at thread_pthread.c:309
#3  0x0816e78f in native_sleep (th=0x8aa2358, timeout_tv=<value optimized out>) at thread_pthread.c:909
#4  0x0816ecbe in sleep_forever (arg=4288293932) at thread.c:868
#5  thread_join_sleep (arg=4288293932) at thread.c:701
#6  0x0805bc91 in rb_ensure (b_proc=0x816ec20 <thread_join_sleep>, data1=4288293932, e_proc=0x8168c30 <remove_from_join_list>, data2=4288293932) at eval.c:744
#7  0x0816c8ed in thread_join (target_th=0xe41f068, delay=1e+30) at thread.c:734
#8  0x0816ca50 in thread_join_m (argc=0, argv=0xf7502128, self=221080920) at thread.c:815
#9  0x081535f5 in call_cfunc (func=0x816c9e0 <thread_join_m>, recv=139, len=128, argc=0, argv=0xfffffe00) at vm_insnhelper.c:317
#10 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf7581d1c, num=0, blockptr=0x0, flag=0, id=4744, me=0x8b33338, recv=221080920) at vm_insnhelper.c:404
#11 vm_call_method (th=<value optimized out>, cfp=0xf7581d1c, num=0, blockptr=0x0, flag=0, id=4744, me=0x8b33338, recv=221080920) at vm_insnhelper.c:530
#12 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#13 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#14 0x08165f45 in invoke_block_from_c (val=6) at vm.c:640
#15 vm_yield (val=6) at vm.c:670
#16 rb_yield_0 (val=6) at vm_eval.c:777
#17 rb_yield (val=6) at vm_eval.c:784
#18 0x0805be08 in rb_protect (proc=0x8165d10 <rb_yield>, data=6, state=0xff9a31bc) at eval.c:719
#19 0x080bf6d5 in rb_f_fork (obj=149192700) at process.c:2814
#20 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf7581dcc, num=0, blockptr=0xf7581de0, flag=8, id=8288, me=0x8b238f0, recv=149192700) at vm_insnhelper.c:404
#21 vm_call_method (th=<value optimized out>, cfp=0xf7581dcc, num=0, blockptr=0xf7581de0, flag=8, id=8288, me=0x8b238f0, recv=149192700) at vm_insnhelper.c:530
#22 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#23 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#24 0x08165d60 in vm_yield (val=1) at vm.c:670
#25 rb_yield_0 (val=1) at vm_eval.c:777
#26 rb_yield (val=1) at vm_eval.c:787
#27 0x0808e301 in int_dotimes (num=3) at numeric.c:3328
#28 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf7581e50, num=0, blockptr=0xf7581e64, flag=0, id=3352, me=0x8af03e8, recv=3) at vm_insnhelper.c:404
#29 vm_call_method (th=<value optimized out>, cfp=0xf7581e50, num=0, blockptr=0xf7581e64, flag=0, id=3352, me=0x8af03e8, recv=3) at vm_insnhelper.c:530
#30 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#31 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#32 0x0815f2c5 in rb_iseq_eval (iseqval=147564920) at vm.c:1464
#33 0x081afaff in rb_load_internal (fname=<value optimized out>, wrap=<value optimized out>) at load.c:310
#34 0x081afc48 in rb_f_load (argc=1, argv=0xf750202c) at load.c:384
#35 0x081535f5 in call_cfunc (func=0x81afbd0 <rb_f_load>, recv=139, len=128, argc=1, argv=0xfffffe00) at vm_insnhelper.c:317
#36 0x08158d8f in vm_call_cfunc (th=<value optimized out>, cfp=0xf7581f84, num=1, blockptr=0x0, flag=8, id=6048, me=0x8b29bc8, recv=145578700) at vm_insnhelper.c:404
#37 vm_call_method (th=<value optimized out>, cfp=0xf7581f84, num=1, blockptr=0x0, flag=8, id=6048, me=0x8b29bc8, recv=145578700) at vm_insnhelper.c:530
#38 0x0815b23e in vm_exec_core (th=<value optimized out>, initial=<value optimized out>) at insns.def:1018
#39 0x0815ed7f in vm_exec (th=<value optimized out>) at vm.c:1236
#40 0x0815f162 in rb_iseq_eval_main (iseqval=146688500) at vm.c:1478
#41 0x0805c192 in ruby_exec_internal (n=<value optimized out>) at eval.c:204
#42 0x0805de72 in ruby_exec_node (n=0x8be49f4) at eval.c:251
#43 ruby_run_node (n=0x8be49f4) at eval.c:244
#44 0x0805b3ea in main (argc=8, argv=0xff9a3ed4) at main.c:38

(gdb) call (void) close(1)
(gdb) call (void) close(2)
(gdb)  call (int) open("/dev/pts/0", 2, 0)
$1 = 1
(gdb)  call (int) open("/dev/pts/0", 2, 0)
$2 = 2
(gdb) call (void)rb_backtrace()
    from /usr/lib/ruby/gems/1.9.3/gems/puma-2.8.1/lib/puma/thread_pool.rb:92:in `block in spawn_thread'
    from /usr/lib/ruby/gems/1.9.3/gems/puma-2.8.1/lib/puma/thread_pool.rb:92:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/puma-2.8.1/lib/puma/server.rb:254:in `block in run'
    from /usr/lib/ruby/gems/1.9.3/gems/puma-2.8.1/lib/puma/server.rb:361:in `process_client'
    from /usr/lib/ruby/gems/1.9.3/gems/puma-2.8.1/lib/puma/server.rb:490:in `handle_request'
    from /usr/lib/ruby/gems/1.9.3/gems/puma-2.8.1/lib/puma/configuration.rb:71:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/dispatcher.rb:106:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/rack-1.1.0/lib/rack/lock.rb:11:in `call'
    from <internal:prelude>:10:in `synchronize'
    from /usr/lib/ruby/gems/1.9.3/gems/rack-1.1.0/lib/rack/lock.rb:11:in `block in call'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/failsafe.rb:26:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/cache/strategy/local_cache.rb:25:in `call'
    from /var/local/meraki/manage-released/lib/rack_pageviews.rb:137:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/connection_adapters/abstract/connection_pool.rb:361:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/query_cache.rb:28:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/query_cache.rb:9:in `cache'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/connection_adapters/abstract/query_cache.rb:34:in `cache'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/query_cache.rb:29:in `block in call'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/session/abstract_store.rb:177:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/params_parser.rb:15:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/rack-1.1.0/lib/rack/methodoverride.rb:24:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/rack-1.1.0/lib/rack/head.rb:9:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/string_coercion.rb:25:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/newrelic_rpm-3.7.2.192/lib/new_relic/rack/agent_hooks.rb:32:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/newrelic_rpm-3.7.2.192/lib/new_relic/rack/agent_hooks.rb:32:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/dispatcher.rb:130:in `block in build_middleware_stack'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/dispatcher.rb:121:in `_call'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/dispatcher.rb:87:in `dispatch'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/routing/route_set.rb:438:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/base.rb:386:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/base.rb:391:in `process'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:606:in `process_with_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/base.rb:532:in `process'
    from /usr/lib/ruby/gems/1.9.3/gems/newrelic_rpm-3.7.2.192/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:341:in `perform_action_with_newrelic_trace'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/flash.rb:151:in `perform_action_with_flash'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/rescue.rb:160:in `perform_action_with_rescue'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/benchmarking.rb:68:in `perform_action_with_benchmark'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/core_ext/benchmark.rb:17:in `ms'
    from /usr/lib/ruby/1.9.3/benchmark.rb:295:in `realtime'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/core_ext/benchmark.rb:17:in `block in ms'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/benchmarking.rb:68:in `block in perform_action_with_benchmark'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:610:in `perform_action_with_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:615:in `call_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:635:in `run_before_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:184:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/callbacks.rb:182:in `evaluate_method'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/callbacks.rb:182:in `call'
    from /var/local/meraki/manage-released/app/controllers/cf_controller.rb:21:in `block in <class:CfController>'
    from /var/local/meraki/manage-released/app/controllers/application.rb:514:in `log_pageview'
    from /var/local/meraki/manage-released/app/controllers/application.rb:514:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:638:in `block in run_before_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:615:in `call_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:635:in `run_before_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:186:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/callbacks.rb:178:in `evaluate_method'
    from /var/local/meraki/manage-released/app/controllers/application.rb:289:in `capture_request_binding'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:638:in `block in run_before_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:615:in `call_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:635:in `run_before_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:186:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/callbacks.rb:178:in `evaluate_method'
    from /var/local/meraki/manage-released/app/controllers/application.rb:296:in `block_html_json'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:638:in `block in run_before_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:615:in `call_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:635:in `run_before_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:186:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/callbacks.rb:178:in `evaluate_method'
    from /var/local/meraki/manage-released/app/controllers/application.rb:121:in `set_log_level_to_info'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:638:in `block in run_before_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:615:in `call_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:635:in `run_before_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:186:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/callbacks.rb:178:in `evaluate_method'
    from /var/local/meraki/manage-released/app/controllers/application.rb:121:in `set_log_level_to_info'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:638:in `block in run_before_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/filters.rb:617:in `call_filters'
    from /usr/lib/ruby/gems/1.9.3/gems/actionpack-2.3.18/lib/action_controller/base.rb:1333:in `perform_action'
    from /var/local/meraki/manage-released/app/controllers/apple_mdm_controller.rb:131:in `ios'
    from /var/local/meraki/manage-released/lib/pcc/apple_mdm/checkin_helpers.rb:23:in `ios_handle_plist'
    from /var/local/meraki/manage-released/lib/pcc/apple_mdm/checkin_helpers.rb:63:in `ios_update_checkin_meta'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/transactions.rb:200:in `save_with_transactions!'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/transactions.rb:208:in `rollback_active_record_state!'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/transactions.rb:200:in `block in save_with_transactions!'
    from /usr/lib/ruby/gems/1.9.3/gems/newrelic_rpm-3.7.2.192/lib/new_relic/agent/method_tracer.rb:544:in `transaction_with_trace_ActiveRecord_self_name_transaction'
    from /usr/lib/ruby/gems/1.9.3/gems/newrelic_rpm-3.7.2.192/lib/new_relic/agent/method_tracer.rb:281:in `trace_execution_scoped'
    from /usr/lib/ruby/gems/1.9.3/gems/newrelic_rpm-3.7.2.192/lib/new_relic/agent/method_tracer.rb:549:in `block in transaction_with_trace_ActiveRecord_self_name_transaction'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/transactions.rb:182:in `transaction'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/connection_adapters/abstract/database_statements.rb:136:in `transaction'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/transactions.rb:200:in `block (2 levels) in save_with_transactions!'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/dirty.rb:87:in `save_with_dirty!'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/validations.rb:1099:in `save_with_validation!'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/base.rb:2602:in `save!'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/callbacks.rb:250:in `create_or_update_with_callbacks'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/base.rb:2935:in `create_or_update'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/callbacks.rb:283:in `update_with_callbacks'
    from /usr/lib/ruby/gems/1.9.3/gems/activerecord-2.3.18/lib/active_record/callbacks.rb:344:in `callback'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/callbacks.rb:276:in `run_callbacks'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/callbacks.rb:92:in `run'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/callbacks.rb:92:in `each'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/callbacks.rb:93:in `block in run'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/callbacks.rb:166:in `call'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/callbacks.rb:196:in `should_run_callback?'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/callbacks.rb:196:in `flatten'
    from /usr/lib/ruby/gems/1.9.3/gems/activesupport-2.3.18/lib/active_support/whiny_nil.rb:48:in `method_missing'
(gdb)

[nachogiljaldo]

I just noticed this issue and mine might be similar: #649

[yaminil]

Any updates on this issue team? It's creating huge issues in production envrionment
Thanks!

[dentarg]

@yaminil please open a new issue where you describe how the problem you are having can be reproduced

this bug is from 2013 and closed (with last comment from 2015) so I wouldn't expect any updates here