Foreman doesn't shut down gunicorn

[flashingpumpkin]

Procfile:

web: python project/manage.py run_gunicorn 127.0.0.1:$PORT

uname -a

Linux lucid32 2.6.32-33-generic #70-Ubuntu SMP Thu Jul 7 21:09:46 UTC 2011 i686 GNU/Linux

ruby --version

ruby 1.8.7 (2010-01-10 patchlevel 249) [i486-linux]

Example session:

(application)application@lucid32:[project ~master *]$ ps aux | grep python
1001       820  0.0  0.1   2140   740 pts/1    S+   07:16   0:00 grep --color=auto python

(application)application@lucid32:[project ~master *]$ foreman start
07:16:07 web.1     | started with pid 835
07:16:07 web.1     | Validating models...
07:16:07 web.1     | 0 errors found
07:16:07 web.1     | 
07:16:07 web.1     | Django version 1.3.1, using settings 'project.settings'
07:16:07 web.1     | Server is running
07:16:07 web.1     | Quit the server with CONTROL-C.
07:16:07 web.1     | 2011-09-14 09:16:07 [837] [INFO] Starting gunicorn 0.13.1
07:16:07 web.1     | 2011-09-14 09:16:07 [837] [INFO] Listening at: http://127.0.0.1:5000 (837)
07:16:07 web.1     | 2011-09-14 09:16:07 [837] [INFO] Using worker: sync
07:16:07 web.1     | 2011-09-14 09:16:07 [840] [INFO] Booting worker with pid: 840
^CSIGINT received
07:16:11 system    | sending SIGTERM to all processes
07:16:11 web.1     | process exiting

(application)application@lucid32:[project ~master *]$ ps aux | grep python
1001       837  2.2  3.1  15548 11804 ?        S    07:16   0:00 python project/manage.py run_gunicorn 127.0.0.1:5000
1001       840  0.1  2.9  16432 11276 ?        S    07:16   0:00 python project/manage.py run_gunicorn 127.0.0.1:5000
1001       855  0.0  0.1   2140   736 pts/1    S+   07:16   0:00 grep --color=auto python

(application)application@lucid32:[project ~master *]$ 

[svdgraaf]

Any idea how to fix this? I'm having the same issue...

[flashingpumpkin]

Not quite sure. Here's another session without using foreman:

(vagrant)vagrant@lucid32:[~]$ python manage.py run_gunicorn &
[1] 1992

(vagrant)vagrant@lucid32:[~]$ Validating models...
[...]
2011-10-21 13:41:38 [1992] [INFO] Starting gunicorn 0.13.1
2011-10-21 13:41:38 [1992] [INFO] Listening at: http://127.0.0.1:8000 (1992)
2011-10-21 13:41:38 [1992] [INFO] Using worker: sync
2011-10-21 13:41:38 [2046] [INFO] Booting worker with pid: 2046

(vagrant)vagrant@lucid32:[~]$ ps aux | grep python
vagrant   1992  5.5  4.7  25596 18052 pts/1    S    05:41   0:00 python manage.py run_gunicorn
vagrant   2046  0.0  3.8  25596 14700 pts/1    S    05:41   0:00 python manage.py run_gunicorn
vagrant   2056  0.0  0.1   2140   744 pts/1    S+   05:41   0:00 grep --color=auto python

(vagrant)vagrant@lucid32:[~]$ kill -TERM 1992
2011-10-21 13:41:53 [1992] [INFO] Handling signal: term
2011-10-21 13:41:53 [2046] [INFO] Worker exiting (pid: 2046)
2011-10-21 13:41:53 [1992] [INFO] Shutting down: Master
[1]+  Done                    python manage.py run_gunicorn

(vagrant)vagrant@lucid32:[~]$ ps aux | grep python
vagrant   2082  0.0  0.1   2140   740 pts/1    S+   05:41   0:00 grep --color=auto python

gunicorn does handle the signal properly.

[flashingpumpkin]

Thought it might have to do with subprocessing, I did essentially the same foreman does but in python:

(vagrant)vagrant@lucid32:[~]$ ps aux | grep python
vagrant   2406  0.0  0.1   2140   740 pts/0    S+   05:54   0:00 grep --color=auto python

(vagrant)vagrant@lucid32:[~]$ python
[...]

>>> import subprocess, signal
>>> gu = subprocess.Popen(['python', 'manage.py', 'run_gunicorn'])
[...]
2011-10-21 13:55:32 [2416] [INFO] Starting gunicorn 0.13.1
2011-10-21 13:55:32 [2416] [INFO] Listening at: http://127.0.0.1:8000 (2416)
2011-10-21 13:55:32 [2416] [INFO] Using worker: sync
2011-10-21 13:55:32 [2462] [INFO] Booting worker with pid: 2462

>>> 
[1]+  Stopped                 python

(vagrant)vagrant@lucid32:[~]$ ps aux | grep python
vagrant   2415  0.0  1.1   8472  4496 pts/0    T    05:55   0:00 python
vagrant   2416  4.8  4.7  25616 18052 pts/0    S    05:55   0:00 python manage.py run_gunicorn
vagrant   2462  0.0  3.8  25616 14700 pts/0    S    05:55   0:00 python manage.py run_gunicorn
vagrant   2472  0.0  0.1   2140   744 pts/0    S+   05:55   0:00 grep --color=auto python

(vagrant)vagrant@lucid32:[~]$ curl -I localhost:8000
HTTP/1.1 302 FOUND
Server: gunicorn/0.13.1
Date: Fri, 21 Oct 2011 12:55:46 GMT
Connection: close
Transfer-Encoding: chunked
Vary: Cookie
Content-Type: text/html; charset=utf-8
Location: http://localhost:8000/login/?next=/

(vagrant)vagrant@lucid32:[~]$ %1

>>> gu.send_signal(signal.SIGTERM)
2011-10-21 13:56:04 [2416] [INFO] Handling signal: term
2011-10-21 13:56:04 [2462] [INFO] Worker exiting (pid: 2462)
2011-10-21 13:56:04 [2416] [INFO] Shutting down: Master

>>> quit()

(vagrant)vagrant@lucid32:[~]$ ps aux | grep python
vagrant   2499  0.0  0.1   2140   740 pts/0    S+   05:56   0:00 grep --color=auto python

[flashingpumpkin]

It seems that when not using python manage.py run_gunicorn but gunicorn_django instead it behaves correctly.

Procfile:

web: gunicorn_django path/to/settings.py 

Update

It seems that foreman shuts down all the processes correctly when not binding to a specific address/port with -b 0.0.0.0:$PORT. As soon as you're using -b it won't shut down child processes anymore.

Further update

Binding not with $PORT but a hardcoded port shuts gunicorn down correctly too:

web: gunicorn_django path/to/settings.py -b 0.0.0.0:12345

[svdgraaf]

ok, great! I already figured it had to do something with the subprocesses, thanks for the help! The workaround works like a charm :)

[ddollar]

Rolling into #94

[kevinburke]

I'm still getting issue with subprocesses not being shut down on my Clojure app with a Ctrl+C sent to the Foreman process.

Here's the contents of my Procfile:

web: lein run -m com.twilio.smsauth.core

Running with foreman start, and then Ctrl+C:

18> foreman start
Invalid gemspec in [/Library/Ruby/Gems/1.8/specifications/heroku-2.13.0.gemspec]: invalid date format in specification: "2011-11-10 00:00:00.000000000Z"
15:50:46 web.1     | started with pid 24972
15:50:55 web.1     | 2011-11-18 15:50:55.977:INFO::Logging to STDERR via org.mortbay.log.StdErrLog
15:50:56 web.1     | #<Server Server@7213f866>
15:50:56 web.1     | 2011-11-18 15:50:55.979:INFO::jetty-6.1.25
15:50:56 web.1     | 2011-11-18 15:50:56.004:INFO::Started SocketConnector@0.0.0.0:5000
^CSIGINT received
15:50:59 system    | sending SIGTERM to all processes

There's still a Java process running:

19> ps aux | grep java
kevin    25012   0.0  0.0  2435120    532 s007  R+    3:51PM   0:00.00 grep -i --color=auto java
kevin    24996   0.0  3.1  2889504 128604   ??  S     3:50PM   0:16.92 /usr/bin/java -cp /Users/kevin/code/smsauth/test:/Users/kevin/code/smsauth/test-resources:/Users/kevin/code/smsauth/src:/Users/kevin/code/smsauth/classes:/Users/kevin/code/smsauth/resources:/Users/kevin/code/smsauth/lib/clj-base64-0.0.0-20100308.145053-2.jar:/Users/kevin/code/smsauth/lib/clj-http-0.2.1.jar:/Users/kevin/code/smsauth/lib/clojure-1.2.1.jar:/Users/kevin/code/smsauth/lib/clojure-contrib-1.2.0.jar:/Users/kevin/code/smsauth/lib/clout-0.4.1.jar:/Users/kevin/code/smsauth/lib/commons-codec-1.5.jar:/Users/kevin/code/smsauth/lib/commons-fileupload-1.2.1.jar:/Users/kevin/code/smsauth/lib/commons-io-1.4.jar:/Users/kevin/code/smsauth/lib/commons-logging-1.1.1.jar:/Users/kevin/code/smsauth/lib/compojure-0.6.5.jar:/Users/kevin/code/smsauth/lib/core.incubator-0.1.0.jar:/Users/kevin/code/smsauth/lib/hiccup-0.3.6.jar:/Users/kevin/code/smsauth/lib/httpclient-4.1.2.jar:/Users/kevin/code/smsauth/lib/httpcore-4.1.2.jar:/Users/kevin/code/smsauth/lib/inflections-0.4.2-20110104.084027-3.jar:/Users/kevin/code/smsauth/lib/java.jdbc-0.1.1.jar:/Users/kevin/code/smsauth/lib/jbcrypt-0.3m.jar:/Users/kevin/code/smsauth/lib/jetty-6.1.25.jar:/Users/kevin/code/smsauth/lib/jetty-util-6.1.25.jar:/Users/kevin/code/smsauth/lib/libphonenumber-3.9.jar:/Users/kevin/code/smsauth/lib/postgresql-9.1-901.jdbc4.jar:/Users/kevin/code/smsauth/lib/ring-basic-authentication-0.0.1.jar:/Users/kevin/code/smsauth/lib/ring-core-0.3.11.jar:/Users/kevin/code/smsauth/lib/ring-jetty-adapter-1.0.0-RC1.jar:/Users/kevin/code/smsauth/lib/ring-servlet-1.0.0-RC1.jar:/Users/kevin/code/smsauth/lib/sandbar-0.4.0-20110601.165758-5.jar:/Users/kevin/code/smsauth/lib/servlet-api-2.5-20081211.jar:/Users/kevin/code/smsauth/lib/servlet-api-2.5.jar:/Users/kevin/code/smsauth/lib/tools.macro-0.1.0.jar -Dclojure.compile.path=/Users/kevin/code/smsauth/classes -Dsmsauth.version=0.1 -Dclojure.debug=false clojure.main -e (do (try (clojure.core/require (quote com.twilio.smsauth.core)) (catch java.io.FileNotFoundException ___3908__auto__)) nil (do (clojure.core/ns leiningen.util.injected) (defn- compose-hooks [f1 f2] (fn [& args] (apply f2 f1 args))) (defn- join-hooks [original hooks] (reduce compose-hooks original hooks)) (defn- run-hooks [hook original args] (apply (join-hooks original (clojure.core/deref hook)) args)) (defn- prepare-for-hooks [v] (when-not (:robert.hooke/hook (meta (clojure.core/deref v))) (let [hook (atom ())] (alter-var-root v (fn [original] (with-meta (fn [& args] (run-hooks hook original args)) (assoc (meta original) :robert.hooke/hook hook :robert.hooke/original original))))))) (defn- add-unless-present [coll f] (if-not (some #{f} coll) (conj coll f) coll)) (defn add-hook "Add a hook function f to target-var. Hook functions are passed the\n  target function and all their arguments and must apply the target to\n  the args if they wish to continue execution." [target-var f] (prepare-for-hooks target-var) (swap! (:robert.hooke/hook (meta (clojure.core/deref target-var))) add-unless-present f)) (clojure.core/ns user)) (set! *warn-on-reflection* nil) (try (clojure.core/let [v__3906__auto__ (clojure.core/resolve (quote com.twilio.smsauth.core/-main))] (if (clojure.core/ifn? v__3906__auto__) (v__3906__auto__) (clojure.lang.Reflector/invokeStaticMethod "com.twilio.smsauth.core" "main" (clojure.core/into-array [(clojure.core/into-array java.lang.String (quote nil))])))) (finally (clojure.core/when (clojure.core/and false (clojure.core/not= "1.5" (java.lang.System/getProperty "java.specification.version")) true) (clojure.core/shutdown-agents)))))

I tried setting a $PORT in my env, or just letting Foreman choose one, and either one seems to reproduce the error.

I am running 0.26.1. I'm on a Mac, running Snow Leopard. Please let me know what I can do to solve this.

20> gem search foreman
*** LOCAL GEMS ***
foreman (0.26.1)