Python3でロギングを使用する方法
序章
logging
モジュールは標準のPythonライブラリの一部であり、ソフトウェアの実行中に発生するイベントの追跡を提供します。 コードにロギング呼び出しを追加して、発生したイベントを示すことができます。
logging
モジュールでは、アプリケーションの操作に関連するイベントを記録する診断ログと、分析のためにユーザーのトランザクションのイベントを記録する監査ログの両方が可能です。 これは、イベントをファイルに記録するために特に使用されます。
前提条件
Python 3をインストールし、コンピューターまたはサーバーにプログラミング環境をセットアップする必要があります。 プログラミング環境をセットアップしていない場合は、ローカルプログラミング環境またはサーバー上のプログラミング環境のインストールおよびセットアップガイドを参照して、オペレーティングに適したものにすることができます。システム(Ubuntu、CentOS、Debianなど)
logging
モジュールを使用する理由
logging
モジュールは、プログラム内で発生するイベントの記録を保持し、ソフトウェアの実行時に発生するイベントのいずれかに関連する出力を確認できるようにします。
コード全体でprint()
ステートメントを使用することで、イベントが発生していることを確認することに慣れている場合があります。 print()
ステートメントdoesは、問題を解決するためにコードをデバッグするための基本的な方法を提供します。 コード全体にprint()
ステートメントを埋め込むと、実行フローとプログラムの現在の状態を追跡できますが、このソリューションは、いくつかの理由でlogging
モジュールを使用するよりも保守性が低いことがわかります。
- デバッグ出力と通常のプログラム出力は混在しているため、区別がつきにくくなります。
- コード全体に分散された
print()
ステートメントを使用する場合、デバッグ出力を提供するステートメントを無効にする効率的な方法はありません。 - デバッグが終了すると、すべての
print()
ステートメントを削除することが困難になります - すぐに利用できる診断情報を含むログレコードはありません
コードでlogging
モジュールを使用する習慣を身に付けることをお勧めします。これは、小さなPythonスクリプトを超えて成長し、デバッグへの持続可能なアプローチを提供するアプリケーションに適しているためです。
ログは、時間の経過に伴う動作とエラーを示すことができるため、アプリケーション開発プロセスで何が起こっているかをより正確に把握することもできます。
コンソールへのデバッグメッセージの印刷
情報:このチュートリアルのサンプルコードに従うには、python3
コマンドを実行して、ローカルシステムでPythonインタラクティブシェルを開きます。 次に、>>>
プロンプトの後に例を追加して、例をコピー、貼り付け、または編集できます。
print()
ステートメントを使用してプログラムで何が起こっているかを確認することに慣れている場合は、クラスを定義し、次のようなものを生成するオブジェクトをインスタンス化するプログラムを確認することに慣れているかもしれません。
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
を追加しましょう。
import logging
class Pizza():
def __init__(self, name, value):
self.name = name
self.value = value
...
logging
モジュールのデフォルトレベルはWARNING
で、DEBUG
より上のレベルです。 この例ではデバッグにlogging
モジュールを使用するため、logging.DEBUG
のレベルでコンソールに情報が返されるように構成を変更する必要があります。 これを行うには、importステートメントの下に次の行を追加します。
import logging
logging.basicConfig(level=logging.DEBUG)
class Pizza():
...
このレベルのlogging.DEBUG
は、しきい値を設定するために上記のコードで参照する定数整数値を参照します。 DEBUG
のレベルは10です。
ここで、すべてのprint()
ステートメントをlogging.debug()
ステートメントに置き換えます。 定数であるlogging.DEBUG
とは異なり、logging.debug()
はlogging
モジュールのメソッドです。 このメソッドを使用する場合、次のように、print()
に渡されたものと同じ文字列を使用できます。
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
と呼びましょう。
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
ファイルを開くと、次のメッセージが表示されます。
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
のパラメーターを変更します。
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
ファイルを確認すると、いくつかの新しい行が追加され、プログラムが最後に実行されたときの前の行が保持されていることがわかります。
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
を含める必要があり、ロガーに印刷するように要求する文字列メッセージを保持するには、colon
で区切られます。
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
および文字列としてロガーに渡される関連メッセージの。
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ライブラリの一部であり、ソフトウェアの実行中に発生するイベントの追跡を提供し、これらのイベントを別のログファイルに出力して、コードの実行中に発生するイベントを追跡できるようにします。 これにより、プログラムの実行中に発生するさまざまなイベントを理解することに基づいて、コードをデバッグする機会が得られます。