How to write a Flask log message to an excellent debug log to a file during production?

Question

I have a Flask application that works well and generates a random error that is visible when it works with debug=True :

 if __name__ == '__main__': app.run(debug=True) 

I get helpful error messages such as:

 Traceback (most recent call last): File "./main.py", line 871, in index_route KeyError: 'stateIIIII' 

I would like to receive error messages similar to those saved to a file when I launch the application during production (using Lighttpd + fastcgi).

Having studied various StackOverflow questions ( http://flask.pocoo.org/docs/errorhandling/ , http://docs.python.org/2/library/logging.html , etc.); Flask mailing list and a few blogs, there seems to be no easy way to send all the big error messages to a file - I need to use the Python protocol module to configure things. So I came up with the following code.

At the top of my application file, I have various imported products, followed by:

 app = Flask(__name__) if app.debug is not True: import logging from logging.handlers import RotatingFileHandler file_handler = RotatingFileHandler('python.log', maxBytes=1024 * 1024 * 100, backupCount=20) file_handler.setLevel(logging.ERROR) app.logger.setLevel(logging.ERROR) app.logger.addHandler(file_handler) 

Then I put the code for each route in a try / except statement and used traceback to find out which line the error came from and print a nice error message:

 def some_route(): try: # code for route in here (including a return statement) except: exc_type, exc_value, exc_traceback = sys.exc_info() app.logger.error(traceback.print_exception(exc_type, exc_value, exc_traceback, limit=2)) return render_template('error.html') 

And then right at the end of the file I delete debug=True . Although I do not think I need to do this, since the application is launched by the fastcgi server (?), When it starts in production. The last two lines of my application code are as follows:

 if __name__ == '__main__': app.run() 

I'm struggling to get this to work. I think that best of all I was able to get one error log message, which will be saved in a file using ( app.logger.error('test message') ), but it prints only one message. Attempting to register another error immediately after this is simply ignored.

Answer 1

I do not know why it does not work, but I can tell how this is done.

First of all, you do not need to set the app.logger level. Therefore, remove this line app.logger.setLevel() .

You want to save an exception and error return page for each view. Write a lot, write this code everywhere. Flask provides a method for this. Define an error handler method like this.

  @app.errorhandler(500) def internal_error(exception): app.logger.error(exception) return render_template('500.html'), 500 

Whenever a view throws an exception, this method is called and passes the exception as an argument. The Python protocol provides an exception method that is used to maintain a full trace of the exception.

Since this handles all exceptions, you don’t even need to put the code in a try / except block. Although, if you want to do something before calling the error handler (for example, a rollback session or transaction), do the following:

  try: #code except: #code raise 

If you want the date and time to be added for each entry in your log file, you can use the following code (instead of the similar code in the question).

 if app.debug is not True: import logging from logging.handlers import RotatingFileHandler file_handler = RotatingFileHandler('python.log', maxBytes=1024 * 1024 * 100, backupCount=20) file_handler.setLevel(logging.ERROR) formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s") file_handler.setFormatter(formatter) app.logger.addHandler(file_handler) 

Answer 2

For those who read this later.

I think it's better to come up with more useful information in error messages. URL, client IP, user agent, etc. The checkbox logs exceptions internally (in app.debug==False mode) using the Flask.log_exception function. So, instead of manually writing to @app.errorhandler I am doing something like this:

 class MoarFlask(Flask): def log_exception(self, exc_info): """...description omitted...""" self.logger.error( """ Request: {method} {path} IP: {ip} User: {user} Agent: {agent_platform} | {agent_browser} {agent_browser_version} Raw Agent: {agent} """.format( method = request.method, path = request.path, ip = request.remote_addr, agent_platform = request.user_agent.platform, agent_browser = request.user_agent.browser, agent_browser_version = request.user_agent.version, agent = request.user_agent.string, user=user ), exc_info=exc_info ) 

Then, during setup, associate FileHandler with app.logger and continue. I do not use StreamHandler because many servers (like uWSGI) like to pollute it with their own proprietary verbose useless out-of-line messages.

Do not be afraid to expand the bottle. You will be forced to do it sooner or later;)

Answer 3

I am not a specialist in logging module, but considering my experience with this + several years in Python + Flask, you can have a good logging configuration, given some observations:

• at the beginning of each function (route), create a timestamp object to register the exact time when the request was made, regardless if it was successful or not

• use @ app.after_request , to register each successful request

• use @ app.errorhandler , for reporting common errors + Tracebacks

Here is an example demonstrating this idea:

 #/usr/bin/python3 """ Demonstration of logging feature for a Flask App. """ from logging.handlers import RotatingFileHandler from flask import Flask, request, jsonify from time import strftime __author__ = "@ivanleoncz" import logging import traceback app = Flask(__name__) @app.route("/") @app.route("/index") def get_index(): """ Function for / and /index routes. """ return "Welcome to Flask! " @app.route("/data") def get_data(): """ Function for /data route. """ data = { "Name":"Ivan Leon", "Occupation":"Software Developer", "Technologies":"[Python, Flask, JavaScript, Java, SQL]" } return jsonify(data) @app.route("/error") def get_nothing(): """ Route for intentional error. """ return foobar # intentional non-existent variable @app.after_request def after_request(response): """ Logging after every request. """ # This avoids the duplication of registry in the log, # since that 500 is already logged via @app.errorhandler. if response.status_code != 500: ts = strftime('[%Y-%b-%d %H:%M]') logger.error('%s %s %s %s %s %s', ts, request.remote_addr, request.method, request.scheme, request.full_path, response.status) return response @app.errorhandler(Exception) def exceptions(e): """ Logging after every Exception. """ ts = strftime('[%Y-%b-%d %H:%M]') tb = traceback.format_exc() logger.error('%s %s %s %s %s 5xx INTERNAL SERVER ERROR\n%s', ts, request.remote_addr, request.method, request.scheme, request.full_path, tb) return "Internal Server Error", 500 if __name__ == '__main__': handler = RotatingFileHandler('app.log', maxBytes=10000, backupCount=3) logger = logging.getLogger(__name__) logger.setLevel(logging.ERROR) logger.addHandler(handler) app.run(host="127.0.0.1",port=8000) 

For more information about logrotate and logs on stdout and the file at the same time: this Gist

Answer 4

If you use gunicorn to run your Flask application, you can log all Flask exceptions to gunicorn logs by adding fire error handlers to the Flask logger:

In module/__init__.py :

 @app.before_first_request def setup_logging(): if not app.debug: import logging gunicorn_logger = logging.getLogger('gunicorn.error') for handler in gunicorn_logger.handlers: app.logger.addHandler(handler)