ハイパー仕事し隊

思い立った吉日！イロイロ試してオンリーワンの起業家を目指してます！

現在の場所：ホーム / ウェブアプリ関連 / 【Python】Print なのか Logging なのか問題を考える

【Python】Print なのか Logging なのか問題を考える

Python の勉強をしていると、logging モジュールを使ったログ出力は、プログラムの動作が意図した通り or 意図しない流れになっているのかがわかるので、

「開発者として利用すべき」

であったり

「ベストプラクティス」

と言われてたりしていますが、文字列出力するなら print で良いんじゃない？？と疑問に思っていました。

きっとプログラミングを学びはじめなら誰もが疑問に思うと思います。

イロイロ調べてわかったので、まとめてみました！ぜひ参考にして下さい！

結論

簡単にまとめると下記のようになります。

  • print: 標準出力/標準エラー (stdout/stderr) のみの出力で、出力内容も固定されているので、デバッグ用ではない
  • logging: 必要なときに必要な量の情報をいろんな出力 (例: socket) ができるの。例: デバッグ時に必要な詳細情報を取得できたり、パフォーマンスのチェックやユーザーの利用パターンが分かったりできる。

参考 URL:

Logging でできること

logging は Python の標準ライブラリなので、すぐに利用ができます。

logging の機能は、公式ページにてとてもわかり易く説明されていましたので、引用します。
(ref.: https://docs.python.org/ja/3/howto/logging.html)

logging は、あるソフトウェアが実行されているときに起こったイベントを追跡するための手段です。ソフトウェアの開発者は、特定のイベントが発生したことを示す logging の呼び出しをコードに加えます。イベントは、メッセージで記述され、これに変数データ (すなわち、イベントが起こる度に異なるかもしれないデータ) を加えることもできます。イベントには、開発者がそのイベントに定めた重要性も含まれます。重要性は、レベル (level) や 重大度 (severity) とも呼ばれます。

上記で言う重要性は、以下のように定義されています。

  1. DEBUG
    • 開発中に、原因を突き止めやすくするために、詳細な情報を出力したいときに利用します。
  2. INFO
    • アプリ運用中には、イベントの発生情報 (または、想定通りの動作情報) を出すときに利用します。
    • 例: 「リクエスト来たよ。」「ソケット開けたよ。」など
  3. WARNING
    • 今は問題ではないけど、今後の運用で注意が必要な情報出力として利用します。
    • 例: 「空き容量が残り 20% だよ！」
  4. ERROR
    • 機能実行でエラーが発生した際に利用ります。
    • 例: 「〇〇関数の実行に失敗」「〇〇モジュールインポートに失敗」
  5. CRITICAL
    • 大問題が発生し、アプリ動作がおかしいときに利用します。
    • 例: 「アプリを強制終了します。」

サンプルコードがこちら。

import logging

logging.debug('This is a debug message')
logging.info('This is an info message')
logging.warning('This is a warning message')
logging.error('This is an error message')
logging.critical('This is a critical message')

 

そして、実行結果は特に何も設定していないので、デフォルト出力先のコンソールへ出力されます。

WARNING:root:This is a warning message
ERROR:root:This is an error message
CRITICAL:root:This is a critical message

デフォルトのログレベルは、level=WARNING で、このレベル以上のイベントが発生したときのみ出力されます。

Logging を使うべき理由

それでは print ではなく、logging を使うべき理由をまとめます。
やりようによっては print でもできたりしますが、実装のしやすさや汎用性を考えると logging の方が良さそうです。

タイムスタンプが出力できる(ログ機能では当たり前ですが。。)

ログ解析をするに、タイムスタンプはとれも重要な情報になります。例えば、

  • 「このエラーは、データベース接続前にでたのか、接続後に出たのか？」
  • 「エラー発生は、ディスク容量が一定値を超える前なのか後だったのか？」
  • 「このリクエストはいつ来たんだ？」

ということがわかるようになります。

どこで起きたエラーかがわかる

「エラーが出た！」だけでは、どこから手をつけてよいのかわかりませんね。ですが、logging を使うことで

  • ファイル名: %(filename)s
  • モジュール名: %(module)s
  • 関数名: %(funcName)s
  • 行番号: %(lineno)d
  • プロセスID: %(process)d
  • スレッドID: %(thread)d

と、Formatter というものに設定することで、細かく情報の出力コントロールができます。

その他にも色々と設定ができます。詳細は確認できます。
[公式ページ] LogRecord 属性

ログレベルに応じて、出力先をコントロールできる

Handler というものを使って、出力方法を設定できます。
その Handler にはいくつかの種類があります(以下は抜粋)。

  • StreamHandler: 標準出力でコンソールに出力
  • FileHandler: ファイルに出力
  • HTTPHandler: HTTP 経由で出力

これらの handler を使って、どこに情報を出力するかを設定できます。

参考までに、log4mongo (https://pypi.org/project/log4mongo/) を使うと MongoDB に logging 情報を送ることができます。

また、それらの handler はいくつも設定できるので「開発中は DEBUG ログを、一般公開版は INFO ログを出力する」ということができます。

コードサンプル

まとめるとこのようなコードになります。

import logging

# logger を生成
logger = logging.getLogger(__name__)

# handlers の設定
std_handler = logging.StreamHandler()
file_handler = logging.FileHandler('debug.log')

std_handler.setLevel(logging.WARNING)
file_handler.setLevel(logging.ERROR)

# formatters の設定
std_format = logging.Formatter("%(name)s - %(levelname)s - %(message)s")
file_format = logging.Formatter("%(asctime)s\t%(levelname)s -- %(processName)s -- %(filename)s:%(lineno)s -- %(message)s")

std_handler.setFormatter(std_format)
file_handler.setFormatter(file_format)

# logger に handler を追加
logger.addHandler(std_handler)
logger.addHandler(file_handler)

logger.warning('This is a warning')
logger.error('This is an error')

いかがでしたでしょうか？

いつもはデバッガを使っているので、あまり気にしていませんでしたが、実運用に向けてこれからは logging を使った方が良いと思いました。

もしベストプラクティス的なのをご存知であれば、ぜひ教えて下さい！