Reaping process with unknown worker

Reaping process with unknown worker

[Alberto De Gaspari]

Hello everyone, maybe this is a noob question, but it seems strange from
my point of view, so here i am:

I have 2 master processes running on the same server, pointing to the
same rails application dir.
I need 2 of them because i need some workers to be dedicated responding
to requests coming from a specific socket(and i'm not sure this is the
right way to do this)

Both the standard_error_logs are full of messages like the following:

INFO -- : reaped #<Process::Status: pid 23835 exit 0> worker=unknown

is this a misconfiguration or something similar?
Thank you in advance!
alberto

Re: Reaping process with unknown worker

[Eric Wong]

Alberto De Gaspari <a.degaspari@18months.it> wrote:
> Hello everyone, maybe this is a noob question, but it seems strange from
> my point of view, so here i am:
> 
> I have 2 master processes running on the same server, pointing to the
> same rails application dir.
> I need 2 of them because i need some workers to be dedicated responding
> to requests coming from a specific socket(and i'm not sure this is the
> right way to do this)

That's fine.

> Both the standard_error_logs are full of messages like the following:
> 
> INFO -- : reaped #<Process::Status: pid 23835 exit 0> worker=unknown
> 
> is this a misconfiguration or something similar?

Does your application fork processes?  It may not be reaping
them.   Are your normal unicorn workers dying, too?

You can check the process tree or periodically run "ps" to see
what was running as the reaped pid before it died.

I use "ps axf" from the "procps" package on some Linux sytems;
or "pstree" if installed to see the process tree.

Re: Reaping process with unknown worker

[Alberto De Gaspari]

>> Both the standard_error_logs are full of messages like the following:
>>
>> INFO -- : reaped #<Process::Status: pid 23835 exit 0> worker=unknown
>>
>> is this a misconfiguration or something similar?
> 
> Does your application fork processes?  It may not be reaping
> them.   Are your normal unicorn workers dying, too?
no, workers never dies
> 
> You can check the process tree or periodically run "ps" to see
> what was running as the reaped pid before it died.
> 
> I use "ps axf" from the "procps" package on some Linux sytems;
> or "pstree" if installed to see the process tree.
> 
i'm sorry but i don't get it.
with a line like this in the log:
INFO -- : reaped #<Process::Status: pid 16101 exit 0> worker=unknown
if i run
# ps axf |grep 16101
i only get the ps line:
10277 pts/4    S+     0:00          \_ grep 16101

consider that i have loads of this line in the log, like at least 1
every minute.

what could cause those reaps?

Re: Reaping process with unknown worker

[Eric Wong]

Alberto De Gaspari <a.degaspari@18months.it> wrote:
> >> Both the standard_error_logs are full of messages like the following:
> >>
> >> INFO -- : reaped #<Process::Status: pid 23835 exit 0> worker=unknown
> >>
> >> is this a misconfiguration or something similar?
> > 
> > Does your application fork processes?  It may not be reaping
> > them.   Are your normal unicorn workers dying, too?
> no, workers never dies
> > 
> > You can check the process tree or periodically run "ps" to see
> > what was running as the reaped pid before it died.
> > 
> > I use "ps axf" from the "procps" package on some Linux sytems;
> > or "pstree" if installed to see the process tree.
> > 
> i'm sorry but i don't get it.

I mean, run "ps axf" to get a list of all processes before they exit,
then check the output against the pid shown in the log when the
log entry eventually shows up.

> with a line like this in the log:
> INFO -- : reaped #<Process::Status: pid 16101 exit 0> worker=unknown
> if i run
> # ps axf |grep 16101
> i only get the ps line:
> 10277 pts/4    S+     0:00          \_ grep 16101
> 
> consider that i have loads of this line in the log, like at least 1
> every minute.
> 
> what could cause those reaps?

Reaping happens after a process exits, so it won't show up
in "ps" once it's reaped.

Re: Reaping process with unknown worker

[Alberto De Gaspari]

>> with a line like this in the log:
>> INFO -- : reaped #<Process::Status: pid 16101 exit 0> worker=unknown
>> if i run
>> # ps axf |grep 16101
>> i only get the ps line:
>> 10277 pts/4    S+     0:00          \_ grep 16101
>>
>> consider that i have loads of this line in the log, like at least 1
>> every minute.
>>
>> what could cause those reaps?
> 
> Reaping happens after a process exits, so it won't show up
> in "ps" once it's reaped.
> 
ok, got it:
but if at t0 i run ps axf and save the result, when at t1 i find one of
the lines in the stderr_log and try to grep the stated pid in the saved
result of t0 i don't find anything.
how can i detect what it's reaping? do you consider this a normal
behavior for a rails app which actually only receives simple get
requests and save the result in a pg db?(that's what the small instance
of unicorn does, the other is more complex, but shows the same amount
and type of info messages in errors)

-- 
Cordiali saluti
Alberto De Gaspari
CTO & Software Engineer

18Months S.r.l
Via Copernico 38, Milano 20125, Italia
Tel:    +39 02.92852164
Fax:    +39 02.45075016
Mob:    +39 349.1624385
MeetMe: doodle.com/albertodega
Email:  a.degaspari@18months.it
web:    www.18months.it

Re: Reaping process with unknown worker

[Eric Wong]

Alberto De Gaspari <a.degaspari@18months.it> wrote:
> >> with a line like this in the log:
> >> INFO -- : reaped #<Process::Status: pid 16101 exit 0> worker=unknown
> >> if i run
> >> # ps axf |grep 16101
> >> i only get the ps line:
> >> 10277 pts/4    S+     0:00          \_ grep 16101
> >>
> >> consider that i have loads of this line in the log, like at least 1
> >> every minute.
> >>
> >> what could cause those reaps?
> > 
> > Reaping happens after a process exits, so it won't show up
> > in "ps" once it's reaped.
> > 
> ok, got it:
> but if at t0 i run ps axf and save the result, when at t1 i find one of
> the lines in the stderr_log and try to grep the stated pid in the saved
> result of t0 i don't find anything.

I guess this is because the process is too short-lived.  Can you
audit your code for when you spawn applications and check that?

Actually, what is curious is your master process is reaping
these processes (not workers reaping); yet your workers are not
dying and getting reaped.

Are you using preload_app?

If so, do you spawn any background processes at load time?
Or are there any background threads in the master process?

Does the problem go away if you disable preload_app?

Because, in normal applications, workers may spawn background
processes but its rare for the master to spawn anything but
workers themselves.

> how can i detect what it's reaping? do you consider this a normal
> behavior for a rails app which actually only receives simple get
> requests and save the result in a pg db?(that's what the small instance
> of unicorn does, the other is more complex, but shows the same amount
> and type of info messages in errors)

AFAIK, you cannot detect what it's reaping portably...

You can try the following hack to look for defunct (zombie)
processes before unicorn calls waitpid2.  However, keep in mind
it is subject to race conditions so not 100% reliable:

diff --git a/lib/unicorn/http_server.rb b/lib/unicorn/http_server.rb
index f33aa25..f57271e 100644
--- a/lib/unicorn/http_server.rb
+++ b/lib/unicorn/http_server.rb
@@ -396,6 +396,7 @@ def awaken_master
   # reaps all unreaped workers
   def reap_all_workers
     begin
+      system('ps | grep defunct')
       wpid, status = Process.waitpid2(-1, Process::WNOHANG)
       wpid or return
       if @reexec_pid == wpid



One other thing you try do (on Linux) is strace the master:

	strace -p $PID_OF_MASTER -f -e execve,clone

And see what the master is spawning.  I suppose other OS has
similar functions (truss/ktruss/...)