Flask Logging Appear Twice

Apr 25, 2019

It seems when logging.info is called, a root handler is created and other loggers' logging appear twice due to propagation.

import sysimport loggingfrom flask import Flaskapp = Flask(__name__)app.logger.setLevel(logging.DEBUG)# logging.basicConfig(level=logging.DEBUG)logging.getLogger().setLevel(logging.DEBUG)log = logging.getLogger(__name__)if not log.handlers:    log.setLevel(logging.DEBUG)    formatter = logging.Formatter(fmt="%(asctime)s %(levelname)s %(module)s: %(message)s",                              datefmt="%H:%M:%S")    handler = logging.StreamHandler(sys.stdout)    handler.setLevel(logging.DEBUG)    handler.setFormatter(formatter)    log.addHandler(handler)@app.route('/')def test_logging():    logging.info('root logging')    app.logger.info('app.logger')    logging.getLogger('flask.app').info('flask.app')    log.info('module log')    return 'Test logging'from more import app as more_appapp.register_blueprint(more_app, url_prefix='/')if __name__ == '__main__':    print('started')    app.run(host='127.0.0.1', port=8088, debug=True)

Output

INFO:root:root logging
[2019-04-25 12:52:03,892] INFO in test: app.logger
INFO:flask.app:app.logger
[2019-04-25 12:52:03,893] INFO in test: flask.app
INFO:flask.app:flask.app
12:52:03 INFO test: module log
INFO:__main__:module log

Solution 1: don't use root logging

@app.route('/')def test_logging():    # logging.info('root logging')    app.logger.info('app.logger')    logging.getLogger('flask.app').info('flask.app')    log.info('module log')    return 'Test logging'

Output

[2019-04-25 12:52:43,979] INFO in test: app.logger
[2019-04-25 12:52:43,979] INFO in test: flask.app
12:52:43 INFO test: module log

Solution 2: prevent propagation to root

app.logger.propagate = Falselog.propagate = False@app.route('/')def test_logging():    logging.info('root logging')    app.logger.info('app.logger')    logging.getLogger('flask.app').info('flask.app')    log.info('module log')    return 'Test logging'

Output

INFO:root:root logging
[2019-04-25 12:54:36,079] INFO in test: app.logger
[2019-04-25 12:54:36,080] INFO in test: flask.app
12:54:36 INFO test: module log

❤️ Is this article helpful?

Buy me a coffee ☕ or support my work via PayPal to keep this space 🖖 and ad-free.

Do send some 💖 to @d_luaz or share this article.

✨ By Desmond Lua

A dream boy who enjoys making apps, travelling and making youtube videos. Follow me on @d_luaz

👶 Apps I built

Travelopy - discover travel places in Malaysia, Singapore, Taiwan, Japan.