Flask Logging Appear Twice

April 25, 2019

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

import sys
import logging
from flask import Flask

app = 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_app
app.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 = False
log.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
This work is licensed under a
Creative Commons Attribution-NonCommercial 4.0 International License.