Why is Flask application not creating any logs when hosted by Gunicorn?
Asked Answered
V

3

83

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?

Vigen answered 26/10, 2014 at 22:31 Comment(0)
R
50

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?

Rigby answered 27/10, 2014 at 0:16 Comment(1)
Also note that flask runs in production mode by default under gunicorn, where the app.logger level is set to WARN, so you won't see app.logger.info() or app.logger.debug(). If you want that, set app.debug = True.Disregardful
R
61

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
Recovery answered 2/6, 2016 at 15:19 Comment(7)
Can I add the path of the log file inside the script inside instead at the command line?Acidimetry
Does this result in log messages being printed twice for you, @pkout? (It does for me.)Undervalue
@Undervalue for the doublie logging issue, refer to medium.com/@trstringer/…Prison
Thanks for the suggestion, @IronBishop. Unfortunately, this post is what initially led me down this path, so it won't help me. I think I've determined that the double logging issue I'm seeing is being caused by something one of my dependencies (Plotly Dash) is doing. It seems to be creating a new logging handler which is also tapping into my application logs.Undervalue
Worked for me THANKS ! :)Gallop
Do I need to create /app/logs/gunicorn.log this path and file manually?Tica
I have printing twice issue too, moving logger setup under if __name__ != "__main__": helps avoid. Or like @Cumulative posted at https://mcmap.net/q/241456/-why-is-flask-application-not-creating-any-logs-when-hosted-by-gunicorn in the else. The reason is what @Jeremy Allen posted at https://mcmap.net/q/241456/-why-is-flask-application-not-creating-any-logs-when-hosted-by-gunicornSculpsit
R
50

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?

Rigby answered 27/10, 2014 at 0:16 Comment(1)
Also note that flask runs in production mode by default under gunicorn, where the app.logger level is set to WARN, so you won't see app.logger.info() or app.logger.debug(). If you want that, set app.debug = True.Disregardful
C
16

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

Cumulative answered 24/5, 2020 at 19:0 Comment(1)
I tried this and it's not working. I'm using the app factory pattern so I run gunicorn using create_app. When I call my app from one of my endpoints, I'm using current_app to fetch application logger, but this is not doing it for me. I'm running and example app using gunicorn "src:create_app()". Inside create_app() I'm doing everything there (handlers and such). On my blueprint I'm importing "current_app" from flask and logging current_app.logger.info("Example") but logs aren't appearing! Any idea how to work around app factory for this?Billbug

© 2022 - 2024 — McMap. All rights reserved.