Logging HOWTO
*************

著者:
   Vinay Sajip <vinay_sajip at red-dove dot com>


基本 logging チュートリアル
===========================

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


logging を使うとき
------------------

logging は、単純なロギングの用法に便利な関数群を提供しています。この中
には、 "debug()", "info()", "warning()", "error()" および "critical()"
があります。logging を使うべき時を決めるには、よくあるタスクに使う最適
なツールを述べた、以下のテーブルを参照してください。

+---------------------------------------+----------------------------------------+
| 行いたいタスク                        | そのタスクに最適なツール               |
|=======================================|========================================|
| コマンドラインスクリプトやプログラム  | "print()"                              |
| で普通に使う、コンソール出力の表示    |                                        |
+---------------------------------------+----------------------------------------+
| プログラムの通常の操作中に発生したイ  | "logging.info()" (または、診断のための |
| ベントの報告 (例えば、状態の監視や 障 | 特に詳細な出力には "logging.debug()")  |
| 害の分析)                             |                                        |
+---------------------------------------+----------------------------------------+
| 特定のランタイムイベントに関わる警告  | その発行が避けられるもので、クライアン |
| の発行                                | トアプリケーションを修正してその 警告  |
|                                       | を排除するべきなら "warnings.warn()"   |
|                                       | アプリケーションにできることはないが、 |
|                                       | それでもイベントを記録するべきな ら    |
|                                       | "logging.warning()"                    |
+---------------------------------------+----------------------------------------+
| 特定のランタイムイベントに関わるエラ  | 例外の送出                             |
| ーの報告                              |                                        |
+---------------------------------------+----------------------------------------+
| 例外の送出をしないエラーの抑制 (例え  | 特定のエラーやアプリケーションドメイン |
| ば、長期のサーバプロセス中のエラー ハ | に応じて "logging.error()",            |
| ンドラ)                               | "logging.exception()" または           |
|                                       | "logging.critical()"                   |
+---------------------------------------+----------------------------------------+

ロギング関数は、そのイベントのレベルや重大度から名前を付けられ、それが
追跡に使われます。標準のレベルとその適用範囲は、以下に (重大度が増す順
に) 記述されています:

+----------------+-----------------------------------------------+
| レベル         | いつ使うか                                    |
|================|===============================================|
| "DEBUG"        | おもに問題を診断するときにのみ関心があるよう  |
|                | な、詳細な情報。                              |
+----------------+-----------------------------------------------+
| "INFO"         | 想定された通りのことが起こったことの確認。    |
+----------------+-----------------------------------------------+
| "WARNING"      | 想定外のことが起こった、または問題が近く起こ  |
|                | りそうである (例えば、 'disk space low') こと |
|                | の表示。                                      |
+----------------+-----------------------------------------------+
| "ERROR"        | より重大な問題により、ソフトウェアがある機能  |
|                | を実行できないこと。                          |
+----------------+-----------------------------------------------+
| "CRITICAL"     | プログラム自体が実行を続けられないことを表す  |
|                | 、重大なエラー。                              |
+----------------+-----------------------------------------------+

デフォルトのレベルは "WARNING" で、logging パッケージが他に設定されな
ければ、このレベル以上のイベントのみ追跡されます。

追跡されるイベントは、異なる方法で処理されます。追跡されたイベントを処
理する最も単純な方法は、それをコンソールに表示することです。その他のよ
くある方法は、それをディスクファイルに書き出すことです。


簡単な例
--------

ごく簡単な例は:

   import logging
   logging.warning('Watch out!')  # will print a message to the console
   logging.info('I told you so')  # will not print anything

これらの行をスクリプトにタイプして実行すると、次のようにコンソールに出
力されます:

   WARNING:root:Watch out!

デフォルトのレベルは "WARNING" なので、"INFO" メッセージは現れません。
表示されたメッセージには、レベルの表示と、ロギングの呼び出しで提供され
た、イベントの説明すなわち 'Watch out!' が含まれます。'root' の部分は
今は気にしないでください。あとで説明します。実際の出力は、必要に応じて
かなり柔軟に書式化できます。書式化操作もあとで説明します。


ファイルへの logging
--------------------

logging イベントをファイルに記録するのは非常によくあるパターンなので次
はこれを見て行きましょう。以下のサンプルを試すときは Python インタプリ
タを新しく起動して、上のセッションの続きにならないようにしてください:

   import logging
   logging.basicConfig(filename='example.log', encoding='utf-8', level=logging.DEBUG)
   logging.debug('This message should go to the log file')
   logging.info('So should this')
   logging.warning('And this, too')
   logging.error('And non-ASCII stuff, too, like Øresund and Malmö')

バージョン 3.9 で変更: *encoding* 引数が追加されました。以前のバージョ
ンの Python では、あるいは指定されなかったら、エンコーディングには
"open()" が使うデフォルト値が使われます。上の例に出てきていませんが、
同じく渡せるようになった *errors* 引数は、エンコーディングエラーの扱い
を決定します。利用可能な値およびデフォルト値については、 "open()" のド
キュメントを参照してください。

そして、ファイルの中身を確認すると、ログメッセージが確認できます:

   DEBUG:root:This message should go to the log file
   INFO:root:So should this
   WARNING:root:And this, too
   ERROR:root:And non-ASCII stuff, too, like Øresund and Malmö

この例はまた、追跡のしきい値となるロギングレベルを設定する方法も示して
います。この例では、しきい値を "DEBUG" に設定しているので、全てのメッ
セージが表示されています。

次のようなコマンドラインオプションでログレベルを設定したいと考え:

   --log=INFO

"--log" に渡されたパラメータの値を変数 *loglevel* に保存しているとした
ら、

   getattr(logging, loglevel.upper())

というコードを使い、 "basicConfig()" の *level* 引数に渡すべき値が得ら
れます。ユーザの入力値をすべてエラーチェックしたくなり、次の例のように
実装することもあるでしょう:

   # assuming loglevel is bound to the string value obtained from the
   # command line argument. Convert to upper case to allow the user to
   # specify --log=DEBUG or --log=debug
   numeric_level = getattr(logging, loglevel.upper(), None)
   if not isinstance(numeric_level, int):
       raise ValueError('Invalid log level: %s' % loglevel)
   logging.basicConfig(level=numeric_level, ...)

"basicConfig()" の呼び出しは "debug()", "info()" などの呼び出しの *前
に* 行わなければなりません。さもなければ、他の関数の内部で
"basicConfig()" がデフォルトのオプションで呼び出されてしまいます。この
関数は一度限りの単純な設定機能を意図しているため、最初の呼び出しだけが
実際に設定作業を行います: それ以降の呼び出しは実効的に何もしません。

上記のスクリプトを複数回実行すると、2 回目以降の実行によるメッセージは
*example.log* に加えられます。以前の実行によるメッセージを記憶せず、実
行ごとに新たに始めたいなら、上記の例での呼び出しを次のように変え、
*filemode* 引数を指定する方法がとれます:

   logging.basicConfig(filename='example.log', filemode='w', level=logging.DEBUG)

出力は先ほどと同じになりますが、ログファイルは追記されなくなり、以前の
実行によるメッセージは失われます。


複数のモジュールからのロギング
------------------------------

プログラムが複数のモジュールでできているなら、そのロギングをどのように
構成するかの例はこちらです:

   # myapp.py
   import logging
   import mylib

   def main():
       logging.basicConfig(filename='myapp.log', level=logging.INFO)
       logging.info('Started')
       mylib.do_something()
       logging.info('Finished')

   if __name__ == '__main__':
       main()

   # mylib.py
   import logging

   def do_something():
       logging.info('Doing something')

*myapp.py* を実行すれば、*myapp.log* でログが確認できます:

   INFO:root:Started
   INFO:root:Doing something
   INFO:root:Finished

この *mylib.py* でのパターンは、複数のモジュールに一般化できます。なお
、この簡単な使用パターンでは、ログファイルを見ることで、イベントの説明
は見られますが、アプリケーションの *どこから* メッセージが来たのかを知
ることはできません。メッセージの位置を追跡したいなら、このチュートリア
ルレベルを超えたドキュメントが必要になります -- 上級ロギングチュートリ
アル を参照してください。


変数データのロギング
--------------------

変数データのログを取るには、イベント記述メッセージにフォーマット文字列
を使い、引数に変数データを加えてください。例えば:

   import logging
   logging.warning('%s before you %s', 'Look', 'leap!')

により、次のように表示されます:

   WARNING:root:Look before you leap!

ご覧の通り、イベント記述メッセージに変数データを統合するために、古い、
% スタイルの文字列フォーマットを使っています。これは後方互換性のためで
す。logging パッケージは、 "str.format()" や "string.Template" のよう
な新しいフォーマットオプションよりも先に生まれました。新しいフォーマッ
トオプションはサポートされて *います* が、その探求はこのチュートリアル
では対象としません。詳細は 固有の書式化スタイルをアプリケーション全体
で使う を参照してください。


表示されるメッセージのフォーマットの変更
----------------------------------------

メッセージを表示するのに使われるフォーマットを変更するには、使いたいフ
ォーマットを指定する必要があります:

   import logging
   logging.basicConfig(format='%(levelname)s:%(message)s', level=logging.DEBUG)
   logging.debug('This message should appear on the console')
   logging.info('So should this')
   logging.warning('And this, too')

により、次のように表示されます:

   DEBUG:This message should appear on the console
   INFO:So should this
   WARNING:And this, too

ご覧の通り、先の例に現れた 'root' が消失しています。フォーマット文字列
に含めることができるものの一覧は、 LogRecord 属性 のドキュメントから参
照できますが、単純な用途では、必要なものは *levelname* (重大度)、
*message* (変数データを含むイベント記述)、それともしかしたら、イベント
がいつ起こったかという表示だけです。これは次の節で解説します。


メッセージ内での日付と時刻の表示
--------------------------------

イベントの日付と時刻を表示するには、フォーマット文字列に '%(asctime)s'
を置いてください:

   import logging
   logging.basicConfig(format='%(asctime)s %(message)s')
   logging.warning('is when this event was logged.')

これは以下の様なフォーマットで表示されます:

   2010-12-12 11:41:42,612 is when this event was logged.

デフォルトの日付と時間の表示フォーマット （上記の結果） は、ISO8601 や
**RFC 3339** に似ています。日付と時間のフォーマットをより詳細に制御す
る必要があるなら、以下の例の様に、 "basicConfig" に *datefmt* 引数を指
定してください:

   import logging
   logging.basicConfig(format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p')
   logging.warning('is when this event was logged.')

これは次のように表示されます:

   12/12/2010 11:46:36 AM is when this event was logged.

*datefmt* 引数のフォーマットは、 "time.strftime()" でサポートされてい
るものと同じです。


次のステップ
------------

基本チュートリアルはこれで終わりです。あなたがロギングを使っていくため
には、これで十分でしょう。logging パッケージが提供するものはもっとあり
ますが、それを使いこなすためには、もうちょっと時間をかけて、以下のセク
ションを読む必要があります。その用意ができたら、好きな飲み物を持って、
次に進みましょう。

ロギングを簡潔に行いたいなら、上記の例を使って、ロギングをあなたのスク
リプトに組み込んでください。問題があったり理解出来ないことがあったら、
comp.lang.python Usenet group
(https://groups.google.com/forum/#!forum/comp.lang.python から利用でき
ます) に質問を投稿してくだされば、そう遠くないうちに助けが得られるでし
ょう。

まだいますか？もう少し上級の、踏み込んだチュートリアルを綴った、幾つか
の節を読み続けることができます。その後で、 Logging クックブック もご覧
ください。


上級ロギングチュートリアル
==========================

logging ライブラリはモジュール方式のアプローチを取り、いくつかのカテゴ
リの部品を提供します。ロガー、ハンドラ、フィルタ、フォーマッタです。

* ロガーは、アプリケーションコードが直接使うインターフェースを公開しま
  す。

* ハンドラは、(ロガーによって生成された) ログ記録を適切な送信先に送り
  ます。

* フィルタは、どのログ記録を出力するかを決定する、きめ細かい機能を提供
  します。

* フォーマッタは、ログ記録が最終的に出力されるレイアウトを指定します。

ログイベント情報は "LogRecord" インスタンスの形で、 logger, handler,
filter, formatter の間でやりとりされます。

ロギングは、 "Logger" クラスのインスタンス (以下 *ロガー*) にメソッド
を呼び出すことで実行されます。各インスタンスには名前があり、名前空間階
層構造に、ドット (ピリオド) をセパレータとして、概念的に並べられていま
す。例えば、 'scan' という名前のロガーは、ロガー 'scan.text',
'scan.html' および 'scan.pdf'の親です。ロガー名は、何でも望むものにで
き、ロギングされたメッセージが発生した場所を指し示します。

ロガーに名前をつけるときの良い習慣は、ロギングを使う各モジュールに、以
下のように名付けられた、モジュールレベルロガーを使うことです:

   logger = logging.getLogger(__name__)

これにより、ロガー名はパッケージ/モジュール階層をなぞり、ロガー名だけ
で、どこでイベントのログが取られたか、直感的に明らかになります。

ロガーの階層構造の根源は、ルートロガーと呼ばれます。それが、関数
"debug()", "info()", "warning()", "error()" および "critical()" によっ
て使われるロガーとなります。これらの関数は単に、ルートロガーの同名のメ
ソッドを呼び出します。これらの関数とメソッドは、同じ署名をもっています
。ルートロガーの名前は、ログ出力では 'root' と表示されます。

もちろん、メッセージを異なる送信先に記録することも出来ます。このパッケ
ージでは、ファイルへ、 HTTP GET/POST 先へ、 SMTP 経由で電子メールへ、
汎用のソケットへ、キューへ、または Windows NT イベントログのような OS
毎のログ記録機構への、ログメッセージの書きこみがサポートされています。
送信先は、 *handler* クラスによって取り扱われます。組み込みのハンドラ
クラスでは満たせないような、特殊な要件があるなら、独自のログ送信先を生
成できます。

デフォルトでは、どのロギングメッセージに対しても、送信先は設定されてい
ません。チュートリアルの例のように、 "basicConfig()" を使って、送信先
(コンソールやファイルなど) を指定できます。関数 "debug()", "info()",
"warning()", "error()" および "critical()" を呼び出すと、それらは送信
先が設定されていないかを調べます。そして設定されていなければ、ルートロ
ガーに委譲して実際にメッセージを出力する前に、コンソール
("sys.stderr") を送信先に、デフォルトのフォーマットを表示されるメッセ
ージに設定します。

"basicConfig()" が設定するデフォルトのメッセージのフォーマットは次のよ
うになります:

   severity:logger name:message

"basicConfig()" の *format* キーワード引数にフォーマット文字列を渡すこ
とで、これを変更できます。フォーマット文字列を構成するためのすべてのオ
プションは、 フォーマッタオブジェクト を参照してください。


Logging Flow
------------

次の図はログイベントが logger と handler をどう流れるかを示しています
。

[画像]


ロガー
------

"Logger" オブジェクトの仕事は大きく三つに分かれます。一つ目は、アプリ
ケーションが実行中にメッセージを記録できるように、いくつかのメソッドを
アプリケーションから呼べるようにしています。二つ目に、ロガーオブジェク
トはどのメッセージに対して作用するかを、深刻度 (デフォルトのフィルタ機
構) またはフィルタオブジェクトに基づいて決定します。三つ目に、ロガーオ
ブジェクトは関心を持っているすべてのログハンドラに関連するログメッセー
ジを回送します。

とりわけ広く使われるロガーオブジェクトのメソッドは、二つのカテゴリーに
分類できます: 設定とメッセージ送信です。

これらが設定メソッドの中でよく使われます:

* "Logger.setLevel()" はロガーが扱うログメッセージの最も低い深刻度を指
  定します。組み込みの深刻度の中では DEBUG が一番低く、 CRITICAL が一
  番高くなります。たとえば、深刻度が INFO と設定されたロガーは INFO,
  WARNING, ERROR, CRITICAL のメッセージしか扱わず、 DEBUG メッセージは
  無視します。

* "Logger.addHandler()" と "Logger.removeHandler()" は、ハンドラオブジ
  ェクトをロガーオブジェクトから追加または削除します。ハンドラについて
  は、 ハンドラ で詳しく述べます。

* "Logger.addFilter()" と "Logger.removeFilter()" はロガーオブジェクト
  にフィルタオブジェクトを追加または削除します。フィルタについては、
  フィルタオブジェクト で詳しく述べます。

これらのメソッドを、生成したすべてのロガーに毎回呼び出さなければならな
いわけではありません。この節の最後の 2 段落を参照してください。

ロガーオブジェクトが設定されれば、以下のメソッドがログメッセージを生成
します:

* "Logger.debug()", "Logger.info()", "Logger.warning()",
  "Logger.error()", "Logger.critical()" はすべて、メッセージとメソッド
  名に対応したレベルでログ記録を作り出します。メッセージは実際にはフォ
  ーマット文字列であり、通常の文字列代入に使う "%s", "%d", "%f" などを
  含むことができます。残りの引数はメッセージの代入される位置に対応する
  オブジェクトのリストです。 "**kwargs" については、ログ記録メソッドが
  気にするキーワードは "exc_info" だけで、例外の情報をログに記録するか
  を決定するのに使います。

* "Logger.exception()" は "Logger.error()" と似たログメッセージを作成
  します。違いは "Logger.exception()" がスタックトレースを一緒にダンプ
  することです。このメソッドは例外ハンドラからだけ呼び出すようにしてく
  ださい。

* "Logger.log()" はログレベルを明示的な引数として受け取ります。これは
  上に挙げた便宜的なログレベル毎のメソッドを使うより少しコード量が多く
  なりますが、独自のログレベルを使うことができます。

"getLogger()" は、指定されればその特定の名前の、そうでなければ "root"
のロガーインスタンスへの参照を返します。ロガーの名前はピリオド区切りの
階層構造を表します。同じ名前で "getLogger()" を複数回呼び出した場合、
同一のロガーオブジェクトへの参照が返されます。階層リストを下ったロガー
はリスト上位のロガーの子です。たとえば、名前が "foo" であるロガーがあ
ったとして、 "foo.bar", "foo.bar.baz", "foo.bam" といった名前のロガー
はすべて "foo" の子孫になります。

ロガーには、*有効レベル (effective level)* の概念があります。ロガーに
レベルが明示的に設定されていなければ、代わりに親のレベルがその有効レベ
ルとして使われます。親のレベルが設定されなければ、*その* 親のレベルが
確かめられ、明示的に設定されたレベルが見つかるまで祖先が探されます。ル
ートロガーは、必ず明示的なレベルが設定されています (デフォルトでは
"WARNING" です)。イベントを処理するかを決定するとき、ロガーの有効レベ
ルを使って、イベントがロガーのハンドラに渡されるかが決められます。

子ロガーはメッセージを親ロガーのハンドラに伝えます。このため、アプリケ
ーションが使っているすべてのロガーのためのハンドラを定義して設定する必
要はありません。トップレベルのロガーのためのハンドラだけ設定しておいて
必要に応じて子ロガーを作成すれば十分です。(しかし、ロガーの
*propagate* 属性を "False" に設定することで、伝播を抑制できます。)


ハンドラ
--------

"Handler" オブジェクトは適切なログメッセージを (ログメッセージの深刻度
に基づいて) ハンドラの指定された出力先に振り分けることに責任を持ちます
。 "Logger" オブジェクトには "addHandler()" メソッドで 0 個以上のハン
ドラを追加することができます。例として、あるアプリケーションがすべての
ログメッセージをログファイルに、 error 以上のすべてのログメッセージを
標準出力に、 critical のメッセージはすべてメールアドレスに、それぞれ送
りたいとします。この場合、 3 つの個別のハンドラがそれぞれの深刻度と宛
先に応じて必要になります。

このライブラリには多くのハンドラが用意されています (便利なハンドラ を
参照してください) が、このチュートリアルでは "StreamHandler" と
"FileHandler" だけを例に取り上げます。

アプリケーション開発者にとってハンドラを扱う上で気にするべきメソッドは
極々限られています。組み込みのハンドラオブジェクトを使う (つまり自作ハ
ンドラを作らない) 開発者に関係あるハンドラのメソッドは、次の設定用のメ
ソッドだけでしょう:

* "setLevel()" メソッドは、ロガーオブジェクトの場合と同様に、適切な出
  力先に振り分けられるべき最も低い深刻度を指定します。なぜ 2 つも
  "setLevel()" メソッドがあるのでしょうか? ロガーで設定されるレベルは
  、付随するハンドラにどんな深刻度のメッセージを渡すか決めます。それぞ
  れのハンドラで設定されるレベルは、そのハンドラがどのメッセージを転送
  するべきか決めます。

* "setFormatter()" でこのハンドラが使用する Formatter オブジェクトを選
  択します。

* "addFilter()" および "removeFilter()" はそれぞれハンドラへのフィルタ
  オブジェクトの設定と解除を行います。

アプリケーションのコード中では "Handler" のインスタンスを直接インスタ
ンス化して使ってはなりません。代わりに、 "Handler" クラスはすべてのハ
ンドラが持つべきインターフェイスを定義する基底クラスであり、子クラスが
使える (もしくはオーバライドできる) いくつかのデフォルトの振る舞いを規
定します。


フォーマッタ
------------

フォーマッタオブジェクトは最終的なログメッセージの順序、構造および内容
を設定します。基底クラスである "logging.Handler" とは違って、アプリケ
ーションのコードはフォーマッタクラスをインスタンス化しても構いません。
特別な振る舞いをさせたいアプリケーションではフォーマッタのサブクラスを
使う可能性もあります。コンストラクタは三つのオプション引数を取ります
-- メッセージのフォーマット文字列、日付のフォーマット文字列、スタイル
標識です。

logging.Formatter.__init__(fmt=None, datefmt=None, style='%')

フォーマット文字列に何も渡さない場合は、デフォルトで行メッセージが利用
されます。また、日付フォーマットに何も渡さない場合は、デフォルトで以下
のフォーマットが利用されます:

   %Y-%m-%d %H:%M:%S

時刻の末尾にはミリ秒が付きます。 "style" は "'%'", "'{'", または
"'{TX-PL-LABEL}#x27;" のいずれかです。特に指定がなければ "'%'" が使わ
れます。

"style" が "'%'" の場合、メッセージフォーマット文字列では
"%(<dictionary key>)s" 形式の置換文字列が使われます; キーに指定できる
属性名は LogRecord 属性 に文書化されています。 style が "'{'" の場合、
メッセージフォーマット文字列は (キーワード引数を使う) "str.format()"
と互換となります。 style が "'$'" の場合、メッセージフォーマット文字列
は "string.Template.substitute()" で期待されているものと一致します。

バージョン 3.2 で変更: "style" パラメータが追加されました。

次のメッセージフォーマット文字列は、人が読みやすい形式の時刻、メッセー
ジの深刻度、およびメッセージの内容を、順番に出力します:

   '%(asctime)s - %(levelname)s - %(message)s'

フォーマッタは、ユーザが設定できる関数を使って、生成時刻をタプルに記録
します。デフォルトでは、 "time.localtime()" が使われます。特定のフォー
マッタインスタンスに対してこれを変更するには、インスタンスの
"converter" 属性を "time.localtime()" や "time.gmtime()" と同じ署名を
もつ関数に設定してください。すべてのフォーマッタインスタンスに対してこ
れを変更するには、例えば全てのロギング時刻を GMT で表示するには、フォ
ーマッタクラスの "converter" 属性を (GMT 表示の "time.gmtime" に) 設定
してください。


ロギングの環境設定
------------------

プログラマは、ロギングを 3 種類の方法で設定できます:

1. 上述の設定メソッドを呼び出す Python コードを明示的に使って、ロガー
   、ハンドラ、そしてフォーマッタを生成する。

2. ロギング設定ファイルを作り、それを "fileConfig()" 関数を使って読み
   込む。

3. 設定情報の辞書を作り、それを "dictConfig()" 関数に渡す。

最後の2つの選択肢については、 環境設定のための関数 で解説しています。
以下の例では、Python コードを使って、とても簡単なロガー、コンソールハ
ンドラ、そして簡単なフォーマッタを設定しています:

   import logging

   # create logger
   logger = logging.getLogger('simple_example')
   logger.setLevel(logging.DEBUG)

   # create console handler and set level to debug
   ch = logging.StreamHandler()
   ch.setLevel(logging.DEBUG)

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

   # add formatter to ch
   ch.setFormatter(formatter)

   # add ch to logger
   logger.addHandler(ch)

   # 'application' code
   logger.debug('debug message')
   logger.info('info message')
   logger.warning('warn message')
   logger.error('error message')
   logger.critical('critical message')

このモジュールを実行すると、コマンドラインによって以下の出力がなされま
す:

   $ python simple_logging_module.py
   2005-03-19 15:10:26,618 - simple_example - DEBUG - debug message
   2005-03-19 15:10:26,620 - simple_example - INFO - info message
   2005-03-19 15:10:26,695 - simple_example - WARNING - warn message
   2005-03-19 15:10:26,697 - simple_example - ERROR - error message
   2005-03-19 15:10:26,773 - simple_example - CRITICAL - critical message

以下の Python モジュールは、ロガー、ハンドラ、フォーマッタをほとんど上
述の例と同じように生成していますが、オブジェクト名だけが異なります:

   import logging
   import logging.config

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

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

   # 'application' code
   logger.debug('debug message')
   logger.info('info message')
   logger.warning('warn message')
   logger.error('error message')
   logger.critical('critical message')

これが logging.conf ファイルです:

   [loggers]
   keys=root,simpleExample

   [handlers]
   keys=consoleHandler

   [formatters]
   keys=simpleFormatter

   [logger_root]
   level=DEBUG
   handlers=consoleHandler

   [logger_simpleExample]
   level=DEBUG
   handlers=consoleHandler
   qualname=simpleExample
   propagate=0

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

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

出力は、設定ファイルに基づく例とだいたい同じです:

   $ python simple_logging_config.py
   2005-03-19 15:38:55,977 - simpleExample - DEBUG - debug message
   2005-03-19 15:38:55,979 - simpleExample - INFO - info message
   2005-03-19 15:38:56,054 - simpleExample - WARNING - warn message
   2005-03-19 15:38:56,055 - simpleExample - ERROR - error message
   2005-03-19 15:38:56,130 - simpleExample - CRITICAL - critical message

この通り、設定ファイルの方法は、主に設定とコードが分かれ、非コーダがロ
ギングプロパティを変えやすくなるという点で、Python コードの方法より少
し優れています。

警告:

  "fileConfig()" 関数はデフォルト引数 "disable_existing_loggers" を取
  り、後方互換性のためにデフォルト値は "True" になっています。 これは
  あなたの望むものかもしれませんし、そうでないかもしれません。というの
  は、設定で明示的に指定したクラス (もしくはその親クラス) を除いて、
  "fileConfig()" が呼び出される前に存在した非ルートロガーを無効化して
  しまうからです。 より詳細なことはリファレンスを参照し、望むならこの
  引数に "False" を指定してください。"dictConfig()" に渡される辞書でも
  、キー "disable_existing_loggers" で真偽値を指定することができ、辞書
  の中で明示的に指定しなかった場合はデフォルトで "True" と解釈されます
  。これは上で説明したロガー無効化につながりますが、それを望まないこと
  もあるでしょう - その場合は、明示的にキーを与えて値を "False" にして
  ください。

なお、設定ファイルで参照されるクラス名は、logging モジュールに対して相
対であるか、通常のインポート機構を使って解決される絶対である値でなけれ
ばなりません。従って、(logging モジュールに相対な)
"WatchedFileHandler" または (Python インポートパスとして "mypackage"
が使えるとき、パッケージ "mypackage" のモジュール "mymodule" で定義さ
れたクラスに) "mypackage.mymodule.MyHandler" のどちらかが使えます。

Python 3.2 では、ロギングを設定するのに新しく、辞書に設定情報を持たせ
る手段が導入されました。これは、上で概説した設定ファイルに基づく方法に
よる機能の上位版を提供し、新しいアプリケーションやデプロイにはこのメソ
ッドが推奨されます。Python の辞書を使って設定情報を保持し、辞書は他の
用途にも使えるので、設定の選択肢が広がります。例えば、JSON フォーマッ
トの設定ファイルや、YAML 処理機能が使えれば YAML フォーマットのファイ
ルを使って、設定辞書を構成できます。また、もちろん、Python コードで辞
書を構成し、ソケットを通して pickle 化された形式を受け取るなど、アプリ
ケーションで意味があるいかなるやり方でも使えます。

以下は、上記と同じ設定を辞書ベースの新しい手法で記載した YAML 形式の例
です:

   version: 1
   formatters:
     simple:
       format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
   handlers:
     console:
       class: logging.StreamHandler
       level: DEBUG
       formatter: simple
       stream: ext://sys.stdout
   loggers:
     simpleExample:
       level: DEBUG
       handlers: [console]
       propagate: no
   root:
     level: DEBUG
     handlers: [console]

辞書を使ったロギングについて詳細は、 環境設定のための関数 を参照してく
ださい。


環境設定が与えられないとどうなるか
----------------------------------

ロギング環境設定を与えられないと、ロギングイベントを出力しなければなら
ないのに、イベントを出力するハンドラが見つからないことがあります。この
状況での logging パッケージの振る舞いは、Python のバージョンに依ります
。

Python 3.2 より前のバージョンでは、振る舞いは以下の通りです:

* *logging.raiseExceptions* が "False" (製品モード) なら、イベントは黙
  って捨てられます。

* *logging.raiseExceptions* が "True" (開発モード) なら、メッセージ
  'No handlers could be found for logger X.Y.Z' が一度表示されます。

Python 3.2 以降バージョンでは、振る舞いは以下の通りです:

* イベントは、 "logging.lastResort" に格納された「最終手段ハンドラ」を
  使用して出力されます。この内部的なハンドラはどんなロガーにも関係して
  おらず、イベント記述メッセージを現在の "sys.stderr" の値に書く
  "StreamHandler" のように動作します (したがって、あらゆるリダイレクト
  の効果が反映されます)。メッセージに対してフォーマットは行われません
  - 裸のイベント記述メッセージだけが印刷されます。ハンドラのレベルは
  "WARNING" にセットされ、これより重大度が大きなすべてのイベントが出力
  されます。

3.2 より前の動作にするために、"logging.lastResort" を "None" に設定す
ることもできます。


ライブラリのためのロギングの設定
--------------------------------

ロギングを使うライブラリを開発するときは、ライブラリがどのようにロギン
グを使うのか、例えば使われているロガーの名前などを、ドキュメントにして
おくべきです。ロギングの設定については、いくつか考えておくべきこともあ
ります。使っているアプリケーションがロギングを使っていなくて、ライブラ
リコードがロギングを呼び出すと、(前の節で解説したように) 重大度
"WARNING" 以上のイベントが、"sys.stderr" に表示されます。これが最高の
デフォルトの振る舞いと見なされます。

何らかの理由でロギング設定がなされていないときにメッセージを表示 *させ
たくない* のであれば、ライブラリのトップレベルのロガーに何もしないハン
ドラを取り付けられます。ライブラリの全てのイベントに対してそのハンドラ
が見つかるので、メッセージが表示されなくなります。ライブラリのユーザー
がアプリケーションのためにロギングを設定する場合、おそらくハンドラが追
加され、そしてレベルが適切に設定された場合に、ライブラリコード内でのロ
ギングの呼び出しは通常通りそのハンドラに出力を送るようになります。

何もしないハンドラ "NullHandler" (Python 3.1 以降) は、 logging パッケ
ージに含まれます。このハンドラのインスタンスを、 (ロギング設定がなされ
ていないときにライブラリのログイベントを "sys.stderr" に出力させたく *
ないなら*) ライブラリの名前空間で使われるトップレベルロガーに取り付け
られます。ライブラリ *foo* によるすべてのロギングが、 'foo.x',
'foo.x.y' その他に該当する名前のロガーによってなされるなら:

   import logging
   logging.getLogger('foo').addHandler(logging.NullHandler())

とすれば望んだ効果が得られるでしょう。組織が複数のライブラリを作り出す
なら、指定されるロガー名は単に 'foo' ではなく、'orgname.foo' になりま
す。

注釈:

  *ライブラリのロガーには、* "NullHandler" *以外のハンドラを追加しない
  * ことを強く推奨します。これは、ハンドラの設定が、あなたのライブラリ
  を使うアプリケーション開発者にも伝播するからです。アプリケーション開
  発者は、対象となる聴衆と、そのアプリケーションにどのハンドラが最も適
  しているかを知っています。ハンドラを 'ボンネットの中で' 加えてしまう
  と、ユニットテストをして必要に応じたログを送達する能力に干渉しかねま
  せん。


ロギングレベル
==============

ログレベルの数値は以下の表のように与えられています。これらは基本的に自
分でレベルを定義したい人のためのもので、定義するレベルを既存のレベルの
間に位置づけるためには具体的な値が必要になります。もし数値が他のレベル
と同じだったら、既存の値は上書きされその名前は失われます。

+----------------+-----------------+
| レベル         | 数値            |
|================|=================|
| "CRITICAL"     | 50              |
+----------------+-----------------+
| "ERROR"        | 40              |
+----------------+-----------------+
| "WARNING"      | 30              |
+----------------+-----------------+
| "INFO"         | 20              |
+----------------+-----------------+
| "DEBUG"        | 10              |
+----------------+-----------------+
| "NOTSET"       | 0               |
+----------------+-----------------+

レベルはロガーに関連付けることもでき、開発者が設定することも、保存され
たログ記録設定を読み込む際に設定することもできます。ロガーに対してログ
記録メソッドが呼び出されると、ロガーは自らのレベルとメソッド呼び出しに
関連付けられたレベルを比較します。ロガーのレベルがメソッド呼び出しのレ
ベルよりも高い場合、実際のログメッセージは生成されません。これはログ出
力の冗長性を制御するための基本的なメカニズムです。

ログ記録されるメッセージは "LogRecord" クラスのインスタンスとしてエン
コードされます。ロガーがあるイベントを実際にログ出力すると決定した場合
、ログメッセージから "LogRecord" インスタンスが生成されます。

ログ記録されるメッセージは、ハンドラ (*handlers*) を通してディスパッチ
機構にかけられます。ハンドラは "Handler" クラスのサブクラスのインスタ
ンスで、ログ記録された ("LogRecord" 形式の) メッセージが、そのメッセー
ジの伝達対象となる相手 (エンドユーザ、サポートデスクのスタッフ、システ
ム管理者、開発者) に行き着くようにする役割を持ちます。ハンドラには特定
の出力先を意図された "LogRecord" インスタンスが渡されます。各ロガーは
0 個以上のハンドラを ("Logger" の "addHandler()" メソッド) で関連付け
ることができます。ロガーに直接関連付けられたハンドラに加えて、*ロガー
の上位にあるロガーすべてに関連付けられたハンドラ* がメッセージを処理す
る際に呼び出されます (ただしロガーの *propagate* フラグが false 値にセ
ットされている場合を除きます。その場合は、祖先ハンドラへの伝搬はそこで
止まります)。

ロガーと同様に、ハンドラは関連付けられたレベルを持つことができます。ハ
ンドラのレベルはロガーのレベルと同じ方法で、フィルタとして働きます。ハ
ンドラがあるイベントを実際に処理すると決定した場合、 "emit()" メソッド
が使われ、メッセージを出力先に送信します。ほとんどのユーザ定義の
"Handler" のサブクラスで、この "emit()" をオーバライドする必要があるで
しょう。


カスタムレベル
--------------

独自のレベルを定義することは可能ですが、必須ではなく、実経験上は既存の
レベルが選ばれます。しかし、カスタムレベルが必要だと確信するなら、レベ
ルの定義には多大な注意を払うべきで、*ライブラリの開発の際、カスタムレ
ベルを定義することはとても悪いアイデア* になり得ます。これは、複数のラ
イブラリの作者がみな独自のカスタムレベルを定義すると、与えられた数値が
異なるライブラリで異なる意味になりえるため、開発者がこれを制御または解
釈するのが難しくなるからです。


便利なハンドラ
==============

基底の "Handler" クラスに加え、多くの便利なサブクラスが提供されていま
す:

1. "StreamHandler" インスタンスは、メッセージをストリーム (ファイル風
   オブジェクト) に送ります。

2. "FileHandler" インスタンスは、メッセージをディスクファイルに送りま
   す。

3. "BaseRotatingHandler" は、ある地点でログファイルを循環させるハンド
   ラの基底クラスです。これを直接インスタンス化することは意図されてい
   ません。代わりに、 "RotatingFileHandler" や
   "TimedRotatingFileHandler" を使用してください。

4. "RotatingFileHandler" インスタンスは、メッセージをディスクファイル
   に送り、最大ログファイル数とログファイル循環をサポートします。

5. "TimedRotatingFileHandler" インスタンスは、メッセージをディスクファ
   イルに送り、ログファイルを特定時間のインターバルで循環します。

6. "SocketHandler" インスタンスは、 TCP/IP ソケットにメッセージを送り
   ます。バージョン3.4　から、 Unixドメインソケットもサポートされます
   。

7. "DatagramHandler" インスタンスは UDP ソケットにメッセージを送ります
   。バージョン 3.4 から、Unix ドメインソケットもサポートされます。

8. "SMTPHandler" インスタンスは、メッセージを指示された email アドレス
   に送ります。

9. "SysLogHandler" インスタンスは、メッセージを、必要ならばリモートマ
   シンの、Unix syslog daemon に送ります。

10. "NTEventLogHandler" インスタンスは、メッセージを Windows
    NT/2000/XP イベントログに送ります。

11. "MemoryHandler" インスタンスは、メッセージを、特定の基準が満たされ
    る度に流される、メモリ中のバッファに送ります。

12. "HTTPHandler" インスタンスは、メッセージを、 "GET" または "POST"
    セマンティクスを使って、HTTP サーバに送ります。

13. "WatchedFileHandler" インスタンスは、ロギングする先のファイルを監
    視します。ファイルが変更されると、そのファイルは閉じられ、ファイル
    名を使って再び開かれます。このハンドラは Unix 系のシステムにのみ便
    利です。Windows は、使われている基の機構をサポートしていません。

14. "QueueHandler" インスタンスは、 "queue" モジュールや
    "multiprocessing" モジュールなどで実装されているキューにメッセージ
    を送ります。

15. "NullHandler" インスタンスは、エラーメッセージに対して何もしません
    。これは、ライブラリ開発者がロギングを使いたいが、ライブラリのユー
    ザがロギングを設定してなくても 'No handlers could be found for
    logger XXX' メッセージを表示させたくない場合に使われます。詳しい情
    報は ライブラリのためのロギングの設定 を参照してください。

バージョン 3.1 で追加: "NullHandler" クラス。

バージョン 3.2 で追加: "QueueHandler" クラス。

コア logging パッケージで、 "NullHandler", "StreamHandler" および
"FileHandler" クラスが定義されています。その他のハンドラは、サブモジュ
ールの "logging.handlers" で定義されています。(環境設定機能のためのサ
ブモジュール、 "logging.config" もあります。)

ログメッセージは、 "Formatter" クラスのインスタンスを通してフォーマッ
ト化してから表示されます。このインスタンスは、 % 演算子と辞書で使うの
に適切なフォーマット文字列で初期化されます。

複数のメッセージを一括してフォーマット化するには、
"BufferingFormatter" が使えます。(一連の文字列のそれぞれに適用される)
フォーマット文字列に加え、ヘッダとトレーラフォーマット文字列も提供され
ています。

ロガーレベルおよび/またはハンドラレベルに基づくフィルタリングで十分で
なければ、 "Filter" のインスタンスを "Logger" と "Handler" インスタン
スの両方に ("addFilter()" を通して) 加えることができます。メッセージの
処理を続ける前に、ロガーもハンドラも、全てのフィルタに許可を求めます。
フィルタのいずれかが偽値を返したら、メッセージの処理は続けられません。

基本の "Filter" 機能では、特定のロガー名でのフィルタリングをできます。
この機能が使われると、指名されたロガーに送られたメッセージとその子だけ
がフィルタを通り、その他は落とされます。


ログ記録中に発生する例外
========================

logging パッケージは、ログを生成している間に起こる例外を飲み込むように
設計されています。これは、ログ記録イベントを扱っている間に発生するエラ
ー (ログ記録の設定ミス、ネットワークまたは他の同様のエラー) によってロ
グ記録を使用するアプリケーションが早期に終了しないようにするためです。

"SystemExit" と "KeyboardInterrupt" 例外は決して飲み込まれません。
"Handler" サブクラスの "emit()" メソッドの間に起こる他の例外は、
"handleError()" メソッドに渡されます。

"Handler" の "handleError()" のデフォルト実装は、モジュールレベル変数
"raiseExceptions" が設定されているかどうかチェックします。設定されてい
るなら、トレースバックが "sys.stderr" に出力されます。設定されていない
なら、例外は飲み込まれます。

注釈:

  "raiseExceptions" のデフォルト値は "True" です。これは、開発の間に起
  こるどんな例外についても通常は通知してほしいからです。実運用環境では
  "raiseExceptions" を "False" に設定することをお勧めします。


任意のオブジェクトをメッセージに使用する
========================================

前の節とそこで挙げた例では、イベントを記録するときに渡されたメッセージ
が文字列であると仮定していました。しかし、これは唯一の可能性ではありま
せん。メッセージとして任意のオブジェクトを渡すことができます。そして、
ロギングシステムがそのオブジェクトを文字列表現に変換する必要があるとき
、オブジェクトの "__str__()" メソッドが呼び出されます。実際、そうした
ければ、文字列表現を計算することを完全に避けることができます - 例えば
、 "SocketHandler" は、イベントを pickle してネットワーク上で送信する
ことでログ出力します。


最適化
======

message 引数の整形は、必要になるまで延期されます。しかしながら、ログ記
録メソッドに渡す引数を計算するだけでもコストがかかる場合があります。ロ
ガーが単にイベントを捨てるなら、その計算を避けたいと考えるかもしれませ
ん。どうするかを決定するために "isEnabledFor()" メソッドを呼ぶことがで
きます。このメソッドは引数にレベルを取って、そのレベルの呼び出しに対し
て Logger がイベントを生成するなら true を返します。このようにコードを
書くことができます:

   if logger.isEnabledFor(logging.DEBUG):
       logger.debug('Message with %s, %s', expensive_func1(),
                                           expensive_func2())

このようにすると、ロガーの閾値が "DEBUG" より上に設定されている場合、
"expensive_func1()" と "expensive_func2()" の呼び出しは行われません。

注釈:

  ある種のケースでは、 "isEnabledFor()" それ自身があなたが期待するより
  も高価になる場合があります(たとえば明示的なレベル指定がロガー階層の
  上位のみに設定されていて、ロガーが深くネストされているような場合です
  )。そのようなケース(あるいはタイトなループ内でメソッド呼び出しを避け
  たい場合)は、 "isEnabledFor()" 結果をローカルにもしくはインスタンス
  変数としてキャッシュし、メソッドを毎回呼び出すかわりに使えば良いです
  。そのようなキャッシュ値は、(まったく一般的ではありませんが)ロギング
  設定がアプリケーション実行中に動的に変更された場合にのみ再計算が必要
  でしょう。

これ以外にも、どんなログ情報が集められるかについてより正確なコントロー
ルを必要とする、特定のアプリケーションでできる最適化があります。これは
、ログ記録の間の不要な処理を避けるためにできることのリストです:

+-------------------------------------------------------+-----------------------------------------------------+
| 不要な情報                                            | それを避ける方法                                    |
|=======================================================|=====================================================|
| 呼び出しがどこから行われたかに関する情報。            | "logging._srcfile" を "None" にする。このことにより |
|                                                       | "sys._getframe()" 呼び出しを避けることが出来、PyPy  |
|                                                       | のような環境("sys._getframe()" の高速 化が出来ない) |
|                                                       | において高速化の役に立ちます。                      |
+-------------------------------------------------------+-----------------------------------------------------+
| スレッド情報。                                        | "logging.logThreads" を "False" にする。            |
+-------------------------------------------------------+-----------------------------------------------------+
| 現在のプロセスID("os.getpid()")                       | "logging.logProcesses" を "False" にする。          |
+-------------------------------------------------------+-----------------------------------------------------+
| マルチプロセスの制御に "multiprocessing" を使っている | "logging.logMultiprocessing" を "False" にする。    |
| ときの、現在のプ ロセス名                             |                                                     |
+-------------------------------------------------------+-----------------------------------------------------+

また、コア logging モジュールが基本的なハンドラだけを含んでいることに
注意してください。 "logging.handlers" と "logging.config" をインポート
しなければ、余分なメモリを消費することはありません。

参考:

  "logging" モジュール
     logging モジュールの API リファレンス。

  "logging.config" モジュール
     logging モジュールの環境設定 API です。

  "logging.handlers" モジュール
     logging モジュールに含まれる、便利なハンドラです。

  ロギングクックブック
