Pythonのloggingの使い方まとめ(初心者)

# 目次
[0. はじめに](#0-はじめに)
- [0.1. 環境に関して](#01-環境に関して)
- [0.2. 背景，動機](#02-背景動機)

[1. ログ出力と出力レベル](#1-ログ出力と出力レベル)
[2. ハンドラとは](#2-ハンドラとは)
- [2.1. ハンドラのイメージ](#21-ハンドラのイメージ)
- [2.2. ハンドラのレベル](#22-ハンドラのレベル)
- [2.3. ハンドラの出力フォーマット](#23-ハンドラの出力フォーマット)

[3. ハンドラの応用(logging.handlers.XXXHandler)](#3-ハンドラの応用logginghandlersxxxhandler)
- [3.1. RotatingFileHandler(出力先のファイルサイズによる循環)](#31-rotatingfilehandler出力先のファイルサイズによる循環)
- [3.2. TimedRotatingFileHandler(経過時間による循環)](#32-timedrotatingfilehandler経過時間による循環)

[4. おわりに](#4-おわりに)
[5. 参考サイト](#5-参考サイト)

# 0. はじめに
## 0.1. 環境に関して
　loggingモジュールは実行環境によっては最初からハンドラというものが入っている事がある．この場合，意図せぬ出力の重複が出るかもしれない．
 参考：

https://qiita.com/fumiya0238/items/825121848eb017d4d452

 その時は上記記事にもあるが，以下のコードのようにルートロガーへの伝播を切ると良い．
 ```python
 logger = logging.getLogger(__name__)
 logger.propagate = False
 ```

## 0.2. 背景，動機
　loggingモジュールを調べるにあたった理由は，自動化プログラムを組んでいる際にログを取得する必要に気付いたからだ．
　以下の章では文体が崩れる．

# 1. ログ出力と出力レベル
　loggingはモジュールであり，python.exe1つに対して1つしか存在しない制約がある．そのためオブジェクト(logger)を作り用いると良い．
 ![logger_explain.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/3794492/48938b49-9376-fd65-7ef0-b663bcf710bb.png)
```python:python
import logging

logger_1 = logging.getLogger("Alice")
# __name__にするとモジュール，実行ファイル名が出力されるため，より分かりやすくなる．
# logger_1 = logging.getLogger(__name__)

# ログ出力
logger_1.debug('Debug') # 出力されないはず
logger_1.info('Informarion') # 出力されないはず
logger_1.warning('Warning')
logger_1.error('Error')
logger_1.critical('Critical')
```
```:出力
WARNING:Alice:Warning
ERROR:Alice:Error
CRITICAL:Alice:Critical
```
　debug，infoが出力されないのは出力レベルが設定されていないからである．設定にはsetLevel()メソッドを使う．
 ```python:python
logger_1 = logging.getLogger("Alice")

# ログの出力レベルを設定
logger_1.setLevel(level=logging.INFO)

# ログ出力
logger_1.debug('Debug') # ここだけ出力されないはず
logger_1.info('Informarion')
logger_1.warning('Warning')
logger_1.error('Error')
logger_1.critical('Critical')
```
```:出力
INFO:Alice:Informarion
WARNING:Alice:Warning
ERROR:Alice:Error
CRITICAL:Alice:Critical
```
INFOの中身には20というint型の値が入っている．各レベルには以下の数値が入っている．

レベル名 | 数値
----- | -----
DEBUG | 10
INFO | 20
WARNING | 30
ERROR | 40
CRITICAL | 50

# 2. ハンドラとは

## 2.1. ハンドラのイメージ
　ハンドラはloggerがログ出力の際に使用する道具のようなもの．
 
ハンドラインスタンス | loggerに付与される機能
----- | -----
StreamHandler | ターミナルへの出力
FileHandler	| ファイルへの出力
SMTPHandler	| 特定のメールアドレスへの送信出力
HTTPHandler	| HTTPサーバへの出力

```python:python
logger_2_1 = logging.getLogger("Bob_1")
logger_2_1.setLevel(level=logging.INFO)
logger_2_1.propagate = False

# ハンドラクラスをインスタンス化
stream_handler = logging.StreamHandler()
file_handler = logging.FileHandler(filename="test_S2_1.log", mode="w", encoding="utf-8")

# インスタンス化したハンドラをlogger(Bob_1)に渡す
logger_2_1.addHandler(stream_handler)
logger_2_1.addHandler(file_handler)

logger_2_1.debug('Debug')
logger_2_1.info('Informarion')
logger_2_1.warning('Warning')
logger_2_1.error('Error')
logger_2_1.critical('Critical')

# fileログの表示
print("-----"*5)
with open("test_S2_1.log", mode="r", encoding="utf-8") as rf:
    for line in rf.readlines():
        print(line, end="")
```
```:出力(ターミナル)
Informarion
Warning
Error
Critical
-------------------------
Informarion
Warning
Error
Critical
```

## 2.2. ハンドラのレベル
　ハンドラにもそれぞれに出力レベルが存在する．設定方法は1章と同様である．
 ```python:python
logger_2_2 = logging.getLogger("Bob_2")
logger_2_2.setLevel(level=logging.INFO)
logger_2_2.propagate = False

stream_handler = logging.StreamHandler()
file_handler = logging.FileHandler(filename="test_S2_2.log", mode="w", encoding="utf-8")

# ハンドラの出力レベル設定
stream_handler.setLevel(level=logging.INFO)
file_handler.setLevel(level=logging.WARNING)

logger_2_2.addHandler(stream_handler)
logger_2_2.addHandler(file_handler)

logger_2_2.debug('Debug')
logger_2_2.info('Informarion')
logger_2_2.warning('Warning')
logger_2_2.error('Error')
logger_2_2.critical('Critical')

print("-----"*5)
# ファイルへの出力レベルをWarning以上に設定したため，INFOが出力されないことを確認する
with open("test_S2_2.log", mode="r", encoding="utf-8") as rf:
    for line in rf.readlines():
        print(line, end="")
 ```
 ```:出力(ターミナル)
Informarion
Warning
Error
Critical
-------------------------
Warning
Error
Critical
 ```

## 2.3. ハンドラの出力フォーマット
　loggingには出力フォーマットがあり，logging.Formatter(fmt, datefmt)で設定できる．
フォーマットのパラメータは以下の通り．

パラメータ名 | 説明
----- | -----
name | ロガーの名前
asctime | タイムスタンプの文字列表現
created | タイムスタンプ（秒単位）
levelname | ログレベル名（INFO, WARNING, etc.）
levelno | ログレベル番号（10, 20, etc.）
message | ログメッセージ
module | ログ発生モジュール名
filename | ログ発生ファイル名
pathname | ログ発生ファイルのフルパス
funcName | ログ発生関数名
lineno | ログ発生行番号
process | プロセスID
thread | スレッドID
threadName | スレッド名
msecs | タイムスタンプのミリ秒部分
relativeCreated | ロガー生成からの経過時間（ミリ秒）
 ```python:python
logger_2_3 = logging.getLogger("Bob_3")
logger_2_3.setLevel(level=logging.INFO)
logger_2_3.propagate = False

stream_handler = logging.StreamHandler()
file_handler = logging.FileHandler(filename="test_S2_3.log", mode="w", encoding="utf-8")

stream_handler.setLevel(level=logging.INFO)
file_handler.setLevel(level=logging.INFO)

# ハンドラの出力フォーマット設定
fmt = "%(levelname)-9s  %(asctime)s [%(filename)s:%(lineno)d] %(message)s"
stream_handler.setFormatter(logging.Formatter(fmt=fmt))
file_handler.setFormatter(logging.Formatter(fmt=fmt, datefmt="%Y/%m/%d-%H:%M:%S"))

logger_2_3.addHandler(stream_handler)
logger_2_3.addHandler(file_handler)

logger_2_3.debug('Debug')
logger_2_3.info('Informarion')
logger_2_3.warning('Warning')
logger_2_3.error('Error')
logger_2_3.critical('Critical')

print("-----"*5)
with open("test_S2_3.log", mode="r", encoding="utf-8") as rf:
    for line in rf.readlines():
        print(line, end="")
 ```
 ```:出力(ターミナル)
INFO       2024-05-18 09:49:10,123 [<ipython-input-15-0fcb01f9fecd>:20] Informarion
WARNING    2024-05-18 09:49:10,127 [<ipython-input-15-0fcb01f9fecd>:21] Warning
ERROR      2024-05-18 09:49:10,131 [<ipython-input-15-0fcb01f9fecd>:22] Error
CRITICAL   2024-05-18 09:49:10,133 [<ipython-input-15-0fcb01f9fecd>:23] Critical
-------------------------
INFO       2024/05/18-09:49:10 [<ipython-input-15-0fcb01f9fecd>:20] Informarion
WARNING    2024/05/18-09:49:10 [<ipython-input-15-0fcb01f9fecd>:21] Warning
ERROR      2024/05/18-09:49:10 [<ipython-input-15-0fcb01f9fecd>:22] Error
CRITICAL   2024/05/18-09:49:10 [<ipython-input-15-0fcb01f9fecd>:23] Critical
 ```

# 3. ハンドラの応用(logging.handlers.XXXHandler)

## 3.1. RotatingFileHandler(出力先のファイルサイズによる循環)
　循環とは：
> ログ出力は、その性質上時間経過と共に容量が増え続けるものである。
>
> そこで実際の運用時には、ログファイルの循環についての設定をしておく必要がある。
>
> ログファイルの循環とは、出力先のファイルを容量もしくは経過時間によって新しいものと切り替える設定のことである。
> [Pythonのloggingをイメージで理解する【Python Logging徹底解説】](https://zenn.dev/dencyu/articles/2b58f669bcd473)

　設定方法は以下の通り．maxBytesまでのファイルをbackupCount個作る．backupCount=0の場合は作られない．
*class* logging.handlers.__RotatingFileHandler__(*filename, mode='a', maxBytes=0, backupCount=0, encoding=None, delay=False, errors=None*)
 ```python:python
!mkdir "test_S3_1"
logger_3_1 = logging.getLogger("Charlotte")
logger_3_1.setLevel(level=logging.INFO)

stream_handler = logging.StreamHandler()
# FileHandler => RotatingFileHandler
file_handler = logging.handlers.RotatingFileHandler(filename="test_S3_1/test_S3_1.log", maxBytes=100, backupCount=10, encoding="utf-8")

stream_handler.setLevel(level=logging.INFO)
file_handler.setLevel(level=logging.INFO)

fmt = "%(levelname)-9s  %(asctime)s [%(filename)s:%(lineno)d] %(message)s"
stream_handler.setFormatter(logging.Formatter(fmt=fmt))
file_handler.setFormatter(logging.Formatter(fmt=fmt))

logger_3_1.addHandler(stream_handler)
logger_3_1.addHandler(file_handler)

logger_3_1.debug('Debug')
logger_3_1.info('Informarion')
logger_3_1.warning('Warning')
logger_3_1.error('Error')
logger_3_1.critical('Critical')

print("-----"*5)
with open("test_S3_1/test_S3_1.log", mode="r", encoding="utf-8") as rf:
    for line in rf.readlines():
        print(line, end="")
 ```
 ```:出力(ターミナル)
INFO       2024-05-18 09:57:02,986 [<ipython-input-16-823db5e116ad>:21] Informarion
WARNING    2024-05-18 09:57:02,990 [<ipython-input-16-823db5e116ad>:22] Warning
ERROR      2024-05-18 09:57:02,993 [<ipython-input-16-823db5e116ad>:23] Error
CRITICAL   2024-05-18 09:57:02,997 [<ipython-input-16-823db5e116ad>:24] Critical
-------------------------
CRITICAL   2024-05-18 09:57:02,997 [<ipython-input-16-823db5e116ad>:24] Critical
 ```
 作業ディレクトリに複数のログファイルが出来ていることが分かる．
![RotatingFileHandler_image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/3794492/03711608-1b99-41c7-17e4-7da66abe6155.png)

## 3.2. TimedRotatingFileHandler(経過時間による循環)
　設定方法は以下の通り．
 *class* logging.handlers.__TimedRotatingFileHandler__(*filename, when='h', interval=1, backupCount=0, encoding=None, delay=False, utc=False, atTime=None, errors=None*)

when | interval の単位 | atTime の使用有無/使用方法
----- | ----- | -----
'S' | 秒 | 無視
'M' | 分 | 無視
'H' | 時間 | 無視
'D' | 日 | 無視
'W0'-'W6' | 曜日 (0=月曜)(interval is unused) | 初期のロールオーバー時刻の算出に使用
'midnight' | atTime が指定されなかった場合は深夜に、そうでない場合は atTime の時刻にロールオーバーされます | 初期のロールオーバー時刻の算出に使用

[when="S", interval=10]なら10秒経過後に別ログファイルが作られる．
 ```python:python
!mkdir "test_S3_2"
logger_3_2 = logging.getLogger("Charlotte")
logger_3_2.setLevel(level=logging.INFO)
logger_3_2.propagate = False

stream_handler = logging.StreamHandler()
# FileHandler => TimedRotatingFileHandler
file_handler = logging.handlers.TimedRotatingFileHandler(filename="test_S3_2/test_S3_2.log", when="S", interval=1, backupCount=10, encoding="utf-8")

stream_handler.setLevel(level=logging.INFO)
file_handler.setLevel(level=logging.INFO)

fmt = "%(levelname)-9s  %(asctime)s [%(filename)s:%(lineno)d] %(message)s"
stream_handler.setFormatter(logging.Formatter(fmt=fmt))
file_handler.setFormatter(logging.Formatter(fmt=fmt))

logger_3_2.addHandler(stream_handler)
logger_3_2.addHandler(file_handler)

logger_3_2.debug('Debug')
logger_3_2.info('Informarion')
logger_3_2.warning('Warning')
logger_3_2.error('Error')
logger_3_2.critical('Critical')

print("-----"*5)
with open("test_S3_2/test_S3_2.log", mode="r", encoding="utf-8") as rf:
    for line in rf.readlines():
        print(line, end="")
 ```
 ```:出力(ターミナル)
 INFO       2024-05-18 10:04:48,149 [<ipython-input-17-7d071b68b122>:21] Informarion
WARNING    2024-05-18 10:04:48,152 [<ipython-input-17-7d071b68b122>:22] Warning
ERROR      2024-05-18 10:04:48,154 [<ipython-input-17-7d071b68b122>:23] Error
CRITICAL   2024-05-18 10:04:48,157 [<ipython-input-17-7d071b68b122>:24] Critical
-------------------------
INFO       2024-05-18 10:04:48,149 [<ipython-input-17-7d071b68b122>:21] Informarion
WARNING    2024-05-18 10:04:48,152 [<ipython-input-17-7d071b68b122>:22] Warning
ERROR      2024-05-18 10:04:48,154 [<ipython-input-17-7d071b68b122>:23] Error
CRITICAL   2024-05-18 10:04:48,157 [<ipython-input-17-7d071b68b122>:24] Critical
 ```
　実行するごとにログファイルが作られていることが分かる．
![image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/3794492/0a99355a-381f-3211-b41f-0f8baaeb012f.png)

## 3.3. HTTPHandler擬き
　HTTPHandlerを使用してDiscordに通知を飛ばそうとしたのですが上手くいかず，他ライブラリで力押ししました．そのため擬きとしました．
 ```python:python(自作ハンドラ，フィルタ)
class DiscordHandler(logging.Handler):
    def __init__(self, url):
        super().__init__()
        self.url = url

    def emit(self, record:logging.LogRecord):
        if (type(record.msg) is str):
            data = {"content": self.format(record),
                    "username": "Taro",
                    }
            res = requests.post(url=self.url, data=data)
        elif (type(record.msg) is bytes):
            data = {"username": "Taro",}
            files = {"file": ("test.png", record.msg)}
            res = requests.post(url=self.url, files=files, data=data)


class BytesFilter(logging.Filter):
    def __init__(self):
        super().__init__()

    def filter(self, record):
        return not (type(record.msg) is bytes)
 ```
 ```python:python
import json
import requests
from google.colab import drive
drive.mount("/content/drive")

URL = "<YOUR DISCORD WEBHOOK URL>"

logger_3_3 = logging.getLogger("Dom")
logger_3_3.setLevel(logging.INFO)
logger_3_3.propagate = False

formatter = logging.Formatter("%(levelname)-9s%(asctime)s [%(pathname)s:line%(lineno)d]%(message)s", datefmt="%Y/%m/%d-%H:%M:%S")

discord_handler = DiscordHandler(url=URL)
discord_handler.setFormatter(formatter)
discord_handler.setLevel(level=logging.CRITICAL)
logger_3_3.addHandler(discord_handler)

stream_handler = logging.StreamHandler()
stream_handler.setLevel(level=logging.INFO)
stream_handler.setFormatter(formatter)
stream_handler.addFilter(BytesFilter())
logger_3_3.addHandler(stream_handler)

logger_3_3.debug('Debug')
logger_3_3.info('Informarion')
logger_3_3.warning('Warning')
logger_3_3.error('Error')
logger_3_3.critical('Critical')

img = None
with open("/content/drive/MyDrive/logger_explain.png", mode="rb") as rbf:
    img = rbf.read()
logger_3_3.critical(img)
 ```
 ```:出力(ターミナル)
INFO     2024/05/18-10:20:45 [<ipython-input-5-34a290deb6fa>:line21]Informarion
WARNING  2024/05/18-10:20:45 [<ipython-input-5-34a290deb6fa>:line22]Warning
ERROR    2024/05/18-10:20:45 [<ipython-input-5-34a290deb6fa>:line23]Error
CRITICAL 2024/05/18-10:20:45 [<ipython-input-5-34a290deb6fa>:line24]Critical
 ```
　discord側にも上手く送信できています．
![discord_image.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/3794492/cb3d96ff-885a-a82b-ca7b-ab87e47bb040.png)

# 4. おわりに
　記事を書いていて気付いたのですが，タイムゾーンの設定が上手くいっていませんね．調べた感じでは以下の記事で解決してるみたいです．
　初めての記事で至らないところもあると思いますが，お目通しいただきありがとうございます．

 https://qiita.com/r1wtn/items/d615f19e338cbfbfd4d6

# 5. 参考サイト
1. [Logging HOWTO — Python 3.12.3 ドキュメント](https://docs.python.org/ja/3/howto/logging.html)
1. [Python のロギングを完全に理解する #Python - Qiita](https://qiita.com/smats-rd/items/c5f4345aca3a452041c7)
1. [Pythonのloggingをイメージで理解する【Python Logging徹底解説】](https://zenn.dev/dencyu/articles/2b58f669bcd473)
1. [Python logging 各種出力ハンドラーの使い方について - Symfoware](https://symfoware.blog.fc2.com/blog-entry-885.html)
1. [【Python】フィルタを利用してSlackに通知するログを振り分ける - 人間だったら考えて](https://www.szdrblog.info/entry/2020/08/15/002418)
1. [AWS lambdaでログが重複して出力される理由と対処法（Python） #Python - Qiita](https://qiita.com/fumiya0238/items/825121848eb017d4d452)