Pythonのデバッグ情報を画面・ファイルに出力するには [Python, Logging]
ここではPythonのライブラリ「Logging」を使用してプログラムのデバッグ情報(ログ情報)を画面・ファイルに出力する方法を解説します。
Loggingライブラリを使用するとデバッグ情報を画面またはファイルに出力することができます。
また、デバッグ情報を「DEBUG, INFO, WARNING, ERROR, CRITICAL」などに分類することも可能です。
この記事ではMicrosoftのVisual Studio Code(VS Code)を使用していますが、Jupyter NotebookなどのツールでもOKです。
説明文の左側に図の画像が表示されていますが縮小されています。
画像を拡大するにはマウスを画像上に移動してクリックします。
画像が拡大表示されます。拡大された画像を閉じるには右上の[X]をクリックします。
画像の任意の場所をクリックして閉じることもできます。
Pythonのデバッグ情報を画面・ファイルに出力するには
-
プログラムのデバッグ情報を画面に表示する
VS Codeを起動したら新規ファイルを作成して行1-13を入力(コピペ)します。
行1ではPythonのライブラリを取り込んでいます。
行3ではloggingライブラリの環境を設定しています。
ここではloggingのbasicConfig()メソッドでlevelを「DEBUG」に設定しています。
この場合すべての種類(DEBUG, INFO, WARNING, ERROR, CRITICAL)のログが表示されます。
levelを設定すると、設定したレベルを含めて上位のレベルのログが表示されます。
levelのデフォルトは「WARNING」に設定されています。
したがって、levelの設定を省略したときは(WARNING, ERROR, CRITICAL)のログのみ表示されます。
levelについては行3-7のコメントを参照してください。
行9-13ではloggingの各種メソッド「debug(), info(), warning(), error(), critical()」でデバッグ情報を表示しています。
デフォルトの設定では「levelname」+「root」+「message」が表示されます。
import logging
logging.basicConfig(level=logging.DEBUG) # value=10
# logging.basicConfig(level=logging.INFO) # value=20
# logging.basicConfig(level=logging.WARNING) # value=30 (Default)
# logging.basicConfig(level=logging.ERROR) # value=40
# logging.basicConfig(level=logging.CRITICAL) # value=50
logging.debug("Hello World!")
logging.info("Hello World!")
logging.warning("Hello World!")
logging.error("Hello World!")
logging.critical("Hello World!")
図1は実行結果です。
ログ情報として「levelname(DEBUG, INFO, WARNING, ERROR, CRITICAL)」+「root」+「message」がコロン[:]区切りで表示されています。
-
プログラムのデバッグ情報をログ・ファイルに出力する
VS Codeを起動したら新規ファイルを作成して行1-24を入力します。
行3-4ではPythonのライブラリを取り込んでいます。
デバッグ情報をファイルに出力するときは、loggingのbasicConfig()メソッドの引数に「filename=」を指定します。
行14, 17では、「log」フォルダに「sample.log」のファイル名で作成しています。
行6-18ではプログラム起動時のパラメータをチェックしてします。
パラメータを省略したときは、行17-18が実行されます。
この場合、ログが既存のファイルに追加されます。
パラメータ「--reset」を指定して起動したときは、行14-15が実行されます。
この場合、ログ・ファイルが初期化されます。
ログ・ファイルを初期するときは、basicConfig()メソッドの引数に「filemode='w'」を追加します。
# RUN: python filename.py --reset
import logging
import argparse
# Create the parser
parser = argparse.ArgumentParser()
# The "store_true" option automatically creates a default value of False.
parser.add_argument('--reset', action='store_true')
# Parse the argument
args = parser.parse_args()
if args.reset:
logging.basicConfig(filename='log/sample.log', filemode='w', encoding='utf-8', level=logging.DEBUG) # reset the log file
logging.info("Reset the 'sample.log' file")
else:
logging.basicConfig(filename='log/sample.log', encoding='utf-8', level=logging.DEBUG) # append to the log file
logging.info("Append log to the 'sample.log' file")
logging.debug("Hello World!")
logging.info("Hello World!")
logging.warning("Hello World!")
logging.error("Hello World!")
logging.critical("Hello World!")
図2-1は実行結果です。
ここではプログラム起動時にパラメータを省略しています。
この場合、ログ・ファイルは追加モードになります。
図2-2はログ・ファイルの内容です。
先頭に「Append...」が追加されています。
つまり、ログが追加モードになっています。
図2-3は実行結果では。
ここではプログラム起動時にパラメータ「--reset」を指定しています。
この場合、ログ・ファイルは初期化されます。
図2-4はログ・ファイルの内容です。
先頭に「Reset...」が追加されています。
つまり、ログが初期化モートになっています。
TIP1: 「sys.argv」を使用してプログラム起動時のパラメータを取得するには
前出のPythonのライブラリ「argparse」は複数のパラメータを指定するときに便利です。
今回のように1個のパラメータのみ指定するときは「sys.argv」を使用する方法もあります。
行1ではPythonのライブラリ「sys」を取り込んでいます。
プログラム起動時のパラメータを取得するには「sys.argv」を使用します。
「sys.argv」にはパラメータがlist形式で格納されます。
「sys.argv[0]には起動したプログラムのファイル名が格納されます。
「sys.argv[1]には1番目のパラメータが格納されます。
行4-5ではプログラム起動時のパラメータを2個以上指定したときのエラー処理を行っています。
ここではエラーメッセージを表示して強制終了「sys.exit()」させています。
行7-9ではプログラム起動時のパラメータを1個指定したときのエラー処理を行っています。
ここではパラメータ値が「reset」かどうかをチェックして「reset」以外ならエラーメッセージを表示して強制終了「sys.exit()」させています。
import sys
import logging
if len(sys.argv) > 2:
sys.exit(f"Invalid parameters {sys.argv[1:]} : usage: python logging_1_tip.py reset")
if len(sys.argv) == 2:
if sys.argv[1] != 'reset':
sys.exit(f"Invalid parameter '{sys.argv[1]}' : usage: python logging_1_tip.py reset")
# no parameter or reset parameter
if len(sys.argv) == 1: # no parameter => append mode
logging.basicConfig(filename='log/sample.log', encoding='utf-8', level=logging.DEBUG) # append to the log file
logging.info("Append log to the 'sample.log' file")
else: # reset parameter => reset mode
logging.basicConfig(filename='log/sample.log', filemode='w', encoding='utf-8', level=logging.DEBUG) # reset the log file
logging.info("Reset the 'sample.log' file")
logging.debug("Hello World!")
logging.info("Hello World!")
logging.warning("Hello World!")
logging.error("Hello World!")
logging.critical("Hello World!")
図TIP1は不正なパラメータを指定したときの実行結果です。
例1ではパラメータ「xxx」を指定しています。
例2ではパラメータ「p1 p2 p3」を指定しています。
例3ではパラメータ「set」を指定しています。
いずれのケースもエラーとしてプログラムを強制終了させています。
-
デバッグ情報(時刻、レベル名、メッセージ等)をフォーマットして表示する
VS Codeを起動したら新規ファイルを作成して行1-12を入力します。
行3ではloggingのbasicConfig()メソッドに引数「format=」を追加してログをフォーマットしています。
ログがどのように表示されるかは図3を参照してください。
import logging
logging.basicConfig(format='%(asctime)s :%(levelname)s: %(message)s', datefmt='%Y/%m/%d %H:%M:%S', level=logging.DEBUG)
# logging.basicConfig(format='%(levelname)s::%(message)s', level=logging.DEBUG)
# logging.basicConfig(format='%(asctime)s %(levelname)s::%(message)s', level=logging.DEBUG)
# logging.basicConfig(format='%(asctime)s %(levelname)s::%(message)s', datefmt='%Y/%m/%d %I:%M:%S %p', level=logging.DEBUG)
logging.debug("Hello World!")
logging.info("Hello World!")
logging.warning("Hello World!")
logging.error("Hello World!")
logging.critical("Hello World!")
図3は実行結果です。
ログには「asctime」+「levelname」+「message」が表示されています。
「asctime」で日時を表示するときは、引数「datefmt=」を追加して日時をフォーマットすることができます。
日時のフォーマットの書式はPythonと同じです。
「levelname」には「DEBUG, INFO, WARNING, ERROR, CRITICAL」が表示されます。
ここではコロン「:」で囲っています。
-
デバッグ情報を色で分類する【1】
VS Codeを起動したら新規ファイルを作成して行1-19を入力します。
行3-12ではクラス「bcolors」を定義しています。
ここではカラー(色)を定義しています。
行14ではlogginのbasicConfig()メソッドでログ情報をカラー化しています。
ログの内容は「message」+「asctime」の順に表示されます。
行16-19ではlogginのdebug()メソッドでログを作成しています。
ここでは「DEBUG, INFO, WARNING, ERROR」を色分けしています。
import logging
class bcolors:
HEADER = '\033[95m'
OKBLUE = '\033[94m'
OKCYAN = '\033[96m'
OKGREEN = '\033[92m'
WARNING = '\033[93m'
FAIL = '\033[91m'
ENDC = '\033[0m'
BOLD = '\033[1m'
UNDERLINE = '\033[4m'
logging.basicConfig(format='%(message)s %(asctime)s', datefmt='[\033[96m%Y/%m/%d %H:%M:%S\033[0m]', level=logging.DEBUG)
logging.debug(f"main....DEBUG Hello World!")
logging.debug(f"main....{bcolors.OKGREEN}INFO{bcolors.ENDC} Hello World!")
logging.debug(f"main....{bcolors.WARNING}WARNING{bcolors.ENDC} Hello World!")
logging.debug(f"main....{bcolors.FAIL}ERROR{bcolors.ENDC} Hello World!")
図4は実行結果です。
ログのレベル名「DEBUG, INFO, WARNING, ERROR」が色分けされて表示されています。
-
デバッグ情報を色で分類する【2】
VS Codeを起動したら新規ファイル「logcolors.py」を作成して行1-10を入力します。
ここではクラス「Colors」を定義しています。
logcolors.py:
class Colors:
HEADER = '\033[95m'
OKBLUE = '\033[94m'
OKCYAN = '\033[96m'
OKGREEN = '\033[92m'
WARNING = '\033[93m'
FAIL = '\033[91m'
ENDC = '\033[0m'
BOLD = '\033[1m'
UNDERLINE = '\033[4m'
新規ファイル「main.py」を作成した行1-18を入力します。
行2ではクラス「Colors」を取り込んでいます。
行4-9では関数「main()」を定義しています。
行7-8では関数「func1(), func2()」を呼び出しています。
行11-12では関数「func1()」を定義しています。
行14-15では関数「func2()」を定義しています。
行17-18では関数「main()」を呼び出しています。
main.py:
import logging
import logcolors as log
def main():
logging.basicConfig(format='%(message)s %(asctime)s', datefmt='[\033[96m%Y/%m/%d %H:%M:%S\033[0m]', level=logging.DEBUG)
logging.debug(f"{log.Colors.WARNING}main{log.Colors.ENDC}....started...")
func1()
func2()
logging.debug(f"{log.Colors.WARNING}main{log.Colors.ENDC}....ended...")
def func1():
logging.debug(f"....{log.Colors.WARNING}func1{log.Colors.ENDC} return ▶ none")
def func2():
logging.debug(f"....{log.Colors.WARNING}func2{log.Colors.ENDC} return ▶ none")
if __name__ == '__main__':
main()
図5は実行結果です。
関数「func1, func2」がインデントされて表示されています。
さらに関数名が「黄色」で表示されています。
-
デバッグ情報を色で分類する【3】
VS Codeを起動したら新規ファイル「logmylib.py」を作成して行1-5を入力します。
logmylib.py:
import logging
import logcolors as log
def do_something():
logging.debug(f"....{log.Colors.WARNING}logmylib{log.Colors.ENDC}: doing something() ▶ no return")
新規ファイル「main.py」を作成したら行1-13を入力します。
行2では「logcolors.py」を取り込んでいます。
行3では「logmylib.py」を取り込んでいます。
行5-10では関数「main()」を定義しています。
行9ではlogmylibの「do_something()」メソッドを呼び出しています。
行12-13では関数「main()」を呼び出しています。
main.py:
import logging
import logcolors as log
import logmylib as mylib
def main():
logging.basicConfig(format='%(message)s %(asctime)s', datefmt='[\033[96m%Y/%m/%d %H:%M:%S\033[0m]', level=logging.DEBUG)
logging.debug(f"{log.Colors.WARNING}main{log.Colors.ENDC}....started...")
mylib.do_something()
logging.debug(f"{log.Colors.WARNING}main{log.Colors.ENDC}....ended...")
if __name__ == '__main__':
main()
図6は実行結果です。
logmylibの関数「doing_something()」がインデントされて表示されています。