Flask logging not working at all

Question

I'm trying to log messages in Flask both to file and to stdout. I've been reading the official Flask docs and came up with this:

from flask import Flask
import logging
from logging import Formatter, FileHandler

app = Flask(__name__)



@app.route('/')
def hello_world():
    app.logger.debug('second test message...')
    return 'Hello World!'


if __name__ == '__main__':
    #Setup the logger
    file_handler = FileHandler('output.log')
    handler = logging.StreamHandler()
    file_handler.setLevel(logging.DEBUG)
    handler.setLevel(logging.DEBUG)
    file_handler.setFormatter(Formatter(
        '%(asctime)s %(levelname)s: %(message)s '
        '[in %(pathname)s:%(lineno)d]'
     ))
     handler.setFormatter(Formatter(
        '%(asctime)s %(levelname)s: %(message)s '
        '[in %(pathname)s:%(lineno)d]'
     ))
     app.logger.addHandler(handler)
     app.logger.addHandler(file_handler)
     app.logger.error('first test message...')
     app.run()

There are several problems:

1. No output.log file is generated

2. Only the first logging message works:

   app.logger.error('testing...')

And only in stdout...the one in the view "/" does not even print to stdout... am I doing something wrong?

This is the output from starting the app and going to /:

2015-03-08 11:33:27,183 ERROR: first test message... [in /home/mosquito/python_projects/flask_tst/flask_tst.py:31]
* Running on http://127.0.0.1:5000/ (Press CTRL+C to quit)
127.0.0.1 - - [08/Mar/2015 11:33:43] "GET / HTTP/1.1" 200 -

Answer 1

Your (debug) logging messages are getting suppressed by Flask as you're not running in debug mode. If you set the following flag to True, your code will work.

    app.run(debug=True)

The messages will now appear as expected.

BennyE$ python3 stackoverflow.py 
2015-03-08 12:04:04,650 ERROR: firs test message... [in stackoverflow.py:31]
 * Running on http://0.0.0.0:5000/ (Press CTRL+C to quit)
 * Restarting with stat
2015-03-08 12:04:04,807 ERROR: firs test message... [in stackoverflow.py:31]
--------------------------------------------------------------------------------
DEBUG in stackoverflow [stackoverflow.py:11]:
second test message...
--------------------------------------------------------------------------------
2015-03-08 12:04:13,789 DEBUG: second test message... [in stackoverflow.py:11]
192.168.178.23 - - [08/Mar/2015 12:04:13] "GET / HTTP/1.1" 200 -
--------------------------------------------------------------------------------
DEBUG in stackoverflow [stackoverflow.py:11]:
second test message...
--------------------------------------------------------------------------------
2015-03-08 12:04:14,899 DEBUG: second test message... [in stackoverflow.py:11]
192.168.178.23 - - [08/Mar/2015 12:04:14] "GET / HTTP/1.1" 200 -

This is the output in the associated output file:

BennyE$ cat output.log 
2015-03-08 11:58:22,226 ERROR: firs test message... [in stackoverflow.py:31]
2015-03-08 12:04:04,650 ERROR: firs test message... [in stackoverflow.py:31]
2015-03-08 12:04:04,807 ERROR: firs test message... [in stackoverflow.py:31]
2015-03-08 12:04:13,789 DEBUG: second test message... [in stackoverflow.py:11]
2015-03-08 12:04:14,899 DEBUG: second test message... [in stackoverflow.py:11]