---
# System prepended metadata

title: Python Logging
tags: [' logging', Python]

---

---
lang: ja-jp
tags: Python, logging
title: Python Logging
---
# Python Logging

## Overview
Pythonのログ機構は、Loggerのメソッドを呼び出すことにより成り立っている。
`logging.info()`のような関数の呼出しを行うときも、ルートロガーと呼ばれるLoggerの同じシグネチャを持つメソッドを呼出している。

Loggerどうしは木構造の関係性（親と子）を持ち、その関係性は**名前空間階層構造**により制御されている。命名規則は、`foo.bar`のようにロガーの名前を`.`で連結する。

### デフォルトのログレベル
入力は次の通り：
```python=
import logging

if __name__ == '__main__':
    logging.critical('critical')
    logging.error('error')
    logging.warning('warning')
    logging.info('info')
    logging.debug('debug')
```
対する出力は次のようになる：
```txt=
CRITICAL:root:critical
ERROR:root:error
WARNING:root:warning
```

このコードからわかることは、デフォルトのログレベルは**warning**にあるということ。

### ログレベルの変更
以下のように設定を追加すると、ログレベルを更新できる。
```python=
logging.basicConfig(level=logging.DEBUG)

# 省略
```

出力は以下の通り：
```txt=
CRITICAL:root:critical
ERROR:root:error
WARNING:root:warning
INFO:root:info
DEBUG:root:debug
```

期待通り、DEBUGレベルまでのログを出力できるようになった。この設定の更新は、ランタイム全体に適用される。次の例のように、異なる名前空間を持つロガーを作成した場合を見てみる。
```python=
logging.basicConfig(level=logging.DEBUG)

myLogger = logging.getLogger('myLogger')

if __name__ == '__main__':
    logging.debug('root debug')
    myLogger.debug('myLogger debug')
```

結果は次の通り：
```txt=
DEBUG:root:debug
DEBUG:myLogger:debug
```

### ログメッセージのフォーマット
一番簡単なフォーマットの更新は、`logging.basicConfig(format='')`を設定すること。

```python=
import logging

logging.basicConfig(format='%(levelname)s:%(message)s')
```

フォーマット文字列として参照できるパターンについては、[LogRecord](https://docs.python.org/ja/3/library/logging.html#logrecord-attributes)のセクションを参考にする。

## Logging Components
Pythonのログ機構を構成する４つのコンポーネントについて説明する。

- **Loggers**: ログ出力のためのインタフェースの提供
- **Handlers**: ロガーが生成する記録の送信先を決定
- **Filters**: ログ記録の出力の有無の決定
- **Formatters**: レイアウトの指定

### Loggers
- ロガー名は、ログが発生した場所がわかるような名前にするべき
    - 各モジュールレベルで、ロガーを設定するのが慣習的

```python=
logger = logging.getLogger(__name__)
```

#### 名前空間の具体例
次のようなケースを考えてみる。

```txt=
├── main.py
├── pkg
│   ├── __init__.py
│   └── mod.py
└── text.log
```

**pkg/mod.py**
```python=
import logging


logger = logging.getLogger(__name__)

def func():
    logger.info('func called')
```

**main.py**
```python=
import logging

from pkg import mod


logging.basicConfig(level=logging.INFO, filename='text.log')


if __name__ == '__main__':
    mod.func()
```

スクリプトを実行してみる。

```shell=
$ python3 -m main.py
```

`text.log`が生成されるので、その内容を確認すると...

```txt=
INFO:pkg.mod:func called
```

モジュールレベルのロガーを設定すると、きちんとログが発生した場所として記録されることがわかる。

#### ロガーに特有のレベルを設定する
`Logger.setLevel()`を利用すれば良い。

#### ロガーの階層構造
> 子ロガーはメッセージを親ロガーのハンドラに伝えます。このため、アプリケーションが使っているすべてのロガーのためのハンドラを定義して設定する必要はありません。トップレベルのロガーのためのハンドラだけ設定しておいて必要に応じて子ロガーを作成すれば十分です。(しかし、ロガーの propagate 属性を False に設定することで、伝播を抑制できます。)

```python=
# app.py
import logging
from pkg import mod

logger = logging.getLogger('app')
logger.setLevel(logging.INFO)

ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)

formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')

ch.setFormatter(formatter)

logger.addHandler(ch)


if __name__ == '__main__':
    mod.func()

# pkg/mod.py
import logging

logger = logging.getLogger('app.pkg.mod')

def foo():
    logger.info('foo called')
    logger.debug('foo called')
```

実行結果は次のようになる。
```txt=
2019-12-27 15:08:50,150 - pkg - INFO - info
2019-12-27 15:08:50,150 - pkg.mod - INFO - func called
```

### Handlers
[logging.handlers](https://docs.python.org/ja/3/library/logging.handlers.html)

#### Basics
何が`basic`かと言えば、`logging`モジュール直下に定義されていること。

- **StreamHandler** : `stream`とは標準出力や標準エラー出力、ファイル風オブジェクトを表現する
- **FileHandler** : ログ出力をファイルに送信する
- NullHandler : No-opなハンドラ

#### Advanced
`logging.handlers`モジュールに定義されている。

- WatchedFileHandler
- BaseRotatingHandler（抽象クラス）
- RotatingFileHandler
- TimedRotatingFileHandler
- etc...
