虚無ありき

うるせーーーしらねーーー

Flask の logging 設定

Logging Python Flask

tl;dl

環境

これも一緒

$ cat /etc/os-release
NAME="Alpine Linux"
ID=alpine
VERSION_ID=3.8.2
PRETTY_NAME="Alpine Linux v3.8"
HOME_URL="http://alpinelinux.org"
BUG_REPORT_URL="http://bugs.alpinelinux.org"
$ python -V
Python 3.7.2
$ django-admin version
2.1.5

Flask の Logging の初期設定

下のコードで、Flask インスタンス作成時の Logger を調べると、

# coding: utf-8
import logging
from pprint import pprint

from flask import Flask

if __name__ == "__main__":
    app = Flask(__name__)
    pprint(logging.root.manager.loggerDict)

{'asyncio': <Logger asyncio (WARNING)>,
 'concurrent': <logging.PlaceHolder object at 0x7f71fe7bb550>,
 'concurrent.futures': <Logger concurrent.futures (WARNING)>}

であり、Flask で生成される Logger は存在しない。

ただ、上の Docs より、

from logging.config import dictConfig

dictConfig({
    'version': 1,
    'formatters': {'default': {
        'format': '[%(asctime)s] %(levelname)s in %(module)s: %(message)s',
    }},
    'handlers': {'wsgi': {
        'class': 'logging.StreamHandler',
        'stream': 'ext://flask.logging.wsgi_errors_stream',
        'formatter': 'default'
    }},
    'root': {
        'level': 'INFO',
        'handlers': ['wsgi']
    }
})

app = Flask(__name__)

であることから、Flask は root logger に色々吐いているようだ。

# coding: utf-8
import logging
from pprint import pprint

from flask import Flask

if __name__ == "__main__":
    app = Flask(__name__)
    pprint(vars(logging.getLogger()))

{'_cache': {},
 'disabled': False,
 'filters': [],
 'handlers': [],
 'level': 30,
 'name': 'root',
 'parent': None,
 'propagate': True}

ここでは、handler は登録されていないが、root logger は console に出力する。

$ python3
Python 3.7.2 (default, Jan 30 2019, 23:40:31)
[GCC 6.4.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import logging
>>> root = logging.getLogger()
>>> root.warning("FUGA")
FUGA

どうしたか

logging_config.py を作って以下を記述する。この際、root は handlers の中に入れず、別エントリを作る

# coding: utf-8
from .config import LOG_FILE_PATH
from copy import deepcopy


TEMPLATE = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "default": {
            "format": "[%(asctime)s] %(levelname)s %(message)s",
            "datefmt": "%Y-%m-%d %H:%M:%S",
        },
        "long": {
            "format": "[%(asctime)s] %(levelname)s - %(filename)s#%(funcName)s:%(lineno)d: %(message)s",
            "datefmt": "%Y-%m-%d %H:%M:%S",
        },
    },
    "handlers": {
        "console": {
            "level": "INFO",
            "class": "logging.StreamHandler",
            "formatter": "default",
            "stream": "ext://sys.stderr"
        },
        "file": {
            "level": "INFO",
            "class": "logging.FileHandler",
            "formatter": "default",
            "filename": LOG_FILE_PATH,
        },
    },
    "root": {
        "handlers": ["console", "file"],
        "level": "INFO",
    },
}

wsgi_info = deepcopy(TEMPLATE)
wsgi_info["root"]["handlers"] = ["file"]
wsgi_debug = deepcopy(TEMPLATE)
wsgi_debug["handlers"]["file"]["level"] = "DEBUG"
wsgi_debug["handlers"]["file"]["formatter"] = "long"
wsgi_debug["root"]["handlers"] = ["file"]
wsgi_debug["root"]["level"] = "DEBUG"

local_info = deepcopy(TEMPLATE)
local_debug = deepcopy(TEMPLATE)
local_debug["handlers"]["console"]["level"] = "DEBUG"
local_debug["handlers"]["console"]["formatter"] = "long"
local_debug["handlers"]["file"]["level"] = "DEBUG"
local_debug["handlers"]["file"]["formatter"] = "long"
local_debug["root"]["level"] = "DEBUG"

Flask インスタンスを作成後に、logger を更新する。

# coding: utf-8
import logging
from pprint import pprint
import os

from flask import Flask

if __name__ == "__main__":
    app = Flask(__name__)
    if os.environ.get("DEBUG") == "True":
        if os.environ.get("LOG_LEVEL") == "DEBUG":
            dictConfig(local_debug)
        else:
            dictConfig(local_info)
    else:
        if os.environ.get("LOG_LEVEL") == "DEBUG":
            dictConfig(wsgi_debug)
        else:
            dictConfig(wsgi_info)

更に、Flask は Debug mode の場合、ブラウザで debug するための html が response で帰ってくる。また、log には traceback の情報が残らない仕様になっている。そのため、Error Handler を編集する。

@app.errorhandler(400)
@app.errorhandler(401)
@app.errorhandler(404)
@app.errorhandler(500)
def error_handler(error):
    response = {
        "msg": error.description,
        "status_code": error.code,
    }
    response = jsonify(response)
    response.status_code = error.code
    return response

@app.errorhandler(Exception)
def error_handler_exception(exception):
    import traceback
    root_logger.error(exception.args[0])
    root_logger.debug(traceback.format_exc())
    response = {
        "msg": "The server encountered an internal error and was unable to complete your request.",
        "status_code": 500,
    }
    response = jsonify(response)
    response.status_code = 500
    return response

return app

上を使うことで、DEBUG レベルの log として、traceback が出力されるようになる。