Django Python

[Python実践]Loggingに挑戦してみよう！《応用編》〜公式ドキュメントをもとに解説〜

かるでね

こんにちは！実務でPython、Djangoを使って、機械学習やWebアプリケーションの開発をしているかるでねです！

今回はPythonの「Logging」の応用について解説していこうと思います！

「Logging」の基礎についてはこちらの記事にまとめてあります。

「Logging」はPythonの実務などでよく使われるので、Pythonエンジニアを目指している方は是非この記事でマスターしていってください！

この記事はPythonの公式ドキュメントを参考にしています。

Pythonに限らず、プログラミング言語の公式ドキュメントは非常に読みにくいので、この記事でわかりやすく解説していきます。

「Loggingよく見かけるんだけど全くわからない...」

「Pythonエンジニアを目指して学習中」

「Pythonスキルのレベルアップをしたい！」

このような人のお役に立てれば幸いです。

それでは早速本題に入っていきましょう！

「Logging」はPythonの基礎を理解していないと難しいので、Pythonの基礎を理解していない人は以下を参考に学習してください！

ロギングとは？

まずは「Logging」がどういったものなのかなどの概要から見ていきましょう。

「Logging」とは以下のようなものです。

ポイント

  • プログラムが実行されているときに起こったイベントを追跡してくれる。
  • 重要度を設定して、特定のイベントが発生したことをメッセージと共に知らせてくれる。

より詳しくはこちらにまとめてあります。

細かくみてみる

ロギングは「Logger」クラスのインスタンスにメソッドに呼び出して実行されています。

公式ドキュメント

「ロガー」は、どこでイベントのログが取られたかを明らかにしてくれます。

名前の確認

まずは「ロガー」の名前を確認してきましょう。

logger = logging.getLogger(__name__)
print(logger)
# <Logger __main__ (WARNING)>

__main__ とWARNINIG が表示されていますね。

__main__ は実行されているファイルのことで、WARNINIG はデフォルトの重要度レベルのことです。

__name__ と指定することが推奨されています。

明示的に自分で指定

次に明示的に「ロガー」の名前を指定してみましょう。

logger = logging.getLogger("かるでね")
print(logger)
# <Logger かるでね (WARNING)>

自分が指定した通り、「かるでね」と出力されていますね。

重要度レベル変更してみる

では次に重要度レベルを変更してみましょう。

import logging

logging.basicConfig(level=logging.ERROR)

logger = logging.getLogger(__name__)
print(logger)
# <Logger __main__ (ERROR)>

３行目でERROR に設定してみると、出力部分がWARNINIGからERRORに変わってますね。

他のファイルで実行されたロガー名を確認

名前が__main__だとよくわからないので、別ファイルの「ロガー」名を確認してみましょう。

まずはtest.pyに以下を記入してください。

import logging

def log_info():
    logger = logging.getLogger(__name__)
    return logger

次にmain.pyに以下を記入してください。

import logging
import test

logger = logging.getLogger(__name__)
print(logger)
print(test.log_info())

# <Logger __main__ (WARNING)>
# <Logger test (WARNING)>

main.pyの「ロガー」は__main__と表示されています。（ファイル名がmain.pyだからではなく、「実行されているファイル」という意味です。

test.pyの方はtestと表示されています。

これで__name__が実行されているファイル名を参照していることがわかります。

root

rootとは「ロガー」階層の一番上に位置しているものです。

こんな感じのイメージですね。

ちなみに普通に「ロギング」で出力されたメッセージを見るとひっそり出力されているのが確認できます。

import logging

logging.warning('Warningだよ！！！')
# WARNING:root:Warningだよ！！！

真ん中にrootというのがしっかりありますね。

ロガー

「ロガー」には以下のような特徴があります。

ポイント

  • プログラム実行中にメッセージを記録できるように、メソッドを呼べるようにしている。
  • 重要度やフィルターなどを定義して、どのメッセージについて動作するか決める。
  • 重要度に基づいてハンドラに関連するログメッセージを出力する。

setLevel

基本的な使い方

setLevelは「ロガー」の重要度レベルを変更できます。

import logging

logging.basicConfig(level=logging.ERROR)

logging.debug('Debugだよ！')
logging.info('Infoだよ！！')
logging.warning('Warningだよ！！！')
logging.error('Errorだよ！！！！')
logging.critical('Criticalだよ！！！！')

# ERROR:root:Errorだよ！！！！
# CRITICAL:root:Criticalだよ！！！！

これは「ロギング」の重要度レベルをERRORに設定しています。

では次に「ロガー」の方で設定していきましょう。

logger = logging.getLogger(__name__)
print(logger)
# <Logger __main__ (WARNING)>

logger.setLevel(logging.INFO)

logger.debug('Debugだよ！')
logger.info('Infoだよ！！')
logger.warning('Warningだよ！！！')
logger.error('Errorだよ！！！！')
logger.critical('Criticalだよ！！！！')

# INFO:__main__:Infoだよ！！
# WARNING:__main__:Warningだよ！！！
# ERROR:__main__:Errorだよ！！！！
# CRITICAL:__main__:Criticalだよ！！！！

「ロギング」の方でERRORに設定していますが、「ロガー」の方ではINFOに設定しているのでINFO以上のメッセージが出力されていますね。

このように、「全体設定ファイルで全体の重要度を設定して、個別のファイルで取得するイベントの重要度を変更していく」使われ方がされます。

以下で実際に見てみましょう。

test.pyとmain.pyの２つのファイルを用意してください。

import logging

logger = logging.getLogger(__name__)

logger.setLevel(logging.INFO)

def test_logger():
    logger.debug('Debugだよ！')
    logger.info('Infoだよ！！')
    logger.warning('Warningだよ！！！')
    logger.error('Errorだよ！！！！')
    logger.critical('Criticalだよ！！！！')
    return logger
import logging
import test

logging.basicConfig(level=logging.ERROR)

logging.debug('Debugだよ！')
logging.info('Infoだよ！！')
logging.warning('Warningだよ！！！')
logging.error('Errorだよ！！！！')
logging.critical('Criticalだよ！！！！')

test.test_logger()

では出力を確認しましょう。

# ==========《main.py》==========
# ERROR:root:Errorだよ！！！！
# CRITICAL:root:Criticalだよ！！！！
# ====================

# ==========《test.py》==========
# INFO:test:Infoだよ！！
# WARNING:test:Warningだよ！！！
# ERROR:test:Errorだよ！！！！
# CRITICAL:test:Criticalだよ！！！！
# ====================

main.pyでは「ロギング」 が使われているので、ERROR以上のメッセージが出力されています。

一方、test.pyでは「ロガー」が使われているので、INFO以上のメッセージが出力されています。

setLevelを明示的に指定しない

setLevelを明示的に指定しないと親をたどっていき、有効な重要度レベルを探します。

test.pyとmain.pyの２つのファイルを用意してください。

import logging

logger = logging.getLogger(__name__)

def test_logger():
    logger.debug('Debugだよ！')
    logger.info('Infoだよ！！')
    logger.warning('Warningだよ！！！')
    logger.error('Errorだよ！！！！')
    logger.critical('Criticalだよ！！！！')
    return logger
import logging
import test

logging.basicConfig(level=logging.ERROR)

logging.debug('Debugだよ！')
logging.info('Infoだよ！！')
logging.warning('Warningだよ！！！')
logging.error('Errorだよ！！！！')
logging.critical('Criticalだよ！！！！')

test.test_logger()

では出力を確認しましょう。

# ==========《main.py》==========
# ERROR:root:Errorだよ！！！！
# CRITICAL:root:Criticalだよ！！！！
# ====================

# ==========《test.py》==========
# ERROR:test:Errorだよ！！！！
# CRITICAL:test:Criticalだよ！！！！
# ====================

test.pyの親であるmain.pyで設定されている ERROR レベルが採用されているのが確認できますね。

getLogger

一番最初に使用したgetLoggerをもう少し詳しくみていきましょう。

import logging

logging.basicConfig(level=logging.ERROR)
print(logging.getLogger(__name__))

# <Logger __main__ (ERROR)>

実行されているロガーの情報が確認できます。

しっかり重要度レベルも設定したようにERRORになっていますね。

import logging

logging.basicConfig(level=logging.ERROR)
print(logging.getLogger())

# <RootLogger root (ERROR)>

getLogger に何も渡さないと root「 ロガー」の情報を取得していますね。

ハンドラ

「ハンドラ」とは以下のようなものです。

ハンドラの指定された出力先にログメッセージを出力する。

AddHandler

「ロガー」に設定を追加する。

ではこのaddHandler機能を使用してファイル出力してみましょう。

import logging

logger = logging.getLogger(__name__)

logger.setLevel(logging.INFO)

fh = logging.FileHandler("logging.log")
logger.addHandler(fh)

logger.debug('Debugだよ！')
logger.info('Infoだよ！！')
logger.warning('Warningだよ！！！')
logger.error('Errorだよ！！！！')
logger.critical('Criticalだよ！！！！')

７行目のFileHandlerでメッセージの出力先ファイルを指定しています。

今回はlogging.logというファイルに出力します。（実行時に自動で作成してくれます。）

８行目では「ロガー」にFileHandlerを追加しています。

ではしっかりlogging.logファイルに出力されているか確認してみましょう。

Infoだよ！！
Warningだよ！！！
Errorだよ！！！！
Criticalだよ！！！！

ちゃんと出力されていますね。

RemoveHandler

「ロガー」から設定を取り除く。

今回はtest.pyとmain.pyの２つのファイルを用意してください。

import logging

logger = logging.getLogger(__name__)

logger.setLevel(logging.INFO)

fh = logging.FileHandler("logging.log")
logger.addHandler(fh)

def test_logger(output=True):
    if not output:
        logger.removeHandler(fh)

    logger.debug('Debugだよ！')
    logger.info('Infoだよ！！')
    logger.warning('Warningだよ！！！')
    logger.error('Errorだよ！！！！')
    logger.critical('Criticalだよ！！！！')

１０行目でoutputという引数を受け取っています。

デフォルトではTrueとなっていますが、もしFalseが渡されるとremoveHandlerが呼び出されて、「ロガー」からファイル出力設定を取り除きます。

import logging
import test

logging.basicConfig(level=logging.ERROR)

logging.debug('Debugだよ！')
logging.info('Infoだよ！！')
logging.warning('Warningだよ！！！')
logging.error('Errorだよ！！！！')
logging.critical('Criticalだよ！！！！')

test.test_logger(False)

１２行目でtest.pyのtest_logger関数を呼び出し、引数にFalseを渡しています。

では出力されていないかlogging.logを見てみましょう。

何も出力されていないですね。

StreamHandler

ログメッセージをコンソールに出力してくれる。

早速みてみましょう。

import logging

logger = logging.getLogger(__name__)

logger.setLevel(logging.INFO)

st = logging.StreamHandler()

logger.addHandler(st)

logger.debug('Debugだよ！')
logger.info('Infoだよ！！')
logger.warning('Warningだよ！！！')
logger.error('Errorだよ！！！！')
logger.critical('Criticalだよ！！！！')

７行目でStreamHandlerを定義してコンソール出力するようにしています。

８行目でStreamHandlerの設定を追加しています。

では出力結果をコンソールで確認してみましょう。

Infoだよ！！
Warningだよ！！！
Errorだよ！！！！
Criticalだよ！！！！

ちゃんと想定通りコンソールに出力されています。

他にも「ハンドラー」はいくつかあるので以下を参考にしてください。

公式ドキュメント

フォーマッタ

ログメッセージ出力をカスタムできる。

名前の通りログメッセージの出力表現を自分好みにカスタムできます。

早速みていきましょう。

import logging

logger = logging.getLogger(__name__)

logger.setLevel(logging.INFO)

sh = logging.StreamHandler()

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

sh.setFormatter(formatter)

logger.addHandler(sh)


logger.debug('Debugだよ！')
logger.info('Infoだよ！！')
logger.warning('Warningだよ！！！')
logger.error('Errorだよ！！！！')
logger.critical('Criticalだよ！！！！')

９行目で出力のメッセージを定義しています。

asctimeは、「日時」を出力します。

nameは、「ロガー」の名前を出力してくれます。

levelnameは、「重要度」を出力してくれます。

messageは、「ログメッセージ」のことです。

１１行目で先ほど定義したformatterをセットしています。

１３行目で「ロガー」に渡しています。

では早速出力を見てみましょう。

2022-02-20 12:01:23,202 - __main__ - INFO - Infoだよ！！
2022-02-20 12:01:23,202 - __main__ - WARNING - Warningだよ！！！
2022-02-20 12:01:23,202 - __main__ - ERROR - Errorだよ！！！！
2022-02-20 12:01:23,202 - __main__ - CRITICAL - Criticalだよ！！！！

ちゃんと自分が設定したように出力されていますね。

コンフィグ

「ロガー」設定をまとめて定義。

「コンフィグ」では、「ロガー」の設定を別ファイルや辞書型など、まとめて定義します。

Webアプリケーションなどではこのような方法で使われることが多いので確認しておきましょう。

設定ファイル

まずは設定ファイルに「ロガー」をまとめて定義する方法を見ていきましょう。

logging.confというファイルを作成してください。

[loggers]
keys=root,CardeneHandler

[handlers]
keys=streamHandler

[formatters]
keys=formatter

[logger_root]
level=INFO
handlers=streamHandler

[logger_CardeneHandler]
level=DEBUG
handlers=streamHandler
qualname=cardeneHandler
propagate=0

[handler_streamHandler]
class=StreamHandler
level=DEBUG
formatter=formatter
args=(sys.stdout,)

[formatter_formatter]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s

１つ１つ解説すると長くなってしまうので、ここまでの知識でなんとなく理解してください。

ではこの設定ファイルを読み込んで「ロガー」を実行してみましょう。

import logging
import logging.config

logging.config.fileConfig('logging.conf')

logger = logging.getLogger('CardeneHandler')

logging.debug('Debugだよ！')
logging.info('Infoだよ！！')
logging.warning('Warningだよ！！！')
logging.error('Errorだよ！！！！')
logging.critical('Criticalだよ！！！！')

４行目で先ほど定義したlogging.confファイルを読み込んでいます。

６行目では、logging.confで定義してあるCardeneHandlerという「ハンドラー」を呼び出しています。

では出力を見てみましょう。

2022-02-20 13:59:25,418 - root - INFO - Infoだよ！！
2022-02-20 13:59:25,418 - root - WARNING - Warningだよ！！！
2022-02-20 13:59:25,418 - root - ERROR - Errorだよ！！！！
2022-02-20 13:59:25,418 - root - CRITICAL - Criticalだよ！！！！

ちゃんと出力されていますね。

辞書型

辞書型で定義する方法は「Django」などのWebアプリケーションを作成できるフレームワークでよく使われます。

では早速みていきましょう。

import logging
import logging.config

logging.config.dictConfig({
    'version': 1,
    'formatters': {
        'cardeneFormatter': {
            'format': '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
        }
    },
    'handlers': {
        'cardeneHandlers': {
            'class': 'logging.StreamHandler',
            'formatter': 'cardeneFormatter',
            'level': logging.INFO
        }
    },
    'root': {
        'handlers': ['cardeneHandlers'],
        'level': logging.WARNING,
    },
    'loggers': {
        'cardeneHandler': {
            'handlers': ['cardeneHandlers'],
            'level': logging.INFO,
            'propagate': 0
        }
    }
})

# create logger
logger = logging.getLogger('cardeneHandler')

logging.debug('Debugだよ！')
logging.info('Infoだよ！！')
logging.warning('Warningだよ！！！')
logging.error('Errorだよ！！！！')
logging.critical('Criticalだよ！！！！')

めちゃくちゃ長いですね...。

こちらも先ほどと設定内容はほとんど同じなので細かい説明は省きます。

では早速実行してみましょう。

2022-02-20 14:12:17,174 - root - WARNING - Warningだよ！！！
2022-02-20 14:12:17,175 - root - ERROR - Errorだよ！！！！
2022-02-20 14:12:17,175 - root - CRITICAL - Criticalだよ！！！！

ちゃんと出力できました。

今回はWARNING以上に重要度レベルを設定しました。

さらに詳しく

より詳しく知りたいときは公式のドキュメントを読み進めてみてください！

公式ドキュメント

最後に

今回は「Loggingに挑戦してみよう！《応用編》」と」いうテーマで「Logging」の使い方をみてきました。

いかかだったでしょうか？

「Logging」を実装するまでの力がついたと思います。

普段はPythonやブロックチェーンメインに情報発信をしています。

Twiiterでは図解でわかりやすく解説する投稿をしているのでぜひフォローしてくれると嬉しいです！

-Django, Python
-,