Flask 记录日志

日志是我们应用中十分重要的一部分，正确合理的日志记录可以帮助我们监控系统运行状态，也能在出现问题时帮助我们及时定位异常。

今天就讲一讲在 Flask 应用中记录日志。

默认日志

其实从 Flask 0.3 版本开始，系统就已经帮我们预配置一个 logger，而这个 logger 的使用也十分简单：

1
2
3

app.logger.debug('debug: hello')
app.logger.warning('warning: hello')
app.logger.error('error: hello')

使用方法与正常 logger 无异，如果有不了解请参考上一篇文章：。

不过如果我们要输出更多的信息，或者将日志输出为文件，默认的配置就有些不够用了。

手动添加 handler 和 formatter

我们可以通过手动添加 handler 和 formatter：

from flask import Flask
import logging
from logging.handlers import RotatingFileHandler

app = Flask(__name__)
log_file = 'foo.log'


@app.route('/')
def index():
    # 3
    app.logger.debug('debug: hello')
    app.logger.info('info: hello')
    app.logger.warning('warning: hello')
    app.logger.error('error: hello')
    app.logger.critical('critical: hello')

    # 4
    try:
        raise ValueError("Test Exception")
    except ValueError as e:
        app.logger.exception(e)

    return "Hello World"


if __name__ == '__main__':
    # 1
    handler = RotatingFileHandler(log_file, maxBytes=1024 * 1024, backupCount=5)
    fmt = '%(asctime)s - %(filename)s:%(lineno)s - func: [%(name)s] - %(message)s'
    # 2
    formatter = logging.Formatter(fmt)
    handler.setFormatter(formatter)

    app.logger.addHandler(handler)
    app.logger.setLevel(logging.DEBUG)
    app.run()

运行程序，访问 http://localhost:5000

会在当前目录下产生一个 foo.log 文件：

2017-11-09 14:27:01,130 - Log.py:11 - func: [__main__] - debug: hello
2017-11-09 14:27:01,131 - Log.py:12 - func: [__main__] - info: hello
2017-11-09 14:27:01,131 - Log.py:13 - func: [__main__] - warning: hello
2017-11-09 14:27:01,131 - Log.py:14 - func: [__main__] - error: hello
2017-11-09 14:27:01,131 - Log.py:15 - func: [__main__] - critical: hello
2017-11-09 14:27:01,131 - Log.py:20 - func: [__main__] - Test Exception
Traceback (most recent call last):
  File "E:/pycharm-workspace/Hello/Log.py", line 18, in index
    raise ValueError("Test Exception")
ValueError: Test Exception

代码解释：

我们通过 logging.handlers 模块中的 RotatingFileHandler 类定义了一个 handler，这个类的作用是滚动日志文件，log_file 是日志文件，maxBytes 参数是日志文件的最大 byte 数，backupCount 是备份数。假设 log_file 变量值为 foo.log，当 foo.log 达到 maxBytes 限制时，Python 会自动将其重命名为 foo.log.1，并且之后的日志依然写入 foo.log。又一次到达最大限制时，将 foo.log.1 重命名为 foo.log.2，一直这样滚动记录。总日志文件数是 foo.log + foo.log.1 + ... + foo.log.backupCount。更详细的资料请查看官网。
formatter，setFormatter、addHandler、setLevel 等操作有了上一篇的基础想必很容易理解。其实 app.logger 就是一个 Logger 类实例
输出五个级别的日志信息
发出异常，然后在日志中显示 stack trace，如果使用 3 中的几个函数输出，则只会输出 "Test Exception" 而不会输出栈追踪信息。

理解了上面这些内容，在 flask 中定制日志就很简单了。

服务器端日志记录

服务器端我采用的是：部署方式，其中运行命令在 /etc/supervisord.d/server.ini 下：

1	command=/虚拟环境目录/bin/gunicorn -w 2 -b 127.0.0.1:5000 wsgi:app

这条命令的作用是：从项目目录下的 wsgi 模块中引入 app 变量，然后执行 app.run()。

所以，如果我们要像之前一样记录日志并且自己定制日志的格式，我们必须在 wsgi 模块中这样写：

from flask import Flask
import logging
from logging.handlers import RotatingFileHandler

app = Flase(__name__)
log_file = 'foo.log'

handler = RotatingFileHandler(log_file, maxBytes=1024 * 1024, backupCount=5)
fmt = '%(asctime)s - %(filename)s:%(lineno)s - func: [%(name)s] - %(message)s'
formatter = logging.Formatter(fmt)
handler.setFormatter(formatter)

app.logger.addHandler(handler)
app.logger.setLevel(logging.DEBUG)
# app.debug=True

注意最后一行，因为 gunicorn 只是从 wsgi 模块中导入了 app，然后自己执行定制的 app.run()。如果我们需要在日志文件中看到 DEBUG 级别的信息，可以通过 app.debug 手动指定开启 DEBUG 模式，这样我们才能看到 DEBUG 级别的日志。

app.debug=True 与 app.run(debug=True) 是等价的，因为查看源码发现：

def run(self, host=None, port=None, debug=None, **options):
    # 省略...
    if debug is not None:
        self.debug = bool(debug)
    # 省略...

不过开启后就失去了定制格式的意义。因为我们之所以定制日志格式，是为了将自己故意产生的日志与应用运行的日志隔离存放。而开启 DEBUG 模式的话，两个日志文件就基本一样了，定制的意义就凸显不出来。而且在部署环境我们也不应该开启 DEBUG 模式。

参考链接

Python 3.6.3 Documentation RatetingFileHandler
GitHubGist from ibeex Flask logging example