title: Flask app logger not working when running within gunicorn
body: <p>I'm trying to save application log messages from a very simple flask app in a log file. While this works flawlessly when I'm running the app with the embedded Flask server, it is not working at all when running within gUnicorn, basically, no application output is redirected neither the log file (the one specified in my Flask app) or to the STDOUT when running gunicorn. </p>
  
  <p>That said, this is my Flask app:</p>
  
  <pre><code>@app.route('/')
  def index():
      app.logger.debug('Into /!!!!')
      print 'Will this print?'
      return 'Flask is running!'
  
  
  if __name__ == '__main__':
      #Setup the logger
      file_handler = FileHandler('test.log')
      handler = logging.StreamHandler()
      file_handler.setLevel(logging.DEBUG)
      handler.setLevel(logging.DEBUG)
      file_handler.setFormatter(Formatter(
      '%(asctime)s %(levelname)s: %(message)s '
      '[in %(pathname)s:%(lineno)d]'))
      handler.setFormatter(Formatter(
      '%(asctime)s %(levelname)s: %(message)s '
      '[in %(pathname)s:%(lineno)d]'))
      app.logger.addHandler(handler)
      app.logger.addHandler(file_handler)
      app.run(debug=True)
  </code></pre>
  
  <p>Now if I start the app as:</p>
  
  <pre><code>python app.py
  </code></pre>
  
  <p>I get the expected output:</p>
  
  <pre><code> * Running on http://127.0.0.1:5000/ (Press CTRL+C to quit)
   * Restarting with stat
  
  --------------------------------------------------------------------------------
  DEBUG in app [app.py:23]:
  Into /!!!!
  --------------------------------------------------------------------------------
  2015-03-11 09:36:18,375 DEBUG: Into /!!!! [in app.py:23]
  Will this print?
  127.0.0.1 - - [11/Mar/2015 09:36:18] "GET / HTTP/1.1" 200 -
  </code></pre>
  
  <p>Tailing test.log, I see:</p>
  
  <pre><code>2015-03-11 09:36:18,375 DEBUG: Into /!!!! [in app.py:23]
  </code></pre>
  
  <p>Everything looks great so far, then when I try to run the app with nginx + gunicorn, first I've tried to run gunicorn like this:</p>
  
  <pre><code>gunicorn app:app -b localhost:8000 --debug --log-level debug
  </code></pre>
  
  <p>App is working, if I go to <a href="http://localhost" rel="noreferrer">http://localhost</a>:</p>
  
  <pre><code>curl http://localhost
  Flask is running!
  </code></pre>
  
  <p>But looking at the log file, is empty, nothing is being written. I've added 777 permissions just to check if it was a permission problem to no avail. Then looking at gunicorn stdout, nothing is being written besides the print statement:</p>
  
  <pre><code>2015-03-11 09:42:06 [25641] [DEBUG] GET /
  Will this print?
  </code></pre>
  
  <p><a href="https://github.com/benoitc/gunicorn/issues/379" rel="noreferrer">Looking around</a>, I've tried to redirect all output to gunicorn logs, then starting gunicorn like this:</p>
  
  <pre><code>gunicorn app:app -b localhost:8000 --debug --log-file /tmp/test.log --log-level debug --error-logfile /tmp/error.log
  </code></pre>
  
  <p>But now I don't even get print statements in gunicorn files, this is the output from both test.log and error.log (they are identical):</p>
  
  <pre><code>2015-03-11 09:46:17 [26257] [DEBUG]   tmp_upload_dir: None
  2015-03-11 09:46:17 [26257] [DEBUG]   keyfile: None
  2015-03-11 09:46:17 [26257] [DEBUG]   backlog: 2048
  2015-03-11 09:46:17 [26257] [DEBUG]   logger_class: simple
  2015-03-11 09:46:17 [26257] [INFO] Starting gunicorn 17.5
  2015-03-11 09:46:17 [26257] [DEBUG] Arbiter booted
  2015-03-11 09:46:17 [26257] [INFO] Listening at: http://127.0.0.1:8000 (26257)
  2015-03-11 09:46:17 [26257] [INFO] Using worker: sync
  2015-03-11 09:46:17 [26262] [INFO] Booting worker with pid: 26262
  2015-03-11 09:48:15 [26262] [DEBUG] GET /
  </code></pre>
  
  <p>There is a very similar question <a href="https://stackoverflow.com/questions/8950674/debugging-a-flask-app-running-in-gunicorn?lq=1">here</a>, one of the answers seems to suggest that no application logger is available when runnning within gunicorn??? This sounds, at least, quite strange...how am I supposed to log then?</p>
  
  <p>Another <a href="https://stackoverflow.com/questions/17743019/flask-logging-cannot-get-it-to-write-to-a-file?rq=1">proposed solution</a> seems to suggest not using Flask logger, but is not related with gunicorn (I think)...</p>
  
  <p>What I'm missing? Should I give up on gunicorn and go for Apache-mod wsgi? Nginx-uWSGI? FastCGI? Any ideas?</p>
  
  <p>Thanks!
  Alejandro</p>
  
  <p><strong>EDIT:</strong> </p>
  
  <p>I've tried this very same setup with uWGSI instead of gunicorn and same behaviour, no application logging is obtained whatsoever.</p>
  
  <p>Now based on <a href="https://stackoverflow.com/questions/1383254/logging-streamhandler-and-standard-streams">this response</a> and this <a href="http://lists.unbit.it/pipermail/uwsgi/2012-July/004502.html" rel="noreferrer">other one</a>, I came up with this (on gUnicorn and uWSGI, in both it works)</p>
  
  <pre><code>from flask import Flask
  import logging
  from logging import Formatter, FileHandler
  
  app = Flask(__name__)
  
  LOGGER = logging.getLogger('whatever')
  file_handler = FileHandler('test.log')
  handler = logging.StreamHandler()
  file_handler.setFormatter(Formatter(
      '%(asctime)s %(levelname)s: %(message)s '
      '[in %(pathname)s:%(lineno)d]'
  ))
  handler.setFormatter(Formatter(
      '%(asctime)s %(levelname)s: %(message)s '
      '[in %(pathname)s:%(lineno)d]'
  ))
  LOGGER.addHandler(file_handler)
  LOGGER.addHandler(handler)
  LOGGER.setLevel(logging.INFO)
  
  @app.route('/')
  def hello():
      LOGGER.info('info log')
      LOGGER.debug('debug log')
      return 'Hello!'
  
  if __name__ == '__main__':
      app.run()
  </code></pre>
  
  <p>Output from gunicorn:</p>
  
  <pre><code>2015-03-11 12:25:01 [11540] [INFO] Starting gunicorn 17.5
  2015-03-11 12:25:01 [11540] [INFO] Listening at: http://127.0.0.1:8000 (11540)
  2015-03-11 12:25:01 [11540] [INFO] Using worker: sync
  2015-03-11 12:25:01 [11545] [INFO] Booting worker with pid: 11545
  2015-03-11 12:26:20,765 INFO: info log [in /home/mosquito/www/flask-project/flask-project/app.py:24]
  </code></pre>
  
  <p>And looking at my test.log file:</p>
  
  <pre><code>2015-03-11 12:26:20,765 INFO: info log [in /home/mosquito/www/flask-project/flask-project/app.py:24]
  </code></pre>
  
  <p>So yeah, it kinda works, but original question still remains...why the heck the Flask logger does not seem to work when running inside wsgi containers - gunicorn, uWSGI?</p>