Pythonのロギング標準ライブラリでファイル出力をログレベル毎にする

#背景
・Pythonでログレベル毎にログファイルを分けたいという話があった。
・そもそもloggingライブラリをやっつけで使っていてきちんと理解していなかった。

では、手を動かして整理しつつ課題を解決してみよう。

#おさらい

import logging

logging.basicConfig(format='%(asctime)s   %(message)s', datefmt='%m/%d/%Y', filename = './basic.log')
logging.warning('basic.logに日付と共に記録される。')
logging.basicConfig(filename = './not-appeared.log')
logging.warning('basicConfigは起動後最初の一回しか機能しないので、not-appeared.logは生成されない。')

root_logger = logging.getLogger('')
root_logger.setLevel(logging.ERROR)
root_logger.error('ERROR レベル以上を記録するroot loggerが設定された。basic.logには引き続き現れる。ハンドラーを指定していないので、他には出ない。')

root_logger.addHandler(logging.StreamHandler())

root_logger.error('これでコンソールに現れる。basicConfigで指定したフォーマットは無視される。')
root_logger.warning('ログレベルが低いのでコンソールには出ない。無視されたらbasic.logにも出ない。')

critical_handler = logging.FileHandler('./critical.log')
critical_handler.setLevel(logging.CRITICAL)
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
critical_handler.setFormatter(formatter)
root_logger.addHandler(critical_handler)

root_logger.critical('CRITICALのみ記録するハンドラーを追加。日付やレベル名も追加。')
root_logger.error('こちらはコンソールに出るものの、ログレベルが低いのでcritical.logには出ない。')

second_logger = logging.getLogger('second')
second_logger.setLevel(logging.WARNING)
second_logger.addHandler(logging.StreamHandler())

second_logger.warning('ロガーを追加してコンソールに出すように。basic.logに加え、rootロガーとこれでコンソールに二度出る。')

second_logger.propagate = False

second_logger.warning('propagateを否にすると上流には伝わらなくなり、こちらはsecond_loggerの一回分しか出ない。')

#ふりかえりと検討
・ルートロガーを元に多段階に継承できる。
・それぞれにハンドラーを複数設定できる。
・ロガーとハンドラーにはそれぞれログレベルを設定できる。
・但しいずれも下方の閾値なので、要件のように特定のログのみフィルタリングする事は出来ない。

#解法
フィルターを使えば、ロギングの都度ログレコード(ログメッセージのインスタンス)を引数に呼ばれて真偽値を返す事でフィルタリング出来る。

こちらのStackOverflowの投稿を参考にした。#1の方の言うように、特定のレベルだけ抜き出しても、人間が読めるようなものにはならないというのは同意するけど。

python logging specific level only

log_file_by_level.py

import logging

class LoggingFilter(object):
    """特定のログレベルのみ残すフィルター"""
    def __init__(self, level):
        self.__level = level

    def filter(self, logRecord):
        #handlerへのレベル設定を外してここは== self.__levelとするのでも可のはず。
        return logRecord.levelno <= self.__level

def set_handler(loglevel, filename):
    #共通のログフォーマット
    log_format = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s', datefmt='%Y-%m-%d %H:%M:%S')
    handler = logging.FileHandler(filename)
    handler.setLevel(loglevel)
    handler.setFormatter(log_format)
    handler.addFilter(LoggingFilter(loglevel))
    logger.addHandler(handler)

logger = logging.getLogger(__name__)
#アプリで記録すべき最低限のレベルを指定。
logger.setLevel(logging.DEBUG)
set_handler(logging.WARN, './warning.log')
set_handler(logging.INFO, './info.log')

main.py

from log_file_by_level import logger

logger.warning('I warn you.')
logger.info('Please be informed that this is just a test.')
logger.error('Found error on your smile.')

#参考
・python logging specific level only
・Logging HOWTO — Python 3.6.1 ドキュメント