* HUP restart is delayed by 2 minutes @ 2014-01-29 6:03 Thorsten von Eicken [not found] ` <52E89997.6020504-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> 0 siblings, 1 reply; 10+ messages in thread From: Thorsten von Eicken @ 2014-01-29 6:03 UTC (permalink / raw) To: rainbows-talk-GrnCvJ7WPxnNLxjTenLetw I'm having trouble getting the HUP restart to work properly (I do have preload_app=false). What happens is that on HUP the master reloads the config file, but it then always takes 2 minutes plus 1-2 seconds for the workers to be reaped. The servers is totally idle, so this is not due to some open connections. Here's how it looks in the log file with 2 worker processes: I, [2014-01-28T21:39:11.106135 #7936] INFO -- : reloading config_file=./config/rainbows.rb I, [2014-01-28T21:39:11.111348 #7936] INFO -- : done reloading config_file=./config/rainbows.rb D, [2014-01-28T21:39:11.112222 #7936] DEBUG -- : waiting 36.5s after suspend/hibernation E, [2014-01-28T21:41:14.786059 #7936] ERROR -- : reaped #<Process::Status: pid 13908 exit 2> worker=0 I, [2014-01-28T21:41:14.786687 #7936] INFO -- : worker=0 spawning... E, [2014-01-28T21:41:14.787357 #7936] ERROR -- : reaped #<Process::Status: pid 13910 exit 2> worker=1 I, [2014-01-28T21:41:14.787576 #7936] INFO -- : worker=1 spawning... I, [2014-01-28T21:41:14.789228 #13932] INFO -- : worker=0 spawned pid=13932 I, [2014-01-28T21:41:14.789925 #13932] INFO -- : Refreshing Gem list I, [2014-01-28T21:41:14.794324 #13934] INFO -- : worker=1 spawned pid=13934 I, [2014-01-28T21:41:14.794639 #13934] INFO -- : Refreshing Gem list (The suspend/hibernation message doesn't always appear.) How can I troubleshoot this? Thanks much! _______________________________________________ Rainbows! mailing list - rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org http://rubyforge.org/mailman/listinfo/rainbows-talk Do not quote signatures (like this one) or top post when replying ^ permalink raw reply [flat|nested] 10+ messages in thread
[parent not found: <52E89997.6020504-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org>]
* Re: HUP restart is delayed by 2 minutes [not found] ` <52E89997.6020504-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> @ 2014-01-29 7:02 ` Eric Wong [not found] ` <20140129070259.GA5938-yBiyF41qdooeIZ0/mPfg9Q@public.gmane.org> 0 siblings, 1 reply; 10+ messages in thread From: Eric Wong @ 2014-01-29 7:02 UTC (permalink / raw) To: Rainbows! list; +Cc: Thorsten von Eicken Thorsten von Eicken <tve-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> wrote: > I'm having trouble getting the HUP restart to work properly (I do have > preload_app=false). What happens is that on HUP the master reloads the > config file, but it then always takes 2 minutes plus 1-2 seconds for the > workers to be reaped. The servers is totally idle, so this is not due to > some open connections. Here's how it looks in the log file with 2 worker > processes: Which concurrency option are you using and which version of Rainbows!, unicorn and Ruby is this? > I, [2014-01-28T21:39:11.106135 #7936] INFO -- : reloading > config_file=./config/rainbows.rb > I, [2014-01-28T21:39:11.111348 #7936] INFO -- : done reloading > config_file=./config/rainbows.rb > D, [2014-01-28T21:39:11.112222 #7936] DEBUG -- : waiting 36.5s after > suspend/hibernation > E, [2014-01-28T21:41:14.786059 #7936] ERROR -- : reaped > #<Process::Status: pid 13908 exit 2> worker=0 That definitely doesn't look right. We need to know as much about your configuration and versions as possible. _______________________________________________ Rainbows! mailing list - rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org http://rubyforge.org/mailman/listinfo/rainbows-talk Do not quote signatures (like this one) or top post when replying ^ permalink raw reply [flat|nested] 10+ messages in thread
[parent not found: <20140129070259.GA5938-yBiyF41qdooeIZ0/mPfg9Q@public.gmane.org>]
* Re: HUP restart is delayed by 2 minutes [not found] ` <20140129070259.GA5938-yBiyF41qdooeIZ0/mPfg9Q@public.gmane.org> @ 2014-01-29 7:26 ` Thorsten von Eicken [not found] ` <52E8AD1B.8090009-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> 0 siblings, 1 reply; 10+ messages in thread From: Thorsten von Eicken @ 2014-01-29 7:26 UTC (permalink / raw) To: Rainbows! list On 1/28/2014 11:02 PM, Eric Wong wrote: > Thorsten von Eicken <tve-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> wrote: >> I'm having trouble getting the HUP restart to work properly (I do have >> preload_app=false). What happens is that on HUP the master reloads the >> config file, but it then always takes 2 minutes plus 1-2 seconds for the >> workers to be reaped. The servers is totally idle, so this is not due to >> some open connections. Here's how it looks in the log file with 2 worker >> processes: > Which concurrency option are you using and which version of Rainbows!, > unicorn and Ruby is this? root@vscale:/home/vscale-admin/current# bundle show rainbows /var/lib/gems/1.9.1/gems/rainbows-4.5.0 root@vscale:/home/vscale-admin/current# bundle show unicorn /var/lib/gems/1.9.1/gems/unicorn-4.7.0 root@vscale:/home/vscale-admin/current# bundle exec ruby -v ruby 1.9.3p0 (2011-10-30 revision 33570) [x86_64-linux] root@vscale:/home/vscale-admin/current# bundle exec rainbows --version Rainbows! v4.5.0 Rainbows! do use :EventMachine # concurrency model to use worker_connections 5 keepalive_timeout 2 # zero disables keepalives entirely client_max_body_size 5*1024*1024 # 5 megabytes Rainbows.module_eval do EventMachine.kqueue = false if RUBY_PLATFORM =~ /darwin/i end end worker_processes 2 # make this configurable later stderr_path LOG_FILE stdout_path LOG_FILE timeout 120 listen "127.0.0.1:8001", :tcp_nopush => true preload_app false > >> I, [2014-01-28T21:39:11.106135 #7936] INFO -- : reloading >> config_file=./config/rainbows.rb >> I, [2014-01-28T21:39:11.111348 #7936] INFO -- : done reloading >> config_file=./config/rainbows.rb >> D, [2014-01-28T21:39:11.112222 #7936] DEBUG -- : waiting 36.5s after >> suspend/hibernation >> E, [2014-01-28T21:41:14.786059 #7936] ERROR -- : reaped >> #<Process::Status: pid 13908 exit 2> worker=0 > That definitely doesn't look right. We need to know as much about > your configuration and versions as possible. I'm happy to add some debug statements if you point me to an appropriate place in the code. Thanks! _______________________________________________ Rainbows! mailing list - rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org http://rubyforge.org/mailman/listinfo/rainbows-talk Do not quote signatures (like this one) or top post when replying ^ permalink raw reply [flat|nested] 10+ messages in thread
[parent not found: <52E8AD1B.8090009-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org>]
* Re: HUP restart is delayed by 2 minutes [not found] ` <52E8AD1B.8090009-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> @ 2014-01-29 7:32 ` Eric Wong 2014-01-29 8:31 ` Eric Wong 1 sibling, 0 replies; 10+ messages in thread From: Eric Wong @ 2014-01-29 7:32 UTC (permalink / raw) To: Rainbows! list; +Cc: Thorsten von Eicken Thorsten von Eicken <tve-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> wrote: > I'm happy to add some debug statements if you point me to an appropriate > place in the code. Thanks! I'll try to reproduce it in a bit. Meanwhile, since you're on Linux, try running strace on a worker while it happens. _______________________________________________ Rainbows! mailing list - rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org http://rubyforge.org/mailman/listinfo/rainbows-talk Do not quote signatures (like this one) or top post when replying ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: HUP restart is delayed by 2 minutes [not found] ` <52E8AD1B.8090009-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> 2014-01-29 7:32 ` Eric Wong @ 2014-01-29 8:31 ` Eric Wong [not found] ` <20140129083147.GA26652-yBiyF41qdooeIZ0/mPfg9Q@public.gmane.org> 1 sibling, 1 reply; 10+ messages in thread From: Eric Wong @ 2014-01-29 8:31 UTC (permalink / raw) To: Rainbows! list; +Cc: Thorsten von Eicken Thorsten von Eicken <tve-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> wrote: > On 1/28/2014 11:02 PM, Eric Wong wrote: > > Thorsten von Eicken <tve-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> wrote: > >> I'm having trouble getting the HUP restart to work properly (I do have > >> preload_app=false). What happens is that on HUP the master reloads the > >> config file, but it then always takes 2 minutes plus 1-2 seconds for the > >> workers to be reaped. The servers is totally idle, so this is not due to > >> some open connections. Here's how it looks in the log file with 2 worker > >> processes: > > Which concurrency option are you using and which version of Rainbows!, > > unicorn and Ruby is this? > root@vscale:/home/vscale-admin/current# bundle show rainbows > /var/lib/gems/1.9.1/gems/rainbows-4.5.0 > root@vscale:/home/vscale-admin/current# bundle show unicorn > /var/lib/gems/1.9.1/gems/unicorn-4.7.0 > root@vscale:/home/vscale-admin/current# bundle exec ruby -v > ruby 1.9.3p0 (2011-10-30 revision 33570) [x86_64-linux] > root@vscale:/home/vscale-admin/current# bundle exec rainbows --version > Rainbows! v4.5.0 This looks like a symptom of unicorn 4.8.0 interacting badly with rainbows 4.5.0, not unicorn 4.7.0. Can you give rainbows 4.6.0 + unicorn 4.8.0 a try? Unfortunately, I broke rainbows 4.5.0 and earlier with unicorn 4.8.0 :x I'll be pushing out unicorn 4.8.1 soon with a minor, unrelated bugfix. _______________________________________________ Rainbows! mailing list - rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org http://rubyforge.org/mailman/listinfo/rainbows-talk Do not quote signatures (like this one) or top post when replying ^ permalink raw reply [flat|nested] 10+ messages in thread
[parent not found: <20140129083147.GA26652-yBiyF41qdooeIZ0/mPfg9Q@public.gmane.org>]
* Re: HUP restart is delayed by 2 minutes [not found] ` <20140129083147.GA26652-yBiyF41qdooeIZ0/mPfg9Q@public.gmane.org> @ 2014-01-29 20:11 ` Thorsten von Eicken [not found] ` <52E9607A.60107-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> 0 siblings, 1 reply; 10+ messages in thread From: Thorsten von Eicken @ 2014-01-29 20:11 UTC (permalink / raw) To: Rainbows! list On 1/29/2014 12:31 AM, Eric Wong wrote: > Thorsten von Eicken <tve-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> wrote: >> On 1/28/2014 11:02 PM, Eric Wong wrote: >>> Thorsten von Eicken <tve-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> wrote: >>>> I'm having trouble getting the HUP restart to work properly (I do have >>>> preload_app=false). What happens is that on HUP the master reloads the >>>> config file, but it then always takes 2 minutes plus 1-2 seconds for the >>>> workers to be reaped. The servers is totally idle, so this is not due to >>>> some open connections. Here's how it looks in the log file with 2 worker >>>> processes: >>> Which concurrency option are you using and which version of Rainbows!, >>> unicorn and Ruby is this? >> root@vscale:/home/vscale-admin/current# bundle show rainbows >> /var/lib/gems/1.9.1/gems/rainbows-4.5.0 >> root@vscale:/home/vscale-admin/current# bundle show unicorn >> /var/lib/gems/1.9.1/gems/unicorn-4.7.0 >> root@vscale:/home/vscale-admin/current# bundle exec ruby -v >> ruby 1.9.3p0 (2011-10-30 revision 33570) [x86_64-linux] >> root@vscale:/home/vscale-admin/current# bundle exec rainbows --version >> Rainbows! v4.5.0 > This looks like a symptom of unicorn 4.8.0 interacting badly > with rainbows 4.5.0, not unicorn 4.7.0. Can you give > rainbows 4.6.0 + unicorn 4.8.0 a try? Unfortunately, I broke > rainbows 4.5.0 and earlier with unicorn 4.8.0 :x > > I'll be pushing out unicorn 4.8.1 soon with a minor, unrelated bugfix. > I am now running with Rainbows 4.6.0 and Unicorn 4.8.1 and still see the same, but not always (the first restart only took 3-4 seconds to happen). I'm printing the versions in the config file: Rainbows version: 4.6.0 Unicorn version: 4.8.1 I, [2014-01-29T11:55:43.687022 #18919] INFO -- : done reloading config_file=./config/rainbows.rb I did an strace of a worker process and not much is happening: $ strace -p 19255 Process 19255 attached - interrupt to quit ppoll([{fd=9, events=POLLIN|POLLPRI}], 1, {0, 805429204}, NULL, 8) = 0 (Timeout) ppoll([{fd=9, events=POLLIN|POLLPRI}], 1, {0, 999995000}, NULL, 8) = 0 (Timeout) ppoll([{fd=9, events=POLLIN|POLLPRI}], 1, {0, 999996000}, NULL, 8) = 0 (Timeout) ... ppoll([{fd=9, events=POLLIN|POLLPRI}], 1, {0, 999997000}, NULL, 8) = 0 (Timeout) ppoll([{fd=9, events=POLLIN|POLLPRI}], 1, {0, 999996000}, NULL, 8) = 0 (Timeout) ppoll([{fd=9, events=POLLIN|POLLPRI}], 1, {0, 999997000}, NULL, 8) = 0 (Timeout) exit_group(2) = ? Process 19255 detached Here's an strace of the master process (the workers at that time were 19781 and 19783). I marked the spot where everything just sits waiting for 2 minutes and there clearly is a select call with a 2 minute timeout. --- SIGVTALRM (Virtual timer expired) @ 0 (0) --- rt_sigreturn(0x1a) = -1 EINTR (Interrupted system call) futex(0x7f0ac29b67a0, FUTEX_WAIT_PRIVATE, 2, NULL) = 0 futex(0x7f0ac29b67a0, FUTEX_WAKE_PRIVATE, 1) = 0 rt_sigprocmask(SIG_SETMASK, ~[SEGV VTALRM RTMIN RT_1], NULL, 8) = 0 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 fcntl(6, F_GETFL) = 0x801 (flags O_WRONLY|O_NONBLOCK) write(6, ".", 1) = 1 select(6, [5], NULL, NULL, {77, 985736}) = 1 (in [5], left {77, 985735}) fcntl(5, F_GETFL) = 0x800 (flags O_RDONLY|O_NONBLOCK) read(5, ".", 11) = 1 wait4(-1, 0x7fff006feabc, WNOHANG, NULL) = 0 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2819, ...}) = 0 write(2, "I, [2014-01-29T12:03:19.875207 #"..., 93) = 93 open("./config/rainbows.rb", O_RDONLY) = 8 fstat(8, {st_mode=S_IFREG|0644, st_size=1642, ...}) = 0 fstat(8, {st_mode=S_IFREG|0644, st_size=1642, ...}) = 0 ioctl(8, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fff006fe8c8) = -1 ENOTTY (Inappropriate ioctl for device) fstat(8, {st_mode=S_IFREG|0644, st_size=1642, ...}) = 0 lseek(8, 0, SEEK_CUR) = 0 read(8, "# See http://unicorn.bogomips.or"..., 1642) = 1642 read(8, "", 8192) = 0 close(8) = 0 getcwd("/home/vscale-admin/git", 200) = 23 write(2, "./config/rainbows.rb:4: warning:"..., 71) = 71 write(1, "APP_PATH is /home/vscale-admin/c"..., 38) = 38 write(1, "\n", 1) = 1 write(2, "./config/rainbows.rb:8: warning:"..., 71) = 71 write(2, "./config/rainbows.rb:9: warning:"..., 71) = 71 stat("/home/vscale-admin/current/./config/rainbows.rb", {st_mode=S_IFREG|0644, st_size=1642, ...}) = 0 geteuid() = 0 getegid() = 0 getuid() = 0 getgid() = 0 access("/home/vscale-admin/current/./config/rainbows.rb", R_OK) = 0 chdir("/home/vscale-admin/current") = 0 write(1, "Rainbows version: 4.6.0", 23) = 23 write(1, "\n", 1) = 1 write(1, "Unicorn version: 4.8.1", 22) = 22 write(1, "\n", 1) = 1 stat("./config.ru", {st_mode=S_IFREG|0644, st_size=633, ...}) = 0 geteuid() = 0 getegid() = 0 getuid() = 0 getgid() = 0 access("./config.ru", R_OK) = 0 open("./config.ru", O_RDONLY) = 8 fstat(8, {st_mode=S_IFREG|0644, st_size=633, ...}) = 0 fstat(8, {st_mode=S_IFREG|0644, st_size=633, ...}) = 0 ioctl(8, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fff006fe8c8) = -1 ENOTTY (Inappropriate ioctl for device) fstat(8, {st_mode=S_IFREG|0644, st_size=633, ...}) = 0 lseek(8, 0, SEEK_CUR) = 0 read(8, "require 'rack/mount'\nrequire Fil"..., 633) = 633 brk(0x24c6000) = 0x24c6000 read(8, "", 8192) = 0 brk(0x24c4000) = 0x24c4000 close(8) = 0 stat("/var/run/admin.pid", {st_mode=S_IFREG|0644, st_size=6, ...}) = 0 geteuid() = 0 getegid() = 0 getuid() = 0 getgid() = 0 access("/var/run/admin.pid", W_OK) = 0 stat("/var/log/admin.log", {st_mode=S_IFREG|0644, st_size=606916, ...}) = 0 geteuid() = 0 getegid() = 0 getuid() = 0 getgid() = 0 access("/var/log/admin.log", W_OK) = 0 stat("/var/log/admin.log", {st_mode=S_IFREG|0644, st_size=606916, ...}) = 0 geteuid() = 0 getegid() = 0 getuid() = 0 getgid() = 0 access("/var/log/admin.log", W_OK) = 0 open("/var/run/admin.pid", O_RDONLY) = 8 fstat(8, {st_mode=S_IFREG|0644, st_size=6, ...}) = 0 fstat(8, {st_mode=S_IFREG|0644, st_size=6, ...}) = 0 ioctl(8, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fff006fe3a8) = -1 ENOTTY (Inappropriate ioctl for device) fstat(8, {st_mode=S_IFREG|0644, st_size=6, ...}) = 0 lseek(8, 0, SEEK_CUR) = 0 read(8, "18919\n", 6) = 6 read(8, "", 8192) = 0 close(8) = 0 kill(18919, SIG_0) = 0 getsockname(7, {sa_family=AF_INET, sin_port=htons(8001), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0 getsockname(7, {sa_family=AF_INET, sin_port=htons(8001), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0 getsockname(7, {sa_family=AF_INET, sin_port=htons(8001), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0 getsockname(7, {sa_family=AF_INET, sin_port=htons(8001), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0 setsockopt(7, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0 getsockname(7, {sa_family=AF_INET, sin_port=htons(8001), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0 setsockopt(7, SOL_TCP, TCP_NODELAY, [1], 4) = 0 getsockname(7, {sa_family=AF_INET, sin_port=htons(8001), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0 setsockopt(7, SOL_TCP, TCP_CORK, [1], 4) = 0 getsockname(7, {sa_family=AF_INET, sin_port=htons(8001), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0 setsockopt(7, SOL_TCP, TCP_DEFER_ACCEPT, [60], 4) = 0 listen(7, 1024) = 0 open("/var/log/admin.log", O_WRONLY|O_CREAT|O_APPEND, 0666) = 8 fstat(8, {st_mode=S_IFREG|0644, st_size=606916, ...}) = 0 fstat(8, {st_mode=S_IFREG|0644, st_size=606916, ...}) = 0 ioctl(8, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fff006fe388) = -1 ENOTTY (Inappropriate ioctl for device) dup2(8, 2) = 2 fstat(2, {st_mode=S_IFREG|0644, st_size=606916, ...}) = 0 close(8) = 0 open("/var/log/admin.log", O_WRONLY|O_CREAT|O_APPEND, 0666) = 8 fstat(8, {st_mode=S_IFREG|0644, st_size=606916, ...}) = 0 fstat(8, {st_mode=S_IFREG|0644, st_size=606916, ...}) = 0 ioctl(8, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fff006fe388) = -1 ENOTTY (Inappropriate ioctl for device) dup2(8, 1) = 1 fstat(1, {st_mode=S_IFREG|0644, st_size=606916, ...}) = 0 close(8) = 0 fcntl(9, F_GETFL) = 0x1 (flags O_WRONLY) fcntl(9, F_SETFL, O_WRONLY|O_NONBLOCK) = 0 write(9, "\3\0\0\0", 4) = 4 fcntl(10, F_GETFL) = 0x1 (flags O_WRONLY) fcntl(10, F_SETFL, O_WRONLY|O_NONBLOCK) = 0 write(10, "\3\0\0\0", 4) = 4 fstat(2, {st_mode=S_IFREG|0644, st_size=606916, ...}) = 0 fcntl(2, F_GETFL) = 0x8401 (flags O_WRONLY|O_APPEND|O_LARGEFILE) fstat(1, {st_mode=S_IFREG|0644, st_size=606916, ...}) = 0 fcntl(1, F_GETFL) = 0x8401 (flags O_WRONLY|O_APPEND|O_LARGEFILE) fstat(2, {st_mode=S_IFREG|0644, st_size=606916, ...}) = 0 stat("/var/log/admin.log", {st_mode=S_IFREG|0644, st_size=606916, ...}) = 0 fstat(1, {st_mode=S_IFREG|0644, st_size=606916, ...}) = 0 stat("/var/log/admin.log", {st_mode=S_IFREG|0644, st_size=606916, ...}) = 0 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2819, ...}) = 0 write(2, "I, [2014-01-29T12:03:19.887123 #"..., 98) = 98 wait4(-1, 0x7fff006feabc, WNOHANG, NULL) = 0 select(6, [5], NULL, NULL, {120, 0} # ======================== LONG DELAY HERE ==================================== ) = 0 (Timeout) wait4(-1, 0x7fff006feabc, WNOHANG, NULL) = 0 select(6, [5], NULL, NULL, {120, 0}) = ? ERESTARTNOHAND (To be restarted) --- SIGCHLD (Child exited) @ 0 (0) --- write(4, "!", 1) = 1 --- SIGVTALRM (Virtual timer expired) @ 0 (0) --- rt_sigreturn(0x1a) = 1 rt_sigreturn(0x2) = -1 EINTR (Interrupted system call) futex(0x1902708, FUTEX_WAIT_PRIVATE, 2, NULL) = 0 --- SIGVTALRM (Virtual timer expired) @ 0 (0) --- rt_sigreturn(0x1a) = 0 futex(0x1902708, FUTEX_WAKE_PRIVATE, 1) = 0 rt_sigprocmask(SIG_SETMASK, ~[SEGV VTALRM RTMIN RT_1], NULL, 8) = 0 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 fcntl(6, F_GETFL) = 0x801 (flags O_WRONLY|O_NONBLOCK) write(6, ".", 1) = 1 select(6, [5], NULL, NULL, {116, 267701}) = 1 (in [5], left {116, 267700}) fcntl(5, F_GETFL) = 0x800 (flags O_RDONLY|O_NONBLOCK) read(5, ".", 11) = 1 wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 2}], WNOHANG, NULL) = 19781 close(9) = 0 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2819, ...}) = 0 write(2, "E, [2014-01-29T12:05:23.674893 #"..., 103) = 103 wait4(-1, 0x7fff006feabc, WNOHANG, NULL) = 0 getrlimit(RLIMIT_NOFILE, {rlim_cur=1024, rlim_max=4*1024}) = 0 pipe([8, 9]) = 0 fstat(8, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0 fstat(9, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0 fcntl(8, F_GETFL) = 0 (flags O_RDONLY) fstat(8, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0 ioctl(8, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fff006fe338) = -1 ENOTTY (Inappropriate ioctl for device) fcntl(9, F_GETFL) = 0x1 (flags O_WRONLY) fstat(9, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0 ioctl(9, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fff006fe338) = -1 ENOTTY (Inappropriate ioctl for device) fcntl(8, F_SETFD, FD_CLOEXEC) = 0 fcntl(9, F_SETFD, FD_CLOEXEC) = 0 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2819, ...}) = 0 write(2, "I, [2014-01-29T12:05:23.676466 #"..., 71) = 71 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 rt_sigaction(SIGPIPE, {0x7f0ac26607a0, [], SA_RESTORER|SA_SIGINFO, 0x7f0ac221b4a0}, {SIG_IGN, [], SA_RESTORER|SA_SIGINFO, 0x7f0ac221b4a0}, 8) = 0 write(4, "!", 1) = 1 futex(0x7f0ac2bd89d0, FUTEX_WAIT, 19784, NULL) = ? ERESTARTSYS (To be restarted) --- SIGCHLD (Child exited) @ 0 (0) --- write(4, "!", 1) = 1 rt_sigreturn(0x2) = -1 EINTR (Interrupted system call) futex(0x7f0ac2bd89d0, FUTEX_WAIT, 19784, NULL) = 0 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f0ac2bcf9d0) = 19798 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 clone(child_stack=0x7f0ac2bd7ff0, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x7f0ac2bd89d0, tls=0x7f0ac2bd8700, child_tidptr=0x7f0ac2bd89d0) = 19799 rt_sigprocmask(SIG_SETMASK, ~[SEGV VTALRM RTMIN RT_1], NULL, 8) = 0 rt_sigaction(SIGPIPE, {SIG_IGN, [], SA_RESTORER|SA_SIGINFO, 0x7f0ac221b4a0}, {0x7f0ac26607a0, [], SA_RESTORER|SA_SIGINFO, 0x7f0ac221b4a0}, 8) = 0 rt_sigprocmask(SIG_SETMASK, ~[SEGV VTALRM RTMIN RT_1], NULL, 8) = 0 close(8) = 0 select(6, [5], NULL, NULL, {120, 0}) = ? ERESTARTNOHAND (To be restarted) --- SIGVTALRM (Virtual timer expired) @ 0 (0) --- rt_sigreturn(0x1a) = -1 EINTR (Interrupted system call) futex(0x1902708, FUTEX_WAIT_PRIVATE, 2, NULL) = 0 futex(0x1902708, FUTEX_WAKE_PRIVATE, 1) = 0 rt_sigprocmask(SIG_SETMASK, ~[SEGV VTALRM RTMIN RT_1], NULL, 8) = 0 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 fcntl(6, F_GETFL) = 0x801 (flags O_WRONLY|O_NONBLOCK) write(6, ".", 1) = 1 select(6, [5], NULL, NULL, {119, 999369}) = 1 (in [5], left {119, 999368}) fcntl(5, F_GETFL) = 0x800 (flags O_RDONLY|O_NONBLOCK) read(5, ".", 11) = 1 wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 2}], WNOHANG, NULL) = 19783 close(10) = 0 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2819, ...}) = 0 write(2, "E, [2014-01-29T12:05:23.681011 #"..., 103) = 103 wait4(-1, 0x7fff006feabc, WNOHANG, NULL) = 0 getrlimit(RLIMIT_NOFILE, {rlim_cur=1024, rlim_max=4*1024}) = 0 pipe([8, 10]) = 0 fstat(8, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0 fstat(10, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0 fcntl(8, F_GETFL) = 0 (flags O_RDONLY) fstat(8, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0 ioctl(8, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fff006fe338) = -1 ENOTTY (Inappropriate ioctl for device) fcntl(10, F_GETFL) = 0x1 (flags O_WRONLY) fstat(10, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0 ioctl(10, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fff006fe338) = -1 ENOTTY (Inappropriate ioctl for device) fcntl(8, F_SETFD, FD_CLOEXEC) = 0 fcntl(10, F_SETFD, FD_CLOEXEC) = 0 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2819, ...}) = 0 write(2, "I, [2014-01-29T12:05:23.682344 #"..., 71) = 71 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 rt_sigaction(SIGPIPE, {0x7f0ac26607a0, [], SA_RESTORER|SA_SIGINFO, 0x7f0ac221b4a0}, {SIG_IGN, [], SA_RESTORER|SA_SIGINFO, 0x7f0ac221b4a0}, 8) = 0 write(4, "!", 1) = 1 futex(0x7f0ac2bd89d0, FUTEX_WAIT, 19799, NULL) = 0 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f0ac2bcf9d0) = 19800 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 clone(child_stack=0x7f0ac2bd7ff0, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x7f0ac2bd89d0, tls=0x7f0ac2bd8700, child_tidptr=0x7f0ac2bd89d0) = 19801 rt_sigprocmask(SIG_SETMASK, ~[SEGV VTALRM RTMIN RT_1], NULL, 8) = 0 rt_sigaction(SIGPIPE, {SIG_IGN, [], SA_RESTORER|SA_SIGINFO, 0x7f0ac221b4a0}, {0x7f0ac26607a0, [], SA_RESTORER|SA_SIGINFO, 0x7f0ac221b4a0}, 8) = 0 rt_sigprocmask(SIG_SETMASK, ~[SEGV VTALRM RTMIN RT_1], NULL, 8) = 0 close(8) = 0 select(6, [5], NULL, NULL, {120, 0} ^C <unfinished ...> Process 18919 detached My config file is: # See http://unicorn.bogomips.org/Unicorn/Configurator.html for complete # documentation. APP_PATH = File.expand_path(File.join(File.dirname(__FILE__), '../../current')) puts "APP_PATH is #{APP_PATH}" if [ 'staging', 'production' ].include?(ENV['RACK_ENV']) PID_FILE = '/var/run/admin.pid' LOG_FILE = '/var/log/admin.log' else PID_FILE = File.join(APP_PATH, 'rainbows.pid') LOG_FILE = APP_PATH + "/log/admin.log" end Rainbows! do use :EventMachine # concurrency model to use worker_connections 5 keepalive_timeout 2 # zero disables keepalives entirely client_max_body_size 5*1024*1024 # 5 megabytes Rainbows.module_eval do EventMachine.kqueue = false if RUBY_PLATFORM =~ /darwin/i end end # Help ensure your application will always spawn in the symlinked # "current" directory that Capistrano sets up. working_directory APP_PATH worker_processes 2 # make this configurable later stderr_path LOG_FILE stdout_path LOG_FILE # Requests can take a looonng time timeout 120 # we use a shorter backlog for quicker failover when busy listen "127.0.0.1:8001", :tcp_nopush => true # PID file location pid PID_FILE # Don't preload app: minimal savings and breaks HUP process control signal preload_app false GC.respond_to?(:copy_on_write_friendly=) and GC.copy_on_write_friendly = true puts "Rainbows version: #{Rainbows::Const::RAINBOWS_VERSION}" puts "Unicorn version: #{Rainbows::Const::UNICORN_VERSION}" _______________________________________________ Rainbows! mailing list - rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org http://rubyforge.org/mailman/listinfo/rainbows-talk Do not quote signatures (like this one) or top post when replying ^ permalink raw reply [flat|nested] 10+ messages in thread
[parent not found: <52E9607A.60107-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org>]
* Re: HUP restart is delayed by 2 minutes [not found] ` <52E9607A.60107-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> @ 2014-01-29 22:03 ` Eric Wong [not found] ` <20140129220352.GA24393-yBiyF41qdooeIZ0/mPfg9Q@public.gmane.org> 0 siblings, 1 reply; 10+ messages in thread From: Eric Wong @ 2014-01-29 22:03 UTC (permalink / raw) To: Rainbows! list; +Cc: Thorsten von Eicken Thanks! Can you try this? Sorry I haven't maintained EM support well, I forgot some versions were broken under Ruby 2.x :x (also "gem install --pre -v 4.6.0.4.g4108 rainbows" should work) --- a/lib/rainbows/event_machine.rb +++ b/lib/rainbows/event_machine.rb @@ -88,7 +88,17 @@ module Rainbows::EventMachine raise RuntimeError, "EM @conns instance variable not accessible!" Rainbows::EventMachine::Server.const_set(:CUR, conns) Rainbows.at_quit do - EM.next_tick { conns.each_value { |c| client_class === c and c.quit } } + EM.next_tick do + LISTENERS.clear + conns.each_value do |c| + case c + when client_class + c.quit + when Rainbows::EventMachine::Server + c.detach + end + end + end end EM.add_periodic_timer(1) do EM.stop if ! Rainbows.tick && conns.empty? && EM.reactor_running? _______________________________________________ Rainbows! mailing list - rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org http://rubyforge.org/mailman/listinfo/rainbows-talk Do not quote signatures (like this one) or top post when replying ^ permalink raw reply [flat|nested] 10+ messages in thread
[parent not found: <20140129220352.GA24393-yBiyF41qdooeIZ0/mPfg9Q@public.gmane.org>]
* Re: HUP restart is delayed by 2 minutes [not found] ` <20140129220352.GA24393-yBiyF41qdooeIZ0/mPfg9Q@public.gmane.org> @ 2014-01-29 22:41 ` Thorsten von Eicken 2014-03-17 21:23 ` Thorsten von Eicken 1 sibling, 0 replies; 10+ messages in thread From: Thorsten von Eicken @ 2014-01-29 22:41 UTC (permalink / raw) To: Rainbows! list On 1/29/2014 2:03 PM, Eric Wong wrote: > Thanks! Can you try this? Sorry I haven't maintained EM support > well, I forgot some versions were broken under Ruby 2.x :x > > (also "gem install --pre -v 4.6.0.4.g4108 rainbows" should work) > > --- a/lib/rainbows/event_machine.rb > +++ b/lib/rainbows/event_machine.rb > @@ -88,7 +88,17 @@ module Rainbows::EventMachine > raise RuntimeError, "EM @conns instance variable not accessible!" > Rainbows::EventMachine::Server.const_set(:CUR, conns) > Rainbows.at_quit do > - EM.next_tick { conns.each_value { |c| client_class === c and c.quit } } > + EM.next_tick do > + LISTENERS.clear > + conns.each_value do |c| > + case c > + when client_class > + c.quit > + when Rainbows::EventMachine::Server > + c.detach > + end > + end > + end > end > EM.add_periodic_timer(1) do > EM.stop if ! Rainbows.tick && conns.empty? && EM.reactor_running? > This indeed seems to fix it! Thanks much! _______________________________________________ Rainbows! mailing list - rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org http://rubyforge.org/mailman/listinfo/rainbows-talk Do not quote signatures (like this one) or top post when replying ^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: HUP restart is delayed by 2 minutes [not found] ` <20140129220352.GA24393-yBiyF41qdooeIZ0/mPfg9Q@public.gmane.org> 2014-01-29 22:41 ` Thorsten von Eicken @ 2014-03-17 21:23 ` Thorsten von Eicken [not found] ` <532767E2.70509-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> 1 sibling, 1 reply; 10+ messages in thread From: Thorsten von Eicken @ 2014-03-17 21:23 UTC (permalink / raw) To: Eric Wong; +Cc: Rainbows! list Thanks for the 4.6.1 update. I pulled it a few weeks ago, but I am still having problems with the rainbows restart and EM. I pretty consistently get a segfault: /var/lib/gems/1.9.1/gems/eventmachine-1.0.3/lib/eventmachine.rb:187: [BUG] Segmentation fault ruby 1.9.3p0 (2011-10-30 revision 33570) [x86_64-linux] -- Control frame information ----------------------------------------------- c:0014 p:---- s:0064 b:0064 l:000063 d:000063 CFUNC :run_machine c:0013 p:0325 s:0061 b:0061 l:000060 d:000060 METHOD /var/lib/gems/1.9.1/gems/eventmachine-1.0.3/lib/eventmachine.rb:187 c:0012 p:0304 s:0054 b:0054 l:0008e8 d:0008e8 METHOD /var/lib/gems/1.9.1/gems/rainbows-4.6.1/lib/rainbows/event_machine.rb:86 c:0011 p:0103 s:0047 b:0047 l:000046 d:000046 METHOD /var/lib/gems/1.9.1/gems/rainbows-4.6.1/lib/rainbows/http_server.rb:45 c:0010 p:0146 s:0041 b:0041 l:000040 d:000040 METHOD /var/lib/gems/1.9.1/gems/unicorn-4.8.2/lib/unicorn/http_server.rb:521 c:0009 p:0252 s:0034 b:0034 l:000033 d:000033 METHOD /var/lib/gems/1.9.1/gems/rainbows-4.6.1/lib/rainbows/http_server.rb:61 c:0008 p:0058 s:0030 b:0030 l:000029 d:000029 METHOD /var/lib/gems/1.9.1/gems/unicorn-4.8.2/lib/unicorn/http_server.rb:532 c:0007 p:0347 s:0026 b:0026 l:000025 d:000025 METHOD /var/lib/gems/1.9.1/gems/unicorn-4.8.2/lib/unicorn/http_server.rb:290 c:0006 p:0264 s:0019 b:0019 l:001f28 d:001f28 TOP /var/lib/gems/1.9.1/gems/rainbows-4.6.1/bin/rainbows:127 c:0005 p:---- s:0013 b:0013 l:000012 d:000012 FINISH c:0004 p:---- s:0011 b:0011 l:000010 d:000010 CFUNC :load c:0003 p:0127 s:0007 b:0007 l:000ae8 d:002080 EVAL /var/lib/gems/1.9.1/bin/rainbows:19 c:0002 p:---- s:0004 b:0004 l:000003 d:000003 FINISH c:0001 p:0000 s:0002 b:0002 l:000ae8 d:000ae8 TOP -- Ruby level backtrace information ---------------------------------------- /var/lib/gems/1.9.1/bin/rainbows:19:in `<main>' /var/lib/gems/1.9.1/bin/rainbows:19:in `load' /var/lib/gems/1.9.1/gems/rainbows-4.6.1/bin/rainbows:127:in `<top (required)>' /var/lib/gems/1.9.1/gems/unicorn-4.8.2/lib/unicorn/http_server.rb:290:in `join' /var/lib/gems/1.9.1/gems/unicorn-4.8.2/lib/unicorn/http_server.rb:532:in `maintain_worker_count' /var/lib/gems/1.9.1/gems/rainbows-4.6.1/lib/rainbows/http_server.rb:61:in `spawn_missing_workers' /var/lib/gems/1.9.1/gems/unicorn-4.8.2/lib/unicorn/http_server.rb:521:in `spawn_missing_workers' /var/lib/gems/1.9.1/gems/rainbows-4.6.1/lib/rainbows/http_server.rb:45:in `worker_loop' /var/lib/gems/1.9.1/gems/rainbows-4.6.1/lib/rainbows/event_machine.rb:86:in `worker_loop' /var/lib/gems/1.9.1/gems/eventmachine-1.0.3/lib/eventmachine.rb:187:in `run' /var/lib/gems/1.9.1/gems/eventmachine-1.0.3/lib/eventmachine.rb:187:in `run_machine' -- C level backtrace information ------------------------------------------- /var/lib/gems/1.9.1/gems/eventmachine-1.0.3/lib/eventmachine.rb:187: [BUG] Segmentation fault ruby 1.9.3p0 (2011-10-30 revision 33570) [x86_64-linux] I'm happy to provide additional information, if useful! Cheers, Thorsten On 1/29/2014 2:03 PM, Eric Wong wrote: > Thanks! Can you try this? Sorry I haven't maintained EM support > well, I forgot some versions were broken under Ruby 2.x :x > > (also "gem install --pre -v 4.6.0.4.g4108 rainbows" should work) > > --- a/lib/rainbows/event_machine.rb > +++ b/lib/rainbows/event_machine.rb > @@ -88,7 +88,17 @@ module Rainbows::EventMachine > raise RuntimeError, "EM @conns instance variable not accessible!" > Rainbows::EventMachine::Server.const_set(:CUR, conns) > Rainbows.at_quit do > - EM.next_tick { conns.each_value { |c| client_class === c and c.quit } } > + EM.next_tick do > + LISTENERS.clear > + conns.each_value do |c| > + case c > + when client_class > + c.quit > + when Rainbows::EventMachine::Server > + c.detach > + end > + end > + end > end > EM.add_periodic_timer(1) do > EM.stop if ! Rainbows.tick && conns.empty? && EM.reactor_running? > _______________________________________________ Rainbows! mailing list - rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org http://rubyforge.org/mailman/listinfo/rainbows-talk Do not quote signatures (like this one) or top post when replying ^ permalink raw reply [flat|nested] 10+ messages in thread
[parent not found: <532767E2.70509-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org>]
* Re: HUP restart is delayed by 2 minutes [not found] ` <532767E2.70509-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> @ 2014-03-17 21:27 ` Eric Wong 0 siblings, 0 replies; 10+ messages in thread From: Eric Wong @ 2014-03-17 21:27 UTC (permalink / raw) To: Thorsten von Eicken; +Cc: Rainbows! list Thorsten von Eicken <tve-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> wrote: > Thanks for the 4.6.1 update. I pulled it a few weeks ago, but I am still > having problems with the rainbows restart and EM. I pretty consistently > get a segfault: > > /var/lib/gems/1.9.1/gems/eventmachine-1.0.3/lib/eventmachine.rb:187: > [BUG] Segmentation fault > ruby 1.9.3p0 (2011-10-30 revision 33570) [x86_64-linux] Can you poke the EM folks about this? However, keep in mind EM is basically abandoned at this point: https://groups.google.com/forum/#!topic/eventmachine/9g7oTzmYERo _______________________________________________ Rainbows! mailing list - rainbows-talk-GrnCvJ7WPxnNLxjTenLetw@public.gmane.org http://rubyforge.org/mailman/listinfo/rainbows-talk Do not quote signatures (like this one) or top post when replying ^ permalink raw reply [flat|nested] 10+ messages in thread
end of thread, other threads:[~2014-03-17 21:35 UTC | newest] Thread overview: 10+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2014-01-29 6:03 HUP restart is delayed by 2 minutes Thorsten von Eicken [not found] ` <52E89997.6020504-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> 2014-01-29 7:02 ` Eric Wong [not found] ` <20140129070259.GA5938-yBiyF41qdooeIZ0/mPfg9Q@public.gmane.org> 2014-01-29 7:26 ` Thorsten von Eicken [not found] ` <52E8AD1B.8090009-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> 2014-01-29 7:32 ` Eric Wong 2014-01-29 8:31 ` Eric Wong [not found] ` <20140129083147.GA26652-yBiyF41qdooeIZ0/mPfg9Q@public.gmane.org> 2014-01-29 20:11 ` Thorsten von Eicken [not found] ` <52E9607A.60107-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> 2014-01-29 22:03 ` Eric Wong [not found] ` <20140129220352.GA24393-yBiyF41qdooeIZ0/mPfg9Q@public.gmane.org> 2014-01-29 22:41 ` Thorsten von Eicken 2014-03-17 21:23 ` Thorsten von Eicken [not found] ` <532767E2.70509-nkzjiHSqi6rZJqsBc5GL+g@public.gmane.org> 2014-03-17 21:27 ` Eric Wong
Code repositories for project(s) associated with this public inbox https://yhbt.net/rainbows.git/ This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).