2

I'm trying to debug an issue with workers and I saw this message in my log file:

2013-07-14T21:59:07.024756+00:00 app[web.1]: E, [2013-07-14T14:59:07.024559 #2] ERROR -- : worker=1 PID:261 timeout (30s > 29s), killing
2013-07-14T21:59:07.067325+00:00 app[web.1]: E, [2013-07-14T14:59:07.066999 #2] ERROR -- : reaped #<Process::Status: pid 261 SIGKILL (signal 9)> worker=1
2013-07-14T21:59:07.070701+00:00 heroku[router]: at=error code=H13 desc="Connection closed without response" method=POST path=/photos/687 host=dev.tacktile.org fwd="199.83.223.92" dyno=web.1 connect=8ms service=29345ms status=503 bytes=0
2013-07-14T21:59:07.898048+00:00 app[web.1]: I, [2013-07-14T14:59:07.897739 #269]  INFO -- : worker=1 ready

If I'm reading this correctly, my worker was killed because it took longer than 30 seconds. I thought only web responses got killed if longer than 30 seconds. I'm putting this task into a delayed job and processing it with a worker because I know it's slow.

I hope I'm misunderstanding something.

2 Answers 2

4

Your log indicates dyno=web.1 - so it looks like the web dyno connection was terminated after 30 seconds, not a worker dyno like you indicate. Have you read the note attached to the definition of the h13 error that indicates:

One example where this might happen is when a Unicorn web server is configured with a timeout shorter than 30s and a request has not been processed by a worker before the timeout happens. In this case, Unicorn closes the connection before any data is written, resulting in an H13.

Perhaps that's related?

PS. Editing my answer I see by "worker" you mean "Unicorn worker" I guess? Looks like your unicorn worker died for some reason (which is perhaps why you got the H13). Heroku won't explicitly kill a sub-process like that AFAIK.

2
  • Thanks, this is helpful. I think you're right that it's the web dyno. I'm still unclear why it's referencing workers at all in this log entry but I'm moving on to deeper diagnosis of the issue I'm trying to resolve. Jul 16, 2013 at 4:23
  • Ah, I think you're right! I didn't realize unicorn used that same terminology. In my mind I always held workers and web process as completely unrelated. Thanks for the insight. Jul 17, 2013 at 4:47
1

I'm not a Ruby on Rails expert, but it seems like what you call "worker" is actually a web process (as evident by the dyno name, web.1). I am guessing you use Unicorn, which spawns several processes, each dealing with a single web request at a time. Each such process is termed a "worker", I guess, so it's really a matter of terminology.

As to why it happens: could it be that your web path actually waits for your real worker to complete the request, and thus it too is taking >30sec?

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.