DispatcherMiddleware with different loggers per app in flask 1.0

[jwldk]

After upgrading to flask 1.0 logging from different apps using DispatcherMiddleware, each log emitted is written to all handlers in the different apps. I assume this caused by app.logger always having the name flask.app, maybe?

Here is a example:

from werkzeug.wsgi import DispatcherMiddleware
from flask import Flask
from logging.handlers import RotatingFileHandler


handler1 = RotatingFileHandler('app1.log')
app1 = Flask('app1')
app1.logger.addHandler(handler1)

handler2 = RotatingFileHandler('app2.log')
app2 = Flask('app2')
app2.logger.addHandler(handler2)


@app1.route("/")
def hello():
    app1.logger.error("from app1")
    return ''


@app2.route("/")
def hello2():
    app2.logger.error("from app2")
    return ''


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

Run with

uwsgi --socket 0.0.0.0:8000 --protocol=http -w app --callable app

And then make a request to / and /app2/. Each error log will be written in both logfiles.

Environment

• Python version: 3.6.5
• Flask version: 1.0.2
• Werkzeug version: 0.14.1

My actual app is using current_app.logger with blueprints with the same behaviour, but I assume it the same issue.

[davidism]

It logs twice because you're adding two handlers to the same logger. Add one handler to the "flask.app" logger instead.

To get different names, override Flask.logger:

class LoggerFlask(Flask):
    @property
    def logger(self):
        return super().logger.getChild(self.name)

app1 = LoggerFlask("app1")
app2 = LoggerFlask("app2")

Or see the docs on logging for how to inject extra information into log records. In your case you would inject current_app.name.

[jwldk]

Thanks for the workaround. I can see this is not really a bug per se - just a breaking change for my setup :), but while I can see from PR 2436 that LOGGER_NAME was removed to simply things. However wouldn't it make sense to at least be able to override the default flask.app in the constructor like app = Flask(..., logger_name="myapp") which can then be used by create_logger ? Because another unfortunate side effect I've encountered, is that if you add a Sentry error handler to the logging, the Sentry interface groups errors by logger.name - so if you have a bunch of flask applications, everything is now simply called flask.app.

[davidism]

Since we now use the flask. prefix for logger names, it's easy to autoconfigure a handler just for Flask, rather than interfering with other libraries by messing with the root logger, which was part of the whole original problem.

Multiple apps was an unforseen case, and I understand how this can be inconvenient.

I'm hesitant to make this configurable again. Perhaps a compromise would be f"flask.app:{app.name}" so that it's unique but still under the flask namespace.

[davidism]

Or even just hard code using app.name instead of "flask.app". If we can be reasonably sure that it won't cause issues like the previous implementation, I'm fine with changing it.