Python3でロギングを使用する方法

序章

loggingモジュールは標準のPythonライブラリの一部であり、ソフトウェアの実行中に発生するイベントの追跡を提供します。 コードにロギング呼び出しを追加して、発生したイベントを示すことができます。

loggingモジュールでは、アプリケーションの操作に関連するイベントを記録する診断ログと、分析のためにユーザーのトランザクションのイベントを記録する監査ログの両方が可能です。 これは、イベントをファイルに記録するために特に使用されます。

前提条件

Python 3をインストールし、コンピューターまたはサーバーにプログラミング環境をセットアップする必要があります。 プログラミング環境をセットアップしていない場合は、ローカルプログラミング環境またはサーバー上のプログラミング環境のインストールおよびセットアップガイドを参照して、オペレーティングに適したものにすることができます。システム（Ubuntu、CentOS、Debianなど）

loggingモジュールを使用する理由

loggingモジュールは、プログラム内で発生するイベントの記録を保持し、ソフトウェアの実行時に発生するイベントのいずれかに関連する出力を確認できるようにします。

コード全体でprint()ステートメントを使用することで、イベントが発生していることを確認することに慣れている場合があります。 print()ステートメントdoesは、問題を解決するためにコードをデバッグするための基本的な方法を提供します。 コード全体にprint()ステートメントを埋め込むと、実行フローとプログラムの現在の状態を追跡できますが、このソリューションは、いくつかの理由でloggingモジュールを使用するよりも保守性が低いことがわかります。

• デバッグ出力と通常のプログラム出力は混在しているため、区別がつきにくくなります。
• コード全体に分散されたprint()ステートメントを使用する場合、デバッグ出力を提供するステートメントを無効にする効率的な方法はありません。
• デバッグが終了すると、すべてのprint()ステートメントを削除することが困難になります
• すぐに利用できる診断情報を含むログレコードはありません

コードでloggingモジュールを使用する習慣を身に付けることをお勧めします。これは、小さなPythonスクリプトを超えて成長し、デバッグへの持続可能なアプローチを提供するアプリケーションに適しているためです。

ログは、時間の経過に伴う動作とエラーを示すことができるため、アプリケーション開発プロセスで何が起こっているかをより正確に把握することもできます。

コンソールへのデバッグメッセージの印刷

情報：このチュートリアルのサンプルコードに従うには、python3コマンドを実行して、ローカルシステムでPythonインタラクティブシェルを開きます。 次に、>>>プロンプトの後に例を追加して、例をコピー、貼り付け、または編集できます。

print()ステートメントを使用してプログラムで何が発生しているかを確認することに慣れている場合は、クラスを定義し、次のようなものを生成するオブジェクトをインスタンス化するプログラムを確認することに慣れている可能性があります。

pizza.py

class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        print("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        print("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        print("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

上記のコードには、Pizzaクラスのオブジェクトのnameおよびpriceを定義する__init__メソッドがあります。 次に、ピザを作るためのmake()と呼ばれる方法と、ピザを食べるためのeat()と呼ばれる方法の2つの方法があります。 これらの2つのメソッドは、1で初期化されるquantityのパラメーターを取り込みます。

それでは、プログラムを実行してみましょう。

python pizza.py

次の出力が表示されます。

OutputPizza created: artichoke ($15)
Made 1 artichoke pizza(s)
Ate 1 pizza(s)
Pizza created: margherita ($12)
Made 2 margherita pizza(s)
Ate 1 pizza(s)

print()ステートメントを使用すると、コードが機能していることを確認できますが、代わりにloggingモジュールを使用してこれを行うことができます。

コード全体でprint()ステートメントを削除またはコメントアウトし、ファイルの先頭にimport loggingを追加しましょう。

pizza.py

import logging


class Pizza():
    def __init__(self, name, value):
        self.name = name
        self.value = value
...

loggingモジュールのデフォルトレベルはWARNINGで、DEBUGより上のレベルです。 この例ではデバッグにloggingモジュールを使用するため、logging.DEBUGのレベルでコンソールに情報が返されるように構成を変更する必要があります。 これを行うには、importステートメントの下に次の行を追加します。

pizza.py

import logging

logging.basicConfig(level=logging.DEBUG)


class Pizza():
...

このレベルのlogging.DEBUGは、しきい値を設定するために上記のコードで参照する定数整数値を参照します。 DEBUGのレベルは10です。

ここで、すべてのprint()ステートメントをlogging.debug()ステートメントに置き換えます。 定数であるlogging.DEBUGとは異なり、logging.debug()はloggingモジュールのメソッドです。 このメソッドを使用する場合、次のように、print()に渡されたものと同じ文字列を使用できます。

pizza.py

import logging

logging.basicConfig(level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

この時点で、python pizza.pyコマンドを使用してプログラムを実行すると、次の出力が表示されます。

OutputDEBUG:root:Pizza created: artichoke ($15)
DEBUG:root:Made 1 artichoke pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: margherita ($12)
DEBUG:root:Made 2 margherita pizza(s)
DEBUG:root:Ate 1 pizza(s)

ログメッセージには、重大度レベルDEBUGと、Pythonモジュールのレベルを示すrootという単語が埋め込まれています。 loggingモジュールは、異なる名前のロガーの階層で使用できるため、モジュールごとに異なるロガーを使用できます。

たとえば、ロガーを、名前と出力が異なるさまざまなロガーと同じに設定できます。

logger1 = logging.getLogger("module_1")
logger2 = logging.getLogger("module_2")

logger1.debug("Module 1 debugger")
logger2.debug("Module 2 debugger")

OutputDEBUG:module_1:Module 1 debugger
DEBUG:module_2:Module 2 debugger

loggingモジュールを使用してメッセージをコンソールに出力する方法を理解したので、次にloggingモジュールを使用してメッセージをファイルに出力する方法に移ります。

メッセージをファイルに記録する

loggingモジュールの主な目的は、メッセージをコンソールではなくファイルに記録することです。 メッセージのファイルを保持すると、コードにどのような変更を加える必要があるかを確認できるように、参照および定量化できるデータが長期にわたって提供されます。

ファイルへのログ記録を開始するには、logging.basicConfig()メソッドを変更して、filenameパラメーターを含めることができます。 この場合、ファイル名をtest.logと呼びましょう。

pizza.py

import logging

logging.basicConfig(filename="test.log", level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

上記のコードは前のセクションと同じですが、ログを印刷するためのファイル名を追加した点が異なります。 python pizza.pyコマンドを使用してコードを実行すると、ディレクトリにtest.logという新しいファイルが作成されます。

nano（または選択したテキストエディタ）でtest.logファイルを開きましょう。

nano test.log

ファイルを開くと、次のメッセージが表示されます。

test.log

DEBUG:root:Pizza created: artichoke ($15)
DEBUG:root:Made 1 artichoke pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: margherita ($12)
DEBUG:root:Made 2 margherita pizza(s)
DEBUG:root:Ate 1 pizza(s)

これは、test.logファイルにあることを除いて、前のセクションで遭遇したコンソール出力に似ています。

CTRL + xでファイルを閉じ、pizza.pyファイルに戻って、コードを変更できるようにします。

コードの大部分は同じままにしますが、2つのピザインスタンスpizza_01とpizza_02のパラメーターを変更します。

pizza.py

import logging

logging.basicConfig(filename="test.log", level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

# Modify the parameters of the pizza_01 object
pizza_01 = Pizza("Sicilian", 18)
pizza_01.make(5)
pizza_01.eat(4)

# Modify the parameters of the pizza_02 object
pizza_02 = Pizza("quattro formaggi", 16)
pizza_02.make(2)
pizza_02.eat(2)

これらの変更を加えて、python pizza.pyコマンドでプログラムを再実行してみましょう。

プログラムが実行されたら、nanoを使用してtest.logファイルを再度開くことができます。

nano test.log

ファイルを確認すると、いくつかの新しい行が追加され、プログラムが最後に実行されたときの前の行が保持されていることがわかります。

test.log

DEBUG:root:Pizza created: artichoke ($15)
DEBUG:root:Made 1 artichoke pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: margherita ($12)
DEBUG:root:Made 2 margherita pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: Sicilian ($18)
DEBUG:root:Made 5 Sicilian pizza(s)
DEBUG:root:Ate 4 pizza(s)
DEBUG:root:Pizza created: quattro formaggi ($16)
DEBUG:root:Made 2 quattro formaggi pizza(s)
DEBUG:root:Ate 2 pizza(s)

この情報は確かに役立ちますが、 LogRecord属性を追加することで、ログをより有益なものにすることができます。 主に、LogRecordがいつ作成されたかを示す人間が読めるタイムスタンプを追加したいと思います。

その属性をformatというパラメーターに追加し、表に示すように文字列%(asctime)sで参照できます。 さらに、DEBUGレベル名を保持するには、文字列%(levelname)sを含める必要があり、ロガーに印刷するように要求する文字列メッセージを保持するには、[を含めます。 X176X]。 追加されたコードに示すように、これらの各属性はcolonで区切られます。

pizza.py

import logging

logging.basicConfig(
    filename="test.log",
    level=logging.DEBUG,
    format="%(asctime)s:%(levelname)s:%(message)s"
    )


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("Sicilian", 18)
pizza_01.make(5)
pizza_01.eat(4)

pizza_02 = Pizza("quattro formaggi", 16)
pizza_02.make(2)
pizza_02.eat(2)

python pizza.pyコマンドで属性を追加して上記のコードを実行すると、レベル名に加えて人間が読めるタイムスタンプを含む新しい行がtest.logファイルに追加されます。 DEBUGおよび文字列としてロガーに渡される関連メッセージの。

test.log

DEBUG:root:Pizza created: Sicilian ($18)
DEBUG:root:Made 5 Sicilian pizza(s)
DEBUG:root:Ate 4 pizza(s)
DEBUG:root:Pizza created: quattro formaggi ($16)
DEBUG:root:Made 2 quattro formaggi pizza(s)
DEBUG:root:Ate 2 pizza(s)
2021-08-19 23:31:34,484:DEBUG:Pizza created: Sicilian ($18)
2021-08-19 23:31:34,484:DEBUG:Made 5 Sicilian pizza(s)
2021-08-19 23:31:34,484:DEBUG:Ate 4 pizza(s)
2021-08-19 23:31:34,484:DEBUG:Pizza created: quattro formaggi ($16)
2021-08-19 23:31:34,484:DEBUG:Made 2 quattro formaggi pizza(s)
2021-08-19 23:31:34,484:DEBUG:Ate 2 pizza(s)

必要に応じて、プログラムファイルのログを関連性のあるものにするために、コードで追加のLogRecord属性を使用することをお勧めします。

デバッグメッセージやその他のメッセージを別々のファイルに記録すると、Pythonプログラムを全体的に理解できるようになり、プログラムに加えられた過去の作業や、発生するイベントとトランザクション。

ロギングレベルの表

開発者は、重大度レベルを追加することで、ロガーでキャプチャされたイベントに重要度のレベルを割り当てることができます。 重大度レベルを次の表に示します。

ロギングレベルは技術的には整数（定数）であり、ロガーを数値0で初期化するNOTSETから始まり、すべて10の増分です。

事前定義されたレベルに関連する独自のレベルを定義することもできます。 同じ数値でレベルを定義すると、その値に関連付けられている名前が上書きされます。

次の表に、さまざまなレベル名、それらの数値、レベルの呼び出しに使用できる関数、およびそのレベルの使用目的を示します。

レベル	数値	働き	慣れている
CRITICAL	50	logging.critical()	重大なエラーが表示された場合、プログラムは実行を継続できない可能性があります
ERROR	40	logging.error()	より深刻な問題を表示する
WARNING	30	logging.warning()	予期しないことが起こった、または起こる可能性があることを示します
INFO	20	logging.info()	物事が期待どおりに機能していることを確認します
DEBUG	10	logging.debug()	問題を診断し、詳細情報を表示する

loggingモジュールはデフォルトレベルをWARNINGに設定するため、WARNING、ERROR、およびCRITICALはすべてデフォルトでログに記録されます。 上記の例では、次のコードでDEBUGレベルを含むように構成を変更しました。

logging.basicConfig(level=logging.DEBUG)

コマンドとデバッガーの操作の詳細については、公式のログドキュメントを参照してください。

結論

デバッグは、ソフトウェア開発プロジェクトの重要なステップです。 loggingモジュールは標準のPythonライブラリの一部であり、ソフトウェアの実行中に発生するイベントの追跡を提供し、これらのイベントを別のログファイルに出力して、コードの実行中に発生するイベントを追跡できます。 これにより、プログラムの実行によって発生するさまざまなイベントを理解することに基づいて、コードをデバッグする機会が得られます。