Why does logging not work when running a Flask app with werkzeug?

Question

So here is a copy paste example that reproduces the problem.

import logging

from flask import Flask
from werkzeug.serving import run_simple
from werkzeug.wsgi import DispatcherMiddleware

def app_builder(app_name, log_file):

    app = Flask(app_name)
    app.debug = True

    handler = logging.FileHandler(log_file)
    handler.setLevel(logging.DEBUG)
    app.logger.addHandler(handler)

    return app

def _simple(env, resp):
    resp(b'200 OK', [(b'Content-Type', b'text/plain')])
    return [b'root']

if __name__ == "__main__":

    app = app_builder(app_name='app', log_file='app.log')

    @app.route('/')
    def index():
        return '<a href="/app/error">click for error</a>'

    @app.route('/error')
    def error():
        1/0
        return 'error page'

    app2 = app_builder(app_name='app2', log_file='app2.log')

    @app2.route('/')
    def index():
        return 'you are getting responses from app2'

    app.debug = True
    app2.debug = True

    application = DispatcherMiddleware(_simple, {
        '/app':     app,
        '/app2':    app2
        })

    run_simple(hostname='localhost',
               port=5000,
               application=application,
               use_reloader=True,
               use_debugger=True)

To make an error show up navigate to http://localhost:5000/app/error, I want to know why the stack trace doesn't show up in the app.log file. I assume that the DispatcherMiddleware or run_simple are somehow catching the exception before it can be logged. If I run only the app instance using app.run() the error logging works fine.

Answer 1

The normal exception handler is not called when app.debug = True. Looking in the code of app.py in Flask:

def log_exception(self, exc_info):
    """Logs an exception.  This is called by :meth:`handle_exception`
    if debugging is disabled and right before the handler is called.
    ^^^^^^^^^^^^^^^^^^^^^^^^
    The default implementation logs the exception as error on the
    :attr:`logger`.

Indeed, when setting app.debug = True the exceptions propagation is set to True explicitly, which prevents log_exception to be called. Here is an excerpt of the documentation (emphasis is mine):

PROPAGATE_EXCEPTIONS: explicitly enable or disable the propagation of exceptions. If not set or explicitly set to None this is implicitly true if either TESTING or DEBUG is true.

So, I managed to get both werkzeug debugging and logging working happily together with a little tweak and the following code:

import logging

from flask import Flask
from werkzeug.serving import run_simple
from werkzeug.wsgi import DispatcherMiddleware
## NEW CODE HERE
import functools
from flask._compat import reraise

def my_log_exception(exc_info, original_log_exception=None):
    original_log_exception(exc_info)
    exc_type, exc, tb = exc_info
    # re-raise for werkzeug
    reraise(exc_type, exc, tb)
## 

def app_builder(app_name, log_file):
    app = Flask(app_name)
    app.debug = True
    app.config.update(PROPAGATE_EXCEPTIONS=False)

    handler = logging.FileHandler(log_file)
    handler.setLevel(logging.DEBUG)
    app.logger.addHandler(handler)

    ## NEW CODE
    app.log_exception = functools.partial(my_log_exception,  original_log_exception=app.log_exception)
    ##

    return app

# rest of your code is unchanged