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
#

@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?