61
votes

I'm trying to add logging to a web application which uses Flask.

When hosted using the built-in server (i.e. python3 server.py), logging works. When hosted using Gunicorn, the log file is not created.

The simplest code which reproduces the problem is this one:

#!/usr/bin/env python

import logging
from flask import Flask
flaskApp = Flask(__name__)


@flaskApp.route('/')
def index():
    flaskApp.logger.info('Log message')
    print('Direct output')
    return 'Hello World\n'


if __name__ == "__main__":
    logHandler = logging.FileHandler('/var/log/demo/app.log')
    logHandler.setLevel(logging.INFO)
    flaskApp.logger.addHandler(logHandler)
    flaskApp.logger.setLevel(logging.INFO)
    flaskApp.run()

The application is called using:

gunicorn server:flaskApp -b :80 -w 4
    --access-gfile /var/log/demo/access.log
    --error-logfile /var/log/demo/error.log

When doing a request to the home page of the site, the following happens:

  1. I receive the expected HTTP 200 "Hello World\n" in response.

  2. There is a trace of the request in /var/log/demo/access.log.

  3. /var/log/demo/error.log stays the same (there are just the boot events).

  4. There is the "Direct output" line in the terminal.

  5. There is no '/var/log/demo/app.log'. If I create the file prior to launching the application, the file is not modified.

Note that:

  • The directory /var/log/demo can be accessed (read, write, execute) by everyone, so this is not the permissions issue.

  • If I add StreamHandler as a second handler, there is still no trace of the "Log message" message neither in the terminal, nor in Gunicorn log files.

  • Gunicorn is installed using pip3 install gunicorn, so there shouldn't be any mismatch with Python versions.

What's happening?

3

3 Answers

47
votes

This approach works for me: Import the Python logging module and add gunicorn's error handlers to it. Then your logger will log into the gunicorn error log file:

import logging

app = Flask(__name__)

gunicorn_error_logger = logging.getLogger('gunicorn.error')
app.logger.handlers.extend(gunicorn_error_logger.handlers)
app.logger.setLevel(logging.DEBUG)
app.logger.debug('this will show in the log')

My Gunicorn startup script is configured to output log entries to a file like so:

gunicorn main:app \
    --workers 4 \
    --bind 0.0.0.0:9000 \
    --log-file /app/logs/gunicorn.log \
    --log-level DEBUG \
    --reload
44
votes

When you use python3 server.py you are running the server3.py script.

When you use gunicorn server:flaskApp ... you are running the gunicorn startup script which then imports the module server and looks for the variable flaskApp in that module.

Since server.py is being imported the __name__ var will contain "server", not "__main__" and therefore you log handler setup code is not being run.

You could simply move the log handler setup code outside of the if __name__ == "__main__": stanza. But ensure that you keep flaskApp.run() in there since you do not want that to be run when gunicorn imports server.

More about what does if __name__ == “__main__”: do?

8
votes

There are a couple of reasons behind this: Gunicorn has its own loggers, and it’s controlling log level through that mechanism. A fix for this would be to add app.logger.setLevel(logging.DEBUG).
But what’s the problem with this approach? Well, first off, that’s hard-coded into the application itself. Yes, we could refactor that out into an environment variable, but then we have two different log levels: one for the Flask application, but a totally separate one for Gunicorn, which is set through the --log-level parameter (values like “debug”, “info”, “warning”, “error”, and “critical”).

A great solution to solve this problem is the following snippet:

import logging
from flask import Flask, jsonify

app = Flask(__name__)

@app.route('/')
def default_route():
    """Default route"""
    app.logger.debug('this is a DEBUG message')
    app.logger.info('this is an INFO message')
    app.logger.warning('this is a WARNING message')
    app.logger.error('this is an ERROR message')
    app.logger.critical('this is a CRITICAL message')
    return jsonify('hello world')

if __name__ == '__main__':
    app.run(host=0.0.0.0, port=8000, debug=True)

else:
    gunicorn_logger = logging.getLogger('gunicorn.error')
    app.logger.handlers = gunicorn_logger.handlers
    app.logger.setLevel(gunicorn_logger.level)

Refrence: Code and Explanation is taken from here