細かい事をあんまり気にしない感じのPython Logging

# はじめに

pythonの`logging`を使っていましたが大規模なプログラムを作っていなかったり、業務で使っていなかったりと適当に使っていました。
今までの使い方でも大きな支障なかったのですが、`RotatingFileHandler`でログファイルを循環されている自作プログラムにおいて循環時に例外が発生するのだけは気になっていました。
自作プログラムの更新作業に伴ってそこら辺の勉強をしてみたので記事にしてみます。

# 対象読者

`logging`の初心者で、日本語で説明されるよりもソースを見せろって方を対象にした感じです。
`logging`モジュールの詳しい使い方は、記述しません。
色々検証した結果、初心者向けでないようなプログラムになっていますが、まあ細かいことは...

# 環境

Python 3.7.3
(更新しないと)

# ファイル構成

- main.py: メインモジュール。module1, module2を使う
- loggerHelper.py: `logging`のための補助関数群 。
- module1.py: mainから使われるモジュール。module2を使う。
- module2.py: main, module1から使われるモジュール。
- loggingConfig.py: 辞書形式で環境設定を記述しているモジュール。

# ソース

## loggerHelper.py

loggerHelperで、`handler`を設定するための関数などを定義しています。
これはPythonドキュメントをご覧になれば理解できるかと思います。

```python:loggerHelper.py
import logging
import logging.handlers
import sys


class LevelFilter(logging.Filter):  # 特定levelだけを通過させるフィルタ
  def __init__(self, level=logging.INFO):
    super().__init__()
    self.level = level

  def filter(self, record):
    if record.levelno != self.level:
      return False  # Falseを返すとrecordの走査が止まるので見つけ次第Falseを返すと良い
    return True


def getConsoleHandler(level=logging.DEBUG,
                      format="{asctime} - {name:<30} - {levelname:<8} - {message}",
                      dateFormat="%H:%M:%S",
                      style="{",
                      stream=sys.stdout,  # sys.stderr
                      ):
  handler = logging.StreamHandler(stream)
  handler.setLevel(level)
  formatter = logging.Formatter(format, datefmt=dateFormat, style=style)
  handler.setFormatter(formatter)
  return handler


def getRotaingFileHandler(level=logging.DEBUG,
                          # format="{asctime} - {name:<30} - {levelname:<8} - {module} - {lineno} - {funcName} - {message}",
                          format="{asctime} - {name:<30} - {levelname:<8} - {message}",
                          dateFormat="%H:%M:%S",
                          style="{",
                          filename="log.txt", mode="a", maxBytes=1024 * 10, backupCount=2, encoding="utf-8", delay=False):
  handler = logging.handlers.RotatingFileHandler(
      filename, mode=mode, maxBytes=maxBytes, backupCount=backupCount, encoding=encoding, delay=delay)
  handler.setLevel(level)
  formatter = logging.Formatter(format, datefmt=dateFormat, style=style)
  handler.setFormatter(formatter)
  return handler


def addHandlers(logger, handlers=[logging.NullHandler()]):
  for handler in handlers:
    logger.addHandler(handler)


def output(logger, message):
  logger.debug(message)
  logger.info(message)
  logger.warning(message)
  logger.error(message)
  logger.critical(message)

```

## module2.py

module2.pyは、他のモジュールから呼ばれるだけのモジュールです。
モジュールグローバル`logger`(module2)、クラス`logger`(module2.C)、インスタンス`logger`(module2.C.XXXX)を作成します。
`logger`の名前をピリオドで連結したものにすると親子と見なされます。
この場合、
親: module2 -> module2.C -> module2.C.XXXX :子
となります。
このモジュールのログを取りたい場合は、mainモジュールで`handler`と`level`を設定する必要があります。

```python:module2.py
import time
import logging
import loggerHelper

moduleLogger = logging.getLogger(__name__)
moduleLogger.addHandler(logging.NullHandler())


class C():
  classLogger = logging.getLogger(f"{__name__}.C")
  classLogger.addHandler(logging.NullHandler())

  def __init__(self):
    self.logger = logging.getLogger(f"{__name__}.C.{self.__hash__():X}")
    self.logger.setLevel(logging.NOTSET)
    self.logger.addHandler(logging.NullHandler())

  def addHandlers(self, handlers=[logging.NullHandler()]):
    for handler in handlers:
      self.logger.addHandler(handler)

  def setLevel(self, level=logging.NOTSET):
    self.logger.setLevel(level)

  def output(self, message=""):
    loggerHelper.output(self.logger, f"*at m2: method: {message}")

  @classmethod
  def clsAddHandlers(cls, handlers=[logging.NullHandler()]):
    for handler in handlers:
      cls.classLogger.addHandler(handler)

  @classmethod
  def clsSetLevel(cls, level=logging.NOTSET):
    cls.classLogger.setLevel(level)

  @classmethod
  def clsOutput(cls, message=""):
    loggerHelper.output(cls.classLogger, f"*at m2: classMethod: {message}")


def output(message):
  c2 = C()
  for i in range(1):
    loggerHelper.output(moduleLogger, f"*at m2: func: {i}: {message}")
    msg = f"#from m2: {i}"
    C.clsOutput(msg)
    c2.output(msg)
    time.sleep(0.5)
```

ベストプラクティスなどに書いてありますが重要な事は、`logger`を用意するが`handler`や`level`を設定しないことです。
こうすることで呼び出し側は、出力先と出力レベルを好きに決める事が出来ます。
また、`logging.NullHandler`をデフォルト`handler`として設定しているのは、`handler`を設定し忘れた場合に何も出力させないためです。
設定し忘れると`sys.stderr`に`WARNING`以上のメッセージが出力されてしまうからです。

わざわざそんな事をする必要があるか分かりませんが、クラスのインスタンスごとに別の`logger`を用意したい場合は、別の名前を付ける必要があります。
`logging.getLogger()`は、同じ名前の場合に同じインスタンスを返します。
そのため、例えば以下のように固定の名前にしてしまうとすべてのインスタンスで同じ`logger`を使うことになります。(この例では、module2のグローバル`logger`を使うことになる)

```python
  def __init__(self):
    self.logger = logging.getLogger(f"{__name__}")
```

もっとも、多くの場合は、モジュールグローバル`logger`もクラス`logger`もインスタンス`logger`も同じ1つのloggerを使えば良いとは思います。
もしくは、モジュールグローバル`logger`とクラス`logger`の2つを用意すれば良いと思います。



## module1.py

module1.pyは、module2.pyとほとんど同じです。
違うところは、関数からmodule2を使用していることです。

```python:module1.py
import time
import logging
import loggerHelper
import module2

moduleLogger = logging.getLogger(__name__)
moduleLogger.addHandler(logging.NullHandler())  # 呼び出し側がloggerを設定しなくても警告等を出さないようにするため


class C():
  classLogger = logging.getLogger(f"{__name__}.C")
  classLogger.addHandler(logging.NullHandler())

  def __init__(self):
    self.logger = logging.getLogger(f"{__name__}.C.{self.__hash__():X}")
    self.logger.setLevel(logging.NOTSET)
    self.logger.addHandler(logging.NullHandler())

  def addHandlers(self, handlers=[logging.NullHandler()]):
    for handler in handlers:
      self.logger.addHandler(handler)

  def setLevel(self, level=logging.NOTSET):
    self.logger.setLevel(level)

  def output(self, message=""):
    loggerHelper.output(self.logger, f"*at m1: method: {message}")

  @classmethod
  def clsAddHandlers(cls, handlers=[logging.NullHandler()]):
    for handler in handlers:
      cls.classLogger.addHandler(handler)

  @classmethod
  def clsSetLevel(cls, level=logging.NOTSET):
    cls.classLogger.setLevel(level)

  @classmethod
  def clsOutput(cls, message=""):
    loggerHelper.output(cls.classLogger, f"*at m1: classMethod: {message}")


def output(message):
  c1 = C()
  c2 = module2.C()
  for i in range(1):
    loggerHelper.output(moduleLogger, f"*at m1: func: {i}: {message}")
    msg = f"#from m1: {i}"
    C.clsOutput(msg)
    c1.output(msg)
    module2.output(msg)
    module2.C.clsOutput(msg)
    c2.output(msg)
    time.sleep(0.5)

```

## main.py

mainでは、`logging.config.dictConfig()`を使い環境設定を行いそれぞれのモジュールを使用しています。

```python:main.py
import logging
import logging.handlers
import logging.config
import time

import module1
import module2
import loggerHelper
import loggerConfig

if __name__ == "__main__":

  logger = logging.getLogger(__name__)
  logging.config.dictConfig(loggerConfig.config)
  c1 = module1.C()
  c2 = module2.C()

  for i in range(2):
    message1 = f"*at main: {i}"
    message2 = f"#from main: {i}"
    loggerHelper.output(logger, message1)
    module1.C.clsOutput(message2)
    c1.output(message2)
    module1.output(message2)
    module2.C.clsOutput(message2)
    c2.output(message2)
    module2.output(message2)
    time.sleep(0.5)

```

## loogerConfig.py

ここでは、

- `formatter`
 - normal: 簡易表示用`formatter`
 - detail: 詳細表示用`formatter`
- `filter`
  - level: 特定`level`(`INFO`)のメッセージしか通さないカスタム`filter`
- `handler`
  - null: 何もしない`handler`。不使用
  - console: 標準出力への`handler`
  - fileAll: 全てのメッセージをファイル(logAll.log)へ出力する`handler`
  - fileModule1: module1で発生したメッセージをファイル(logModule1.log)へ出力する`handler`
  - fileModule2: module2で発生したメッセージをファイル(logModule2.log)へ出力する`handler`
  - fileClass: module1とmodule2のクラスから発生したメッセージをファイル(logClass.log)へ出力する`handler`
- `logger`
  - \_\_main\_\_: main用`logger`
  - module1.moduleLogger.name(module1): module1用`logger`
  - module1.C.classLogger.name(module1.C): module1のクラス用`logger`
  - module2.moduleLogger.name(module2): module2`logger`
  - module2.C.classLogger.name(module2.C): module2のクラス用`logger`

の設定を辞書形式で記述しています。
環境設定は、`logging.config.dictConfig`によって設定します。
`logging.config.fileConfig`は、古いAPIで機能が劣り将来の機能拡張が見込めないような事が書いてあるので避ける事とします。

```python:loggerConfig.py
import logging
import logging.handlers

import module1
import module2
import loggerHelper

config = {
    "version": 1,
    "formatters": {
        "normal": {
            "class": "logging.Formatter",
            "format": "{asctime} - {name:<30} - {levelname:<8} - {message}",
            "datefmt": "%H:%M:%S",
            "style": "{",
        },
        "detail": {
            "class": "logging.Formatter",
            "format": "{asctime} - {name:<30} - {levelname:<8} - {module} - {lineno} - {funcName} - {message}",
            "datefmt": "%H:%M:%S",
            "style": "{",
        },
    },
    "filters": {
        "level": {
            "()": "loggerHelper.LevelFilter", # ()は明示的にインスタンス化する。インスタンス変数で制御しているので必要
            "level": logging.INFO,  # int
        },
    },
    "handlers": {
        "null": {
            "class": "logging.NullHandler",
            "level": "DEBUG",  # logging.DEBUG も可能
        },
        "console": {
            "class": "logging.StreamHandler",
            "level": "INFO",
            "formatter": "normal",
            "filters": ["level"],
        },
        "fileAll": {
            "class": "logging.handlers.RotatingFileHandler",
            "level": "DEBUG",
            "formatter": "detail",
            "filename": "logAll.log",
            "maxBytes": 1024 * 10,
            "backupCount": 2,
            "encoding": "utf-8",
        },
        "fileModule1": {
            "class": "logging.handlers.RotatingFileHandler",
            "level": "WARNING",
            "formatter": "detail",
            "filename": "logModule1.log",
            "maxBytes": 1024 * 10,
            "backupCount": 2,
            "encoding": "utf-8",
        },
        "fileModule2": {
            "class": "logging.handlers.RotatingFileHandler",
            "level": "WARNING",
            "formatter": "detail",
            "filename": "logModule2.log",
            "maxBytes": 1024 * 10,
            "backupCount": 2,
            "encoding": "utf-8",
        },
        "fileClass": {
            "class": "logging.handlers.RotatingFileHandler",
            "level": "CRITICAL",
            "formatter": "detail",
            "filename": "logClass.log",
            "maxBytes": 1024 * 10,
            "backupCount": 2,
            "encoding": "utf-8",
        },
    },
    "loggers": {
        "__main__": {
            "handlers": ["console", "fileAll"],
            "level": logging.DEBUG, # "DEBUG" も可能
        },
        module1.moduleLogger.name: { # module1
            "handlers": ["console", "fileAll", "fileModule1"],
            "level": logging.DEBUG,
        },
        module1.C.classLogger.name: { # module1.C(module1 loggerの子)
            "handlers": ["fileClass"],
            "level": logging.DEBUG,
            "propagate": True # Trueならば親のLoggerにもメッセージが渡される。つまり追加のhandlerだけを記述する。
        }, # インスタンスの出力は親のhandlerに任せる
        module2.moduleLogger.name: { # module2
            "handlers": ["console", "fileAll", "fileModule2"],
            "level": logging.DEBUG,
        },
        module2.C.classLogger.name: { # module2.C(module2 loggerの子)
            "handlers": ["console", "fileAll", "fileModule2", "fileClass"],
            "level": logging.DEBUG,
            "propagate": False # Falseならば親のLoggerにメッセージが渡されない。そのため全てのhandlerを記述する。
        },
    },
}

```

異なった`logger`から`RotatingFileHandler`を使って同じファイルに出力したい場合は、同じ`handler`を使用してください。
そうしないとファイルの切り替え時に例外(`PermissionError`)が発生してしまいます。

`filter`と`level`によるフィルタリングは、初めに`logger`でフィルタリングされ、その後に`handler`でフィルタリングされます。
つまり、`logger`の`level`を`CRITICAL`にすると`handler`の`level`を`INFO`にしても`CRITICAL`のメッセージしか出力されません。

`logger`の`propagate`が`True`(デフォルトで`True`)の場合、子の`logger`で発生した全てのメッセージが親の`handler`にも渡されます。
そのため、通常は親に設定した`handler`を子に設定する必要はありません。
子の`propagate`が`True`の場合に、親と子に同じ`handler`を設定していると、子で発生したメッセージが2回出力される事になってしまいます。

この記事では、module1とmodule2のクラスのインスタンス`logger`に`handler`を設定していません。
それでもメッセージが出力されるのは子のメッセージが親の`handler`に渡されているからです。
インスタンス`logger`に個別の`handler`を設定したい場合は、汎用性などを考えなければいくらでもやりようがあると思いますが、`logging.config.dictConfig`を使用してあらかじめ決めておくのは難しそうです。

# 動作結果

## 標準出力(抜粋)

標準出力には、以下のようなメッセージが出力されます。
特筆すべき点は、

 - 全ての`logger`からメッセージが渡される。
 - カスタム`filter`によりINFOメッセージしか表示されない。
 - `formatter`により簡易表示にされる。

となります。

```text:console
02:04:59 - __main__                       - INFO     - *at main: 0
02:22:47 - __main__                       - INFO     - *at main: 0
02:22:47 - module1.C                      - INFO     - *at m1: classMethod: #from main: 0
02:22:47 - module1.C.13923A959B           - INFO     - *at m1: method: #from main: 0
02:22:47 - module1                        - INFO     - *at m1: func: 0: #from main: 0
02:22:47 - module1.C                      - INFO     - *at m1: classMethod: #from m1: 0
02:22:47 - module1.C.-7FFFFFEC6DC565AF    - INFO     - *at m1: method: #from m1: 0
02:22:47 - module2                        - INFO     - *at m2: func: 0: #from m1: 0
02:22:47 - module2.C                      - INFO     - *at m2: classMethod: #from m2: 0
02:22:47 - module2.C.-7FFFFFEC6DC5659A    - INFO     - *at m2: method: #from m2: 0
02:22:48 - module2.C                      - INFO     - *at m2: classMethod: #from m1: 0
02:22:48 - module2.C.13923A9A5C           - INFO     - *at m2: method: #from m1: 0
02:22:48 - module2.C                      - INFO     - *at m2: classMethod: #from main: 0
02:22:48 - module2.C.13923A9A08           - INFO     - *at m2: method: #from main: 0
02:22:49 - module2                        - INFO     - *at m2: func: 0: #from main: 0
02:22:49 - module2.C                      - INFO     - *at m2: classMethod: #from m2: 0
02:22:49 - module2.C.13923A9A5C           - INFO     - *at m2: method: #from m2: 0
02:22:50 - __main__                       - INFO     - *at main: 1
02:22:50 - module1.C                      - INFO     - *at m1: classMethod: #from main: 1
```

## logAll.log(抜粋)

logAll.logには、以下のようなメッセージが出力されます。
特筆すべき点は、

- 全ての`logger`からメッセージが渡される。
- 全ての`level`が表示される。
- `formatter`により詳細表示にされる。
- ファイルサイズが`MaxBytes`を超えるために、logAll.log.1が作られる

となります。

```text:logAll.log
02:22:50 - module1.C                      - CRITICAL - loggerHelper - 54 - output - *at m1: classMethod: #from main: 1
02:22:50 - module1.C.13923A959B           - DEBUG    - loggerHelper - 50 - output - *at m1: method: #from main: 1
02:22:50 - module1.C.13923A959B           - INFO     - loggerHelper - 51 - output - *at m1: method: #from main: 1
02:22:50 - module1.C.13923A959B           - WARNING  - loggerHelper - 52 - output - *at m1: method: #from main: 1
02:22:50 - module1.C.13923A959B           - ERROR    - loggerHelper - 53 - output - *at m1: method: #from main: 1
02:22:50 - module1.C.13923A959B           - CRITICAL - loggerHelper - 54 - output - *at m1: method: #from main: 1
02:22:50 - module1                        - DEBUG    - loggerHelper - 50 - output - *at m1: func: 0: #from main: 1
02:22:50 - module1                        - INFO     - loggerHelper - 51 - output - *at m1: func: 0: #from main: 1
02:22:50 - module1                        - WARNING  - loggerHelper - 52 - output - *at m1: func: 0: #from main: 1
02:22:50 - module1                        - ERROR    - loggerHelper - 53 - output - *at m1: func: 0: #from main: 1
02:22:50 - module1                        - CRITICAL - loggerHelper - 54 - output - *at m1: func: 0: #from main: 1
02:22:50 - module1.C                      - DEBUG    - loggerHelper - 50 - output - *at m1: classMethod: #from m1: 0
02:22:50 - module1.C                      - INFO     - loggerHelper - 51 - output - *at m1: classMethod: #from m1: 0
02:22:50 - module1.C                      - WARNING  - loggerHelper - 52 - output - *at m1: classMethod: #from m1: 0
02:22:50 - module1.C                      - ERROR    - loggerHelper - 53 - output - *at m1: classMethod: #from m1: 0
02:22:50 - module1.C                      - CRITICAL - loggerHelper - 54 - output - *at m1: classMethod: #from m1: 0
```

## logModule1.log(抜粋)

logModule1.logには、以下のようなメッセージが出力されます。
特筆すべき点は、

- module1から発生した全てのメッセージが渡される。
- `handler`の`level`により`WARNING`以上のメッセージのみが表示される。
- `formatter`により詳細表示にされる。

となります。

```text:logModule1.log
02:04:59 - module1.C                      - WARNING  - loggerHelper - 52 - output - *at m1: classMethod: *from main: 0
02:04:59 - module1.C                      - ERROR    - loggerHelper - 53 - output - *at m1: classMethod: *from main: 0
02:04:59 - module1.C                      - CRITICAL - loggerHelper - 54 - output - *at m1: classMethod: *from main: 0
02:04:59 - module1.C.-7FFFFFE5DFC5ECA8    - WARNING  - loggerHelper - 52 - output - *at m1: method: *from main: 0
02:04:59 - module1.C.-7FFFFFE5DFC5ECA8    - ERROR    - loggerHelper - 53 - output - *at m1: method: *from main: 0
02:04:59 - module1.C.-7FFFFFE5DFC5ECA8    - CRITICAL - loggerHelper - 54 - output - *at m1: method: *from main: 0
02:04:59 - module1                        - WARNING  - loggerHelper - 52 - output - *at m1: func: 0: *from main: 0
02:04:59 - module1                        - ERROR    - loggerHelper - 53 - output - *at m1: func: 0: *from main: 0
02:04:59 - module1                        - CRITICAL - loggerHelper - 54 - output - *at m1: func: 0: *from main: 0
02:04:59 - module1.C                      - WARNING  - loggerHelper - 52 - output - *at m1: classMethod: *#from m1: 0
02:04:59 - module1.C                      - ERROR    - loggerHelper - 53 - output - *at m1: classMethod: *#from m1: 0
02:04:59 - module1.C                      - CRITICAL - loggerHelper - 54 - output - *at m1: classMethod: *#from m1: 0
02:04:59 - module1.C.-7FFFFFE5DFC59CB6    - WARNING  - loggerHelper - 52 - output - *at m1: method: *#from m1: 0
02:04:59 - module1.C.-7FFFFFE5DFC59CB6    - ERROR    - loggerHelper - 53 - output - *at m1: method: *#from m1: 0
02:04:59 - module1.C.-7FFFFFE5DFC59CB6    - CRITICAL - loggerHelper - 54 - output - *at m1: method: *#from m1: 0
02:05:01 - module1.C                      - WARNING  - loggerHelper - 52 - output - *at m1: classMethod: *from main: 1
02:05:01 - module1.C                      - ERROR    - loggerHelper - 53 - output - *at m1: classMethod: *from main: 1
02:05:01 - module1.C                      - CRITICAL - loggerHelper - 54 - output - *at m1: classMethod: *from main: 1
```

## logModule2.log(省略)

logModule2.logは、省略します。

## logClass.log

logClass.logには、以下のようなメッセージが出力されます。
特筆すべき点は、

- module1のクラスとmodule2のクラスから発生した全てのメッセージが渡される。
- `handler`の`level`により`CRITICAL`のメッセージのみが表示される。
- `formatter`により詳細表示にされる。

となります。

```text:logClass.log
02:22:47 - module1.C                      - CRITICAL - loggerHelper - 54 - output - *at m1: classMethod: #from main: 0
02:22:47 - module1.C.13923A959B           - CRITICAL - loggerHelper - 54 - output - *at m1: method: #from main: 0
02:22:47 - module1.C                      - CRITICAL - loggerHelper - 54 - output - *at m1: classMethod: #from m1: 0
02:22:47 - module1.C.-7FFFFFEC6DC565AF    - CRITICAL - loggerHelper - 54 - output - *at m1: method: #from m1: 0
02:22:47 - module2.C                      - CRITICAL - loggerHelper - 54 - output - *at m2: classMethod: #from m2: 0
02:22:47 - module2.C.-7FFFFFEC6DC5659A    - CRITICAL - loggerHelper - 54 - output - *at m2: method: #from m2: 0
02:22:48 - module2.C                      - CRITICAL - loggerHelper - 54 - output - *at m2: classMethod: #from m1: 0
02:22:48 - module2.C.13923A9A5C           - CRITICAL - loggerHelper - 54 - output - *at m2: method: #from m1: 0
02:22:48 - module2.C                      - CRITICAL - loggerHelper - 54 - output - *at m2: classMethod: #from main: 0
02:22:49 - module2.C.13923A9A08           - CRITICAL - loggerHelper - 54 - output - *at m2: method: #from main: 0
02:22:49 - module2.C                      - CRITICAL - loggerHelper - 54 - output - *at m2: classMethod: #from m2: 0
02:22:49 - module2.C.13923A9A5C           - CRITICAL - loggerHelper - 54 - output - *at m2: method: #from m2: 0
02:22:50 - module1.C                      - CRITICAL - loggerHelper - 54 - output - *at m1: classMethod: #from main: 1
02:22:50 - module1.C.13923A959B           - CRITICAL - loggerHelper - 54 - output - *at m1: method: #from main: 1
02:22:50 - module1.C                      - CRITICAL - loggerHelper - 54 - output - *at m1: classMethod: #from m1: 0
02:22:50 - module1.C.13923A9A5C           - CRITICAL - loggerHelper - 54 - output - *at m1: method: #from m1: 0
02:22:50 - module2.C                      - CRITICAL - loggerHelper - 54 - output - *at m2: classMethod: #from m2: 0
02:22:50 - module2.C.13923A9A7F           - CRITICAL - loggerHelper - 54 - output - *at m2: method: #from m2: 0
02:22:50 - module2.C                      - CRITICAL - loggerHelper - 54 - output - *at m2: classMethod: #from m1: 0
02:22:50 - module2.C.13923A9A71           - CRITICAL - loggerHelper - 54 - output - *at m2: method: #from m1: 0
02:22:51 - module2.C                      - CRITICAL - loggerHelper - 54 - output - *at m2: classMethod: #from main: 1
02:22:51 - module2.C.13923A9A08           - CRITICAL - loggerHelper - 54 - output - *at m2: method: #from main: 1
02:22:51 - module2.C                      - CRITICAL - loggerHelper - 54 - output - *at m2: classMethod: #from m2: 0
02:22:51 - module2.C.13923A9A71           - CRITICAL - loggerHelper - 54 - output - *at m2: method: #from m2: 0
```

# 最後に

自分が気になっていた点を凝縮して記述しました。
そのため、良く分からないような構成になってしまったかもしれません。
しかし、個人的には、`logging`への理解が深まり大分楽になりました。
皆様の役にも立てばよいのですが(´・ω・`)

---

# 付録

## main.py `logging.config.dictConfig`不使用版

`logging.config.dictConfig`を使用しないで同等な動作を実現したい場合は、以下のようになります。

```python:main.py
import logging
import logging.handlers
import logging.config
import time

import module1
import module2
import loggerHelper
import loggerConfig

if __name__ == "__main__":

  console = loggerHelper.getConsoleHandler(level=logging.INFO)
  console.addFilter(loggerHelper.LevelFilter(logging.INFO))
  fileAll = loggerHelper.getRotaingFileHandler(filename="logAll_.log", level=logging.DEBUG)
  fileModule1 = loggerHelper.getRotaingFileHandler(filename="logModule1_.log", level=logging.WARNING)
  fileModule2 = loggerHelper.getRotaingFileHandler(filename="logModule2_.log", level=logging.WARNING)
  fileClass = loggerHelper.getRotaingFileHandler(filename="logClass_.log", level=logging.CRITICAL)

  logger = logging.getLogger(__name__)
  logger.setLevel(logging.DEBUG)
  loggerHelper.addHandlers(logger, [console, fileAll])

  module1.moduleLogger.setLevel(logging.DEBUG)
  loggerHelper.addHandlers(module1.moduleLogger, [console, fileAll, fileModule1])
  module1.C.clsSetLevel(logging.DEBUG)
  module1.C.clsAddHandlers([fileClass])

  module2.moduleLogger.setLevel(logging.DEBUG)
  loggerHelper.addHandlers(module2.moduleLogger, [console, fileAll, fileModule2])
  module2.C.clsSetLevel(logging.DEBUG)
  module2.C.clsAddHandlers([fileClass])

  c1 = module1.C()
  c2 = module2.C()

  for i in range(2):
    message1 = f"*at main: {i}"
    message2 = f"#from main: {i}"
    loggerHelper.output(logger, message1)
    module1.C.clsOutput(message2)
    c1.output(message2)
    module1.output(message2)
    module2.C.clsOutput(message2)
    c2.output(message2)
    module2.output(message2)
    time.sleep(0.5)

```

## フィルタリングの流れ

![logging.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/194349/14c384cb-a513-52b2-6e23-e90fe509e451.png)

### 図のPlantUML

```.puml:plantUML
@startuml
title  "logging Filter"
start
:message;
:Logger;
if (logger level?) then (true)
  :Logger Filter;
  if (Logger Filter) then (true)
    :Handler;
    if (Handler level?) then (ture)
      :Handler Filter;
      if (Handler filter?) then (true)
        :output;
      else (false)
        -[#blue]->
        stop
      endif
    else (false)
      -[#blue]->
      stop
    endif
  else (false)
    -[#blue]->
    stop
  endif
else (false)
  -[#blue]->
  stop
endif
end
@enduml
```