Gunicorn --reload option reloads indefinitely #1129

Closed
lyschoening opened this Issue Oct 16, 2015 · 16 comments

Projects

None yet

5 participants

@lyschoening

Running any application, such as the following application (from gunicorn.org) with the --reload option and then making a trivial change leads to a never-ending reload cycle on my system.

def app(environ, start_response):
      data = "Hello, World!\n"
      start_response("200 OK", [
          ("Content-Type", "text/plain"),
          ("Content-Length", str(len(data)))
      ])
      return iter([data])
$ gunicorn --version
gunicorn (version 19.3.0)
$ python --version
Python 3.4.3
$ gunicorn --reload app:app -b localhost:8000
[2015-10-16 13:01:58 +0200] [42184] [INFO] Starting gunicorn 19.3.0
[2015-10-16 13:01:58 +0200] [42184] [INFO] Listening at: http://127.0.0.1:8000 (42184)
[2015-10-16 13:01:58 +0200] [42184] [INFO] Using worker: sync
[2015-10-16 13:01:58 +0200] [42187] [INFO] Booting worker with pid: 42187
[2015-10-16 13:02:05 +0200] [42187] [INFO] Worker reloading: /Users/lyschoening/app.py modified
[2015-10-16 13:02:06 +0200] [42187] [INFO] Worker reloading: /Users/lyschoening/app.py modified
[2015-10-16 13:02:07 +0200] [42187] [INFO] Worker reloading: /Users/lyschoening/app.py modified
[2015-10-16 13:02:08 +0200] [42187] [INFO] Worker reloading: /Users/lyschoening/app.py modified
[2015-10-16 13:02:09 +0200] [42187] [INFO] Worker reloading: /Users/lyschoening/app.py modified
[2015-10-16 13:02:10 +0200] [42187] [INFO] Worker reloading: /Users/lyschoening/app.py modified
[2015-10-16 13:02:11 +0200] [42187] [INFO] Worker reloading: /Users/lyschoening/app.py modified
[2015-10-16 13:02:12 +0200] [42187] [INFO] Worker reloading: /Users/lyschoening/app.py modified
[2015-10-16 13:02:13 +0200] [42187] [INFO] Worker reloading: /Users/lyschoening/app.py modified
^C[2015-10-16 13:02:13 +0200] [42184] [INFO] Handling signal: int
[2015-10-16 13:02:13 +0200] [42187] [INFO] Worker exiting (pid: 42187)
[2015-10-16 13:02:13 +0200] [42184] [INFO] Shutting down: Master

Please let me know what other debug information I can provide.

@wong2
Contributor
wong2 commented Oct 19, 2015

what's your os ?

@tilgovi
Collaborator
tilgovi commented Oct 19, 2015

The reloader should probably sleep, if it doesn't already, to make sure the FS settles?

@lyschoening

I have found out that this happens only when the command is run through the built-in terminal in the PyCharm IDE, so I will assume it is an issue with the IDE.

@lucasvo
lucasvo commented May 11, 2016

@lyschoening Did you ever find out what it is about pycharm's editor that breaks the reload behavior? I've ran into the same issue. (Interestingly enough flask's built in web server doesn't have the same issue).

@benoitc
Owner
benoitc commented May 11, 2016

@lucasvo can you eventually provides a trace in debug mode? would help to see if anything can be reproduced

@lucasvo
lucasvo commented May 11, 2016

@benoitc Yes, of course. Do you just want me to turn the log level up all the way or do you want me to do some sort of traceback inside of the reloader code?

@benoitc
Owner
benoitc commented May 11, 2016

@lucasvo in theory having using the debug level should be enough but the more you can is welcome :)

@lucasvo
lucasvo commented May 11, 2016

Here's the debug output. I'm afraid it's probably not much more helpful than the above output from @lyschoening. But I'd be happy to provide any extra details if you have something specific you want to test.

/Users/lucasvo/.envs/project/bin/python2.7 manage.py gunicorn
[2016-05-11 13:45:07 -0300] [27224] [DEBUG] Current configuration:
  proxy_protocol: False
  worker_connections: 1000
  statsd_host: None
  max_requests_jitter: 0
  post_fork: <function post_fork at 0x1053c7230>
  pythonpath: None
  enable_stdio_inheritance: False
  worker_class: gevent
  ssl_version: 3
  suppress_ragged_eofs: True
  syslog: False
  syslog_facility: user
  when_ready: <function when_ready at 0x1053bced8>
  pre_fork: <function pre_fork at 0x1053c70c8>
  cert_reqs: 0
  preload_app: False
  keepalive: 2
  accesslog: -
  group: 20
  graceful_timeout: 30
  do_handshake_on_connect: False
  spew: False
  workers: 2
  proc_name: None
  sendfile: None
  pidfile: None
  umask: 0
  on_reload: <function on_reload at 0x1053bcd70>
  pre_exec: <function pre_exec at 0x1053c77d0>
  worker_tmp_dir: None
  post_worker_init: <function post_worker_init at 0x1053c7398>
  limit_request_fields: 100
  on_exit: <function on_exit at 0x1053c7e60>
  config: config/gunicorn/local.py
  secure_scheme_headers: {'X-FORWARDED-PROTOCOL': 'ssl', 'X-FORWARDED-PROTO': 'https', 'X-FORWARDED-SSL': 'on'}
  proxy_allow_ips: ['127.0.0.1']
  pre_request: <function pre_request at 0x1053c7938>
  post_request: <function post_request at 0x1053c7a28>
  user: 501
  forwarded_allow_ips: ['127.0.0.1']
  worker_int: <function worker_int at 0x1053c7500>
  threads: 1
  max_requests: 1000
  limit_request_line: 4094
  access_log_format: %(h)s %(l)s %(u)s %(t)s "%(r)s" %(s)s %(b)s "%(f)s" "%(a)s"
  certfile: config/localhost/selfsigned.crt
  worker_exit: <function worker_exit at 0x1053c7b90>
  chdir: /Users/lucasvo/Code/foobar/project
  paste: None
  default_proc_name: project.gunicorn:app
  errorlog: -
  loglevel: DEBUG
  logconfig: None
  syslog_addr: unix:///var/run/syslog
  syslog_prefix: None
  daemon: False
  ciphers: TLSv1
  on_starting: <function on_starting at 0x1053bcc08>
  worker_abort: <function worker_abort at 0x1053c7668>
  bind: ['127.0.0.1:5001']
  raw_env: []
  reload: True
  check_config: False
  limit_request_field_size: 8190
  nworkers_changed: <function nworkers_changed at 0x1053c7cf8>
  timeout: 30
  ca_certs: None
  django_settings: None
  tmp_upload_dir: None
  keyfile: config/localhost/selfsigned.key
  backlog: 2048
  logger_class: gunicorn.glogging.Logger
  statsd_prefix: 
[2016-05-11 13:45:07 -0300] [27224] [INFO] Starting gunicorn 19.4.5
[2016-05-11 13:45:07 -0300] [27224] [DEBUG] Arbiter booted
[2016-05-11 13:45:07 -0300] [27224] [INFO] Listening at: https://127.0.0.1:5001 (27224)
[2016-05-11 13:45:07 -0300] [27224] [INFO] Using worker: gevent
[2016-05-11 13:45:07 -0300] [27227] [INFO] Booting worker with pid: 27227
[2016-05-11 13:45:07 -0300] [27228] [INFO] Booting worker with pid: 27228
[2016-05-11 13:45:07 -0300] [27224] [DEBUG] 2 workers
[2016-05-11 13:45:14 -0300] [27228] [INFO] Worker reloading: /Users/lucasvo/Code/foobar/project/project/app/models.py modified
[2016-05-11 13:45:14 -0300] [27227] [INFO] Worker reloading: /Users/lucasvo/Code/foobar/project/project/app/models.py modified
[2016-05-11 13:45:15 -0300] [27227] [INFO] Worker reloading: /Users/lucasvo/Code/foobar/project/project/app/models.py modified
[2016-05-11 13:45:15 -0300] [27228] [INFO] Worker reloading: /Users/lucasvo/Code/foobar/project/project/app/models.py modified
[2016-05-11 13:45:16 -0300] [27227] [INFO] Worker reloading: /Users/lucasvo/Code/foobar/project/project/app/models.py modified
... ad infinitum...
# gunicorn_config.py
####################

from config.app import LOCAL_SSL_CERT, LOCAL_SSL_KEY

bind = '127.0.0.1:5001'
workers = 2

worker_class = 'gevent'
max_requests = 1000
accesslog = '-'
errorlog = '-'
loglevel = 'DEBUG'
debug = True

reload = True

# Use SSL cert
certfile = LOCAL_SSL_CERT
keyfile = LOCAL_SSL_KEY

from gunicorn.arbiter import Arbiter
import signal
if signal.SIGWINCH in Arbiter.SIGNALS:
    Arbiter.SIGNALS.remove(signal.SIGWINCH)
@benoitc
Owner
benoitc commented May 11, 2016

thanks!

why this line:

import signal
if signal.SIGWINCH in Arbiter.SIGNALS:
    Arbiter.SIGNALS.remove(signal.SIGWINCH)

Did you tried without?

@lucasvo
lucasvo commented May 11, 2016

I am not the author of those lines so not 100% certain what it is. But I did test with those lines removed. Same issue.

@benoitc
Owner
benoitc commented May 11, 2016

i can test under pycharm. how do you launch everything in console?

@lucasvo
lucasvo commented May 11, 2016

@benoitc In my existing project which uses a manage.py file that runs gunicorn with above options, I use the following configuration:

screen shot 2016-05-11 at 18 49 07

If you have an existing test app that you are able to open in pycharm, you can do this: In the menu, go to Run > Edit Configurations. Click the small plus on the left, select python. Then enter the gunicorn command in Script/Script parameters.

If you need more precise steps to set it up, I'd be happy to try to set up and send you an empty pycharm project that reproduces the issue.

@lucasvo
lucasvo commented May 12, 2016

One interesting thing I noticed today: if I use pycharm to edit the files but run gunicorn in a terminal outside of pycharm, the looping reload does not occur. So it seems to be related to how pycharm invokes gunicorn. If I execute gunicorn inside of pycharm but just do touch watched_file.py in a shell. The problem with the reloader occurs.

@tilgovi
Collaborator
tilgovi commented May 13, 2016

Support for manage.py has been deprecated for a while. Does the issue occur if you invoke gunicorn directly and use Django's wsgi function?

@benoitc benoitc added the Bug label May 13, 2016
@benoitc
Owner
benoitc commented May 13, 2016

@tilgovi just tested it with the simple WSGI test application we have in examples and I was able to reproduce the issue. The configuration is the following:

screen shot 2016-05-13 at 10 48 00

@benoitc benoitc reopened this May 13, 2016
@benoitc benoitc added a commit that referenced this issue May 13, 2016
@benoitc don't kill ourself on reload
Killing ourself when using the `--reload` option trigger an infinite loop under some monitoring services like the one in pycharm and don't reload the file.

Instead set self.alive as False which will trigger later the worker exit. Note that if we want to force the exit we could also use sys.exit(0) .

fix #1129
3cbbc71
@lucasvo
lucasvo commented May 13, 2016

@tilgovi manage.py while identically named as django's manage.py, is our own concoction and not related to django.

@benoitc Thanks for reproducing and fixing it!

@benoitc benoitc closed this in #1261 May 14, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment