Demonstration of logging feature for a Flask App.

flask_app_logging.py

#/usr/bin/python3
""" Demonstration of logging feature for a Flask App. """

from logging.handlers import RotatingFileHandler
from flask import Flask, request, jsonify
from time import strftime

__author__ = "@ivanleoncz"

import logging
import traceback


app = Flask(__name__)

@app.route("/")
@app.route("/index")
def get_index():
    """ Function for / and /index routes. """
    return "Welcome to Flask! "


@app.route("/data")
def get_data():
    """ Function for /data route. """
    data = {
            "Name":"Ivan Leon",
            "Occupation":"Software Developer",
            "Technologies":"[Python, Flask, JavaScript, Java, SQL]"
    }
    return jsonify(data)


@app.route("/error")
def get_nothing():
    """ Route for intentional error. """
    return foobar # intentional non-existent variable


@app.after_request
def after_request(response):
    """ Logging after every request. """
    # This avoids the duplication of registry in the log,
    # since that 500 is already logged via @app.errorhandler.
    if response.status_code != 500:
        ts = strftime('[%Y-%b-%d %H:%M]')
        logger.error('%s %s %s %s %s %s',
                      ts,
                      request.remote_addr,
                      request.method,
                      request.scheme,
                      request.full_path,
                      response.status)
    return response


@app.errorhandler(Exception)
def exceptions(e):
    """ Logging after every Exception. """
    ts = strftime('[%Y-%b-%d %H:%M]')
    tb = traceback.format_exc()
    logger.error('%s %s %s %s %s 5xx INTERNAL SERVER ERROR\n%s',
                  ts,
                  request.remote_addr,
                  request.method,
                  request.scheme,
                  request.full_path,
                  tb)
    return "Internal Server Error", 500

if __name__ == '__main__':
    # maxBytes to small number, in order to demonstrate the generation of multiple log files (backupCount).
    handler = RotatingFileHandler('app.log', maxBytes=10000, backupCount=3)
    # getLogger(__name__):   decorators loggers to file + werkzeug loggers to stdout
    # getLogger('werkzeug'): decorators loggers to file + nothing to stdout
    logger = logging.getLogger(__name__)
    logger.setLevel(logging.ERROR)
    logger.addHandler(handler)
    app.run(host="127.0.0.1",port=8000)


# ---> getLogger(__name__)
#
# $ python3 simple_app_logging.py 
# * Running on http://127.0.0.1:8000/ (Press CTRL+C to quit)
# 127.0.0.1 - - [11/Mar/2018 18:55:39] "GET / HTTP/1.1" 200 -
# 127.0.0.1 - - [11/Mar/2018 18:55:47] "GET /data HTTP/1.1" 200 -
# 127.0.0.1 - - [11/Mar/2018 18:55:50] "GET /error HTTP/1.1" 500 -
#
# $ cat app.log 
# [2018-Mar-11 18:55] 127.0.0.1 GET http /? 200 OK
# [2018-Mar-11 18:55] 127.0.0.1 GET http /data? 200 OK
# [2018-Mar-11 18:55] 127.0.0.1 GET http /error? 5xx INTERNAL SERVER ERROR
# Traceback (most recent call last):
#   File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 1612, in full_dispatch_request
#     rv = self.dispatch_request()
#   File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 1598, in dispatch_request
#     return self.view_functions[rule.endpoint](**req.view_args)
#   File "simple_app_logging.py", line 37, in get_nothing
#     return foobar # intentional non-existent variable
# NameError: name 'foobar' is not defined


# ---> getLogger('werkzeug')
#
# $ python3 simple_app_logging.py 
#
#
#
# $ cat app.log 
# [2018-Mar-11 18:44] 127.0.0.1 GET http /? 200 OK
# [2018-Mar-11 18:44] 127.0.0.1 GET http /data? 200 OK
# [2018-Mar-11 18:45] 127.0.0.1 GET http /error? 5xx INTERNAL SERVER ERROR
# Traceback (most recent call last):
#   File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 1612, in full_dispatch_request
#     rv = self.dispatch_request()
#   File "/usr/local/lib/python3.4/dist-packages/flask/app.py", line 1598, in dispatch_request
#     return self.view_functions[rule.endpoint](**req.view_args)
#   File "simple_app_logging.py", line 37, in get_nothing
#     return foobar # intentional non-existent variable
# NameError: name 'foobar' is not defined

# For more info: https://stackoverflow.com/questions/14037975/how-do-i-write-flasks-excellent-debug-log-message-to-a-file-in-production/39284642#39284642
#

Thanks a lot!

Note that if you're using werkzeug you must use the following line instead:

logger = logging.getLogger('werkzeug')

I made an update on this Gist. Check it out, please.
This example above, is focused on maintaining log messages recorded in a file and in the stdout. If you use 'werkzeug', it will supress he stdout messages from Werkzeug and will only record the loggers that are executed via the decorators.
If you have a better idea on how to improve this Gist, please, do it. I just know the basic from Python logging, and maybe there could another approach, more efficient.
Thanks guys for getting in contact :)!

Could you add a "full request" logger? I would like to log the parameters that have been send to the server as well as the headers and co.

Thank you very very much !!

@maximveksler, I have to check this. I believe that this is possible, since that there's a lot of information that you can extract from flask.request module. I'll make an update, as soon as I can :).

@Sumanniroula: you're welcome :).

That's exactly what I was looking for.

Thanks a lot!

Thanks Ivan!

Everyone: you're welcome.
Please, make it better! I'm pretty sure that it can be :)

Best Regards,
@ivanleoncz

Is line 76 logger = logging.getLogger('__name__') intended? I guess, you'd like to use logger = logging.getLogger(__name__) (without single quotes).

No, @Enr1g, it wasn't. But indeed, the single quotes are not necessary for __name__, since that the variable already holds the namespace where the Python module, script, app, etc., is running. I'll make an update. Thanks for observing this 👍 :)

Flask's documentation reads "As of Flask 0.7 this function might not be executed at the end of the request in case an unhandled exception occurred." That's the situation where I care about logging. Anyone encountered problems with that?