mongrel unicorn - Jan 2013 - SIGSEGV at shutdown (was: Re: your mail)

On Mon, Jan 21, 2013 at 11:28 AM, Eric Wong <normalperson at yhbt.net>
wrote:
> Charles Hornberger <charles.hornberger at gmail.com> wrote:
>> Hi!
>>
>> I recently noticed this error message when restarting unicorn after a
>> code deployment (and I don''t think I recall having seen it
before):
>>
>> I, [2013-01-18T17:54:21.502554 #59285]  INFO -- : reaped
>> #<Process::Status: pid 59293 exit 0> worker=6
>> I, [2013-01-18T17:54:21.502692 #59285]  INFO -- : reaped
>> #<Process::Status: pid 59294 exit 0> worker=7
>> I, [2013-01-18T17:54:21.502754 #59285]  INFO -- : reaped
>> #<Process::Status: pid 59292 exit 0> worker=5
>> I, [2013-01-18T17:54:21.502819 #59285]  INFO -- : reaped
>> #<Process::Status: pid 59291 exit 0> worker=4
>> E, [2013-01-18T17:54:21.502915 #59285] ERROR -- : reaped
>> #<Process::Status: pid 59288 SIGSEGV (signal 11)> worker=1
>> I, [2013-01-18T17:54:21.502967 #59285]  INFO -- : reaped
>> #<Process::Status: pid 59287 exit 0> worker=0
>> I, [2013-01-18T17:54:21.604829 #59285]  INFO -- : reaped
>> #<Process::Status: pid 59290 exit 0> worker=3
>> I, [2013-01-18T17:54:21.604935 #59285]  INFO -- : reaped
>> #<Process::Status: pid 59289 exit 0> worker=2
>> I, [2013-01-18T17:54:21.605077 #59285]  INFO -- : master complete
>>
>> Just wondering if it''s something I should be concerned about?
I saw no
>> obvious symptoms of problems before or after?
>>
>> We currently restart unicorn (which is on a freebsd jail) like so:
>
> A SEGV at shutdown is likely an ordering problem at VM shutdown
> (probably GC/finalization handling).  It could be specific to the
> malloc/pthread implementation on FreeBSD, even.
>
> Which version of Ruby are you using?
1.9.3p-125
> Which C extensions do you have loaded?
There''s probably a better way to answer this question, but ...

% find vendor/bundle/ruby/1.9.1/gems -name ''*.so''
vendor/bundle/ruby/1.9.1/gems/clogger-1.1.0/ext/clogger_ext/clogger_ext.so
vendor/bundle/ruby/1.9.1/gems/clogger-1.1.0/lib/clogger_ext.so
vendor/bundle/ruby/1.9.1/gems/eventmachine-1.0.0.rc.4/ext/fastfilereader/fastfilereaderext.so
vendor/bundle/ruby/1.9.1/gems/eventmachine-1.0.0.rc.4/ext/rubyeventmachine.so
vendor/bundle/ruby/1.9.1/gems/eventmachine-1.0.0.rc.4/lib/rubyeventmachine.so
vendor/bundle/ruby/1.9.1/gems/eventmachine-1.0.0.rc.4/lib/fastfilereaderext.so
vendor/bundle/ruby/1.9.1/gems/escape_utils-0.2.4/ext/escape_utils/escape_utils.so
vendor/bundle/ruby/1.9.1/gems/escape_utils-0.2.4/lib/escape_utils.so
vendor/bundle/ruby/1.9.1/gems/http_parser.rb-0.5.3/ext/ruby_http_parser/ruby_http_parser.so
vendor/bundle/ruby/1.9.1/gems/http_parser.rb-0.5.3/lib/ruby_http_parser.so
vendor/bundle/ruby/1.9.1/gems/json-1.7.4/ext/json/ext/generator/generator.so
vendor/bundle/ruby/1.9.1/gems/json-1.7.4/ext/json/ext/parser/parser.so
vendor/bundle/ruby/1.9.1/gems/json-1.7.4/lib/json/ext/generator.so
vendor/bundle/ruby/1.9.1/gems/json-1.7.4/lib/json/ext/parser.so
vendor/bundle/ruby/1.9.1/gems/kgio-2.7.4/ext/kgio/kgio_ext.so
vendor/bundle/ruby/1.9.1/gems/kgio-2.7.4/lib/kgio_ext.so
vendor/bundle/ruby/1.9.1/gems/raindrops-0.10.0/ext/raindrops/raindrops_ext.so
vendor/bundle/ruby/1.9.1/gems/raindrops-0.10.0/lib/raindrops_ext.so
vendor/bundle/ruby/1.9.1/gems/unicorn-4.3.1/ext/unicorn_http/unicorn_http.so
vendor/bundle/ruby/1.9.1/gems/unicorn-4.3.1/lib/unicorn_http.so
vendor/bundle/ruby/1.9.1/gems/json-1.7.3/ext/json/ext/generator/generator.so
vendor/bundle/ruby/1.9.1/gems/json-1.7.3/ext/json/ext/parser/parser.so
vendor/bundle/ruby/1.9.1/gems/json-1.7.3/lib/json/ext/parser.so
vendor/bundle/ruby/1.9.1/gems/json-1.7.3/lib/json/ext/generator.so
vendor/bundle/ruby/1.9.1/gems/therubyracer-freebsd-0.10.1/ext/v8/v8.so
vendor/bundle/ruby/1.9.1/gems/therubyracer-freebsd-0.10.1/lib/v8.so
vendor/bundle/ruby/1.9.1/gems/lwes-0.8.3/ext/lwes_ext/lwes_ext.so
vendor/bundle/ruby/1.9.1/gems/lwes-0.8.3/lib/lwes_ext.so
vendor/bundle/ruby/1.9.1/gems/clogger-1.2.0/ext/clogger_ext/clogger_ext.so
vendor/bundle/ruby/1.9.1/gems/clogger-1.2.0/lib/clogger_ext.so
vendor/bundle/ruby/1.9.1/gems/eventmachine-1.0.0/ext/fastfilereader/fastfilereaderext.so
vendor/bundle/ruby/1.9.1/gems/eventmachine-1.0.0/ext/rubyeventmachine.so
vendor/bundle/ruby/1.9.1/gems/eventmachine-1.0.0/lib/rubyeventmachine.so
vendor/bundle/ruby/1.9.1/gems/eventmachine-1.0.0/lib/fastfilereaderext.so
vendor/bundle/ruby/1.9.1/gems/json-1.7.5/ext/json/ext/generator/generator.so
vendor/bundle/ruby/1.9.1/gems/json-1.7.5/ext/json/ext/parser/parser.so
vendor/bundle/ruby/1.9.1/gems/json-1.7.5/lib/json/ext/generator.so
vendor/bundle/ruby/1.9.1/gems/json-1.7.5/lib/json/ext/parser.so
vendor/bundle/ruby/1.9.1/gems/psych-1.3.4/ext/psych/psych.so
vendor/bundle/ruby/1.9.1/gems/psych-1.3.4/lib/psych.so
vendor/bundle/ruby/1.9.1/gems/unicorn-4.5.0/ext/unicorn_http/unicorn_http.so
vendor/bundle/ruby/1.9.1/gems/unicorn-4.5.0/lib/unicorn_http.so

We use rvm, and afaik Ruby is installed w/ the "usual" rvm packages
(readline, iconv, openssl, zlib, autoconf).
> What at_exit/END handlers does your app have?
None
> What finalizers does your have?
None.

Thanks,
-c

Charles Hornberger <charles.hornberger at gmail.com>
wrote:
> On Mon, Jan 21, 2013 at 11:28 AM, Eric Wong <normalperson at
yhbt.net> wrote:
> > Charles Hornberger <charles.hornberger at gmail.com> wrote:
> >> E, [2013-01-18T17:54:21.502915 #59285] ERROR -- : reaped
> >> #<Process::Status: pid 59288 SIGSEGV (signal 11)> worker=1
<snip>
> >> I, [2013-01-18T17:54:21.605077 #59285]  INFO -- : master complete
> >>
> >> Just wondering if it''s something I should be concerned
about? I saw no
> >> obvious symptoms of problems before or after?
> >>
> >> We currently restart unicorn (which is on a freebsd jail) like so:
> >
> > A SEGV at shutdown is likely an ordering problem at VM shutdown
> > (probably GC/finalization handling).  It could be specific to the
> > malloc/pthread implementation on FreeBSD, even.
> >
> > Which version of Ruby are you using?
> 
> 1.9.3p-125
Can you give 1.9.3-p374 a try?  There were several GC-related segfault
fixes along the way (fairly large and drastic changes, even).

<snip>

Nothing else jumps out at me (I remember nokogiri having a problem
which led to at least one GC bugfix shortly after p125).


Also, did you manage to get any backtrace from Ruby at all?  The Ruby VM
should show a partial stack trace on SEGV (or at least attempt to, but
it may not during shutdown).  Otherwise, you''d have to get gdb-able
core
dumps the old-fashioned way (ulimit -c unlimited) and show us (or
ruby-core) the backtrace.

On Thu, Jan 24, 2013 at 10:52 AM, Eric Wong <normalperson at yhbt.net>
wrote:
> Charles Hornberger <charles.hornberger at gmail.com> wrote:
>> On Mon, Jan 21, 2013 at 11:28 AM, Eric Wong <normalperson at
yhbt.net> wrote:
>> > Charles Hornberger <charles.hornberger at gmail.com> wrote:
>> >> E, [2013-01-18T17:54:21.502915 #59285] ERROR -- : reaped
>> >> #<Process::Status: pid 59288 SIGSEGV (signal 11)>
worker=1
>
> <snip>
>
>> >> I, [2013-01-18T17:54:21.605077 #59285]  INFO -- : master
complete
>> >>
>> >> Just wondering if it''s something I should be
concerned about? I saw no
>> >> obvious symptoms of problems before or after?
>> >>
>> >> We currently restart unicorn (which is on a freebsd jail) like
so:
>> >
>> > A SEGV at shutdown is likely an ordering problem at VM shutdown
>> > (probably GC/finalization handling).  It could be specific to the
>> > malloc/pthread implementation on FreeBSD, even.
>> >
>> > Which version of Ruby are you using?
>>
>> 1.9.3p-125
>
> Can you give 1.9.3-p374 a try?  There were several GC-related segfault
> fixes along the way (fairly large and drastic changes, even).
We''ll be moving to that soon. Since the problem has only occurred
*once* afaik, and there was nothing special that I can think of to do
to reproduce it, we may never know if the change fixed anything. :)
But if I happen to see it again, I will attempt to provide more info.
>
> <snip>
>
> Also, did you manage to get any backtrace from Ruby at all?  The Ruby VM
> should show a partial stack trace on SEGV (or at least attempt to, but
> it may not during shutdown).  Otherwise, you''d have to get
gdb-able core
> dumps the old-fashioned way (ulimit -c unlimited) and show us (or
> ruby-core) the backtrace.
Nothing was emitted at the time -- what I sent before was all that
appeared in stderr.log.