I'm running a django app with gunicorn on heroku. What does this error in my heroku log file mean?

Question

I am trying to use gunicorn with my django app on heroku. I followed the instructions here: http://devcenter.heroku.com/articles/django#using_a_different_wsgi_server. It appears that gunicorn is runing, because the logs indicate it. However, I don't like seeing error messages that I don't understand in my log files, and while reviewing the logs I saw the line that reads "Error R12 (Exit timeout) -> Process failed to exit within 10 seconds of SIGTERM" and then "stopping process with SIGKILL". My app appears to be running fine at the expected URL, so this is not an emergency, but I'm just curious as to what is going on. Thanks.

2012-01-10T20:56:36+00:00 heroku[web.1]: State changed from up to bouncing
2012-01-10T20:56:36+00:00 heroku[web.1]: State changed from bouncing to created
2012-01-10T20:56:36+00:00 heroku[web.1]: State changed from created to starting
2012-01-10T20:56:39+00:00 heroku[web.1]: Stopping process with SIGTERM
2012-01-10T20:56:39+00:00 heroku[web.1]: Starting process with command `python blossom/manage.py run_gunicorn -b "0.0.0.0:27470" -w 3`
2012-01-10T20:56:40+00:00 app[web.1]: Validating models...
2012-01-10T20:56:40+00:00 app[web.1]: Django version 1.3.1, using settings 'blossom.settings'
2012-01-10T20:56:40+00:00 app[web.1]: 
2012-01-10T20:56:40+00:00 app[web.1]: Server is running
2012-01-10T20:56:40+00:00 app[web.1]: 0 errors found
2012-01-10T20:56:40+00:00 app[web.1]: Quit the server with CONTROL-C.
2012-01-10T20:56:40+00:00 app[web.1]: 2012-01-10 15:56:40 [3] [INFO] Starting gunicorn 0.13.4
2012-01-10T20:56:40+00:00 app[web.1]: 2012-01-10 15:56:40 [3] [INFO] Listening at: http://0.0.0.0:27470 (3)
2012-01-10T20:56:40+00:00 app[web.1]: 2012-01-10 15:56:40 [3] [INFO] Using worker: sync
2012-01-10T20:56:40+00:00 app[web.1]: 2012-01-10 15:56:40 [6] [INFO] Booting worker with pid: 6
2012-01-10T20:56:40+00:00 app[web.1]: 2012-01-10 15:56:40 [7] [INFO] Booting worker with pid: 7
2012-01-10T20:56:40+00:00 app[web.1]: 2012-01-10 15:56:40 [8] [INFO] Booting worker with pid: 8  
2012-01-10T20:56:41+00:00 heroku[web.1]: State changed from starting to up
2012-01-10T20:56:48+00:00 heroku[web.1]: Error R12 (Exit timeout) -> Process failed to exit within 10 seconds of SIGTERM
2012-01-10T20:56:48+00:00 heroku[web.1]: Stopping process with SIGKILL
2012-01-10T20:56:50+00:00 heroku[web.1]: Process exited

Answer 1

Basically what it says on the tin. In the Heroku stack a process is always terminated with a SIGTERM, which tells the process to shut down gracefully, and gives it ten seconds to do so.

If this hasn't terminated within 10 seconds you then get a R12 error and a SIGKILL, which is essentially a kill.

Now, why this is happening here isn't completely clear as the logs don't go back far enough, but you can see the SIGTERM happening at 20:56:39

Answer 2

There isn't enough log to show your problem with certainty (Error R12 can mean a number of things). And for the record, I'm not running Gunicorn. That said, I had a similar problem to this.

Turns out that cedar-stack doesn't like you mentioning apps in the INSTALLED_APPS section of settings.py if there isn't a module for that app anywhere else in the project.

I usually code my app into INSTALLED_APPS before I even start to code it in views.py, and the local DJANGO server doesn't complain, so I got used to doing that. Unfortunately, it breaks that cedar-stack.

When I commented out the app that didn't have a module anywhere else in the project and pushed the new version up, it started working again straight away.