ログの出力

ログにメッセージを出力する

Pylons 0.9.6 からは、 Pylons コントローラ (paster controller/restcontroller で作成されたもの) と websetup.py は、 Python の logging モジュール を通して自身の Logger オブジェクトを作るようになります。

例えば、 helloworld プロジェクトの hello コントローラ (helloworld/controllers/hello.py) ではこのようになります:

import logging

from pylons import request, response, session, tmpl_context as c
from pylons.controllers.util import abort, redirect_to

log = logging.getLogger(__name__)

class HelloController(BaseController):

    def index(self):
        ...

Python の特殊変数 __name__ は現在のモジュールの完全修飾された名前を 参照します。この場合は helloworld.controllers.hello です。

メッセージをログ出力するには、単に Logger オブジェクトで利用できるメソッ ドを使うだけです。

import logging

from pylons import request, response, session, tmpl_context as c
from pylons.controllers.util import abort, redirect_to

log = logging.getLogger(__name__)

class HelloController(BaseController):

    def index(self):
        content_type = 'text/plain'
        content = 'Hello World!'

        log.debug('Returning: %s (content-type: %s)', content, content_type)
        response.content_type = content_type
        return content

これは標準エラーに以下の出力を行います (コンソールに出力されます):

16:20:20,440 DEBUG [helloworld.controllers.hello] Returning: Hello World!
                   (content-type: text/plain)

基本的な logging の設定

Pylons 0.9.6 からはデフォルトの ini ファイルに logging モジュール用の基 本的な設定が含まれています。 Paste の ini ファイルは Python の標準的な ConfigParser フォーマット を使います; logging モジュールの設定ファイルフォーマット も同じ フォーマットを使います。

paster は、 serve, shell, setup-app の各コマンドによっ てアプリケーションをロードする際に、指定された ini ファイルが ‘loggers’ エントリを含んでいれば logging.fileConfig 関数 を呼び出します。 logging.fileConfigConfigParser ファイルから logging 設定を 読み込みます。

logging 設定はデフォルトの development.ini と (paster make-config <package_name> <ini_file> で作られる) プロダクション ini ファイルの両方で提供されます。プロダクション ini ファイルの logging セッ トアップは development.ini より少し単純で、次のようになります:

# Logging configuration
[loggers]
keys = root

[handlers]
keys = console

[formatters]
keys = generic

[logger_root]
level = INFO
handlers = console

[handler_console]
class = StreamHandler
args = (sys.stderr,)
level = NOTSET
formatter = generic

[formatter_generic]
format = %(asctime)s %(levelname)-5.5s [%(name)s] [%(threadName)s] %(message)s

一つのルートロガーが作られ、 INFO レベル以上のメッセージのみを標準 エラーに出力するようになります。フォーマットは以下のようになります:

2007-08-17 15:04:08,704 INFO [helloworld.controllers.hello] Loading resource, id: 86

logging.basicConfig 関数のことをよく知っている人にとっては、この設 定は以下のコードと等価です:

logging.basicConfig(level=logging.INFO,
format='%(asctime)s %(levelname)-5.5s [%(name)s] %(message)s')

デフォルトの development.ini の logging セクションは、 2 つの点で異 なっています。 より冗長でないタイムスタンプを使うことと、アプリケーショ ンのログメッセージをデフォルトで DEBUG レベルとすることです。 (次の セクションで記述されます)

Pylons と他のたくさんのライブラリ (Beaker, SQLAlchemy, Paste など) はデ バッグ目的のために大量のメッセージを出力します。ルートロガーのレベルを DEBUG に変更するとそれが明らかになります:

[logger_root]
#level = INFO
level = DEBUG
handlers = console

ログメッセージのフィルタリング

ルートロガーのレベルを DEBUG に変更した場合など、しばしば取捨選択で きないほどたくさんのログ出力が行われることがあります。

例: あなたは、アプリケーションにおけるデータベース接続の問題を診断して いて、コネクションプーリングに関連した SQLAlchemy の DEBUG メッセー ジだけを見たいと思っています。ルートロガーのレベルを、それほど冗長でな い INFO レベルのままにしておき、ルートロガートとは別に特定の SQLAlchemy のロガーを DEBUG に設定できます:

[logger_sqlalchemy.pool]
level = DEBUG
handlers =
qualname = sqlalchemy.pool

次にこれをロガーのリストに追加します:

[loggers]
keys = root, sqlalchemy.pool

このロガーのために Handlers を構成する必要はありません。ルート以外のロ ガーは、デフォルトでログレコードを親のロガーの Handlers に伝播するから です。ルートロガーはすべてのロガーのトップレベルの親です。

このテクニックはデフォルトの development.ini で使用されています。ルー トロガーのレベルは INFO に設定される一方で、アプリケーションのログ レベルは DEBUG に設定されます:

# Logging configuration
[loggers]
keys = root, helloworld
[logger_helloworld]
level = DEBUG
handlers =
qualname = helloworld

明示的に異なる設定がされていない限り、 helloworld ロガーの子供ロガーの すべてが DEBUG レベルを引き継ぐことになります。 つまり、 helloworld.controllers.hello, helloworld.websetup (そしてアプリ ケーションの他のモジュールの) ロガーも、デフォルトで実効レベル DEBUG になります。

より高度なフィルタリングのために、 logging モジュールは Filter オブジェクトを提供していま す。ただし Filter オブジェクトを設定ファイルから直接使用することはでき ません。

高度な構成

ログ出力を個別のファイルに記録するためには、 FileHandler (または RotatingFileHandler) を使 います:

[handler_accesslog]
class = FileHandler
args = ('access.log','a')
level = INFO
formatter = generic

それが認識される前に、 Handlers のリストに追加される必要があります:

[handlers]
keys = console, accesslog

最後にロガーによって使われます。

[logger_root]
level = INFO
handlers = console, accesslog

この最後の 3 行の構成が、ルートロガーの出力のすべてをコンソールに加えて access.log に向けます。次のセクションではこれを無効にしたいと思うでしょう。

Paste の TransLogger によるリクエストログ

Paste は Apache Combined Log Format を使ってリクエ ストを記録するための TransLogger ミドルウェアを 提供しています。 FileHandler と TransLogger を組み合わせると、 Apache のログファイルのような access.log を作成することができます。

Paste エントリーポイントを持つ他の標準的なミドルウェアと同様に、 ini ファ イルの [app:main] セクションでアプリケーションをラップするように TransLogger を構成できます:

filter-with = translogger

[filter:translogger]
use = egg:Paste#translogger
setup_console_handler = False

これは、プロジェクトの config/middleware.py ファイルの最後でアプリ ケーションを TransLogger インスタンスでラップするのと同等です:

from paste.translogger import TransLogger
app = TransLogger(app, setup_console_handler=False)
return app

TransLogger は、引数なしで呼ばれると自動的に logging Handler をコンソー ルに設定するので、 logging を構成しない環境でもそのままで動きます (‘just works’)。 私たちは自身の logging Handlers を構成したので、 setup_console_handler = False によってそのオプションを無効にする必 要があります。

フィルタが適切な場所にあると、ページがリクエストされたときに TransLogger のロガー (‘wsgi’ ロガーという名前になります) は親ロガー (ルー トロガー) にログメッセージを伝播し、その出力はコンソールに送られます:

00:50:53,694 INFO [helloworld.controllers.hello] Returning: Hello World!
                  (content-type: text/plain)
00:50:53,695 INFO [wsgi] 192.168.1.111 - - [11/Aug/2007:20:09:33 -0700] "GET /hello
HTTP/1.1" 404 - "-"
"Mozilla/5.0 (Macintosh; U; Intel Mac OS X; en-US; rv:1.8.1.6) Gecko/20070725
Firefox/2.0.0.6"

TransLogger を上で定義された access.log FileHandler に向けるために、 wsgi ロガーの Handlers リストにその FileHandler を追加する必要がありま す:

# Logging configuration
[loggers]
keys = root, wsgi
[logger_wsgi]
level = INFO
handlers = handler_accesslog
qualname = wsgi
propagate = 0

前述のように、ルート以外のロガーはデフォルトでルートロガーの Handlers (現在はコンソール Handler) にログレコードを伝播します。ここで propagate を 0 (false) に設定すると、これを無効にできます。そのため、 wsgi ロガーは accesslog Handler だけに記録を向けます。

TransLogger 自身が必要とするすべての情報を提供するので、最終的に、 TransLogger と共に generic Formatter を使用する必要は全くありません。 ログメッセージをそのまま素通しする Formatter を使用することにします:

[formatters]
keys = generic, accesslog
[formatter_accesslog]
format = %(message)s

次に、この新しい accesslog Formatter を FileHandler に接続してくだ さい:

[handler_accesslog]
class = FileHandler
args = ('access.log','a')
level = INFO
formatter = accesslog

wsgi.errors に対するログ出力

Pylons は WSGI サーバのエラーストリーム environ['wsgi.errors'] (詳 しくは WSGI Spefification, PEP 333 を参照) にログ出力するため のカスタムな logging Handler クラス pylons.log.WSGIErrorsHandler を 提供しています。 wsgi.errors は特定の状況、例えば Apache mod_wsgi/mod_python のもとでデプロイされているような場合には、ログ出力 に便利です。その場合、 wsgi.errors ストリームは、Apache エラーログ です。

ERROR (と CRITICAL) メッセージだけを wsgi.errors にログ出力 するように構成するには、 ini ファイルに以下を追加してください:

[handlers]
keys = console, wsgierrors
[handler_wsgierrors]
class = pylons.log.WSGIErrorsHandler
args = ()
level = ERROR
format = generic

次に、 ルートロガーによって使用される Handlers のリストに新しい Handler 名を追加してください:

[logger_root]
level = INFO
handlers = console, wsgierrors

Warning

WSGIErrorsHandler はアプリケーションを開始する間に作成されたロ グメッセージを受け取りません。 これは wsgi.errors ストリームは environ 辞書を通してのみ利用可能だからです。リクエストがあるま でそれは利用可能ではありません。

log4j の Chainsaw による lumberjacking

Java の log4j プロジェクトは、ログメッセージを表示したり管理したり するために Java GUI アプリケーション Chainsaw を提供しています。 その特徴として、 on the fly でログメッセージをフィルタリングする機能、 およびカスタマイズ可能なカラーハイライトがあります。

Python の logging モジュールを、 Chainsaw でパース可能な形式 (log4jXMLLayout 形式) で出力するように構成できます。

それをするために、最初に Python XMLLayout package をインストールする必要があり ます:

$ easy_install XMLLayout

このモジュールは XMLLayout XML を生成するログフォーマッタを提供しま す。 また、 RawSocketHandler を提供します。それは、 logging モジュー ルの SocketHandler のようにネットワークの向こう側にログメッセージを 送りますが、それらを pickle しません。

以下は、 XMLLayout ログメッセージをネットワーク経由で Chainsaw (localhost4448 ポート で listen している場合) へ送付するための 構成例です:

[handlers]
keys = console, chainsaw

[formatters]
keys = generic, xmllayout

[logger_root]
level = INFO
handlers = console, chainsaw
[handler_chainsaw]
class = xmllayout.RawSocketHandler
args = ('localhost', 4448)
level = NOTSET
formatter = xmllayout
[formatter_xmllayout]
class = xmllayout.XMLLayout

これは、ルートロガーによって扱われたすべてのログメッセージを Chainsaw に送るように構成します。デフォルトの development.ini はルートロガー を INFO レベルに構成しますが、 Chainsaw を使用する場合はルートロガー を NOTSET に構成して すべての ログメッセージを Chainsaw に送るの が望ましいでしょう。代わりに、コンソールハンドラを INFO レベルに制 限することができます:

[logger_root]
level = NOTSET
handlers = console

[handler_console]
class = StreamHandler
args = (sys.stderr,)
level = INFO
formatter = generic

Chainsaw は ホームページ からダウンロード できますが、 Java が有効なブラウザで以下のリンクから直接実行することも できます: Chainsaw web start.

Chainsaw は GUI から構成することもできますが、 log4j.xml ファイルか ら構成を読み込むこともサポートしています。

以下の log4j.xml ファイルは、ポート 4448XMLLayout スタイ ルのログメッセージを listen するように Chainsaw を構成します。また、 WARN レベルより下の Chainsaw 自身のログメッセージを隠すので、あなた のアプリケーションのログメッセージだけを表示します:

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE configuration>
<configuration xmlns="http://logging.apache.org/">

<plugin name="XMLSocketReceiver" class="org.apache.log4j.net.XMLSocketReceiver">
    <param name="decoder" value="org.apache.log4j.xml.XMLDecoder"/>
    <param name="port" value="4448"/>
</plugin>

<logger name="org.apache.log4j">
    <level value="warn"/>
</logger>

<root>
    <level value="debug"/>
</root>

</configuration>

Chainsaw は開始時に構成ファイルについてのプロンプトを表示します。また、 File/Load Log4J File... をクリックすることで、後で構成をロードする こともできます。 Chainsaw の Receiver リストに XMLSocketReceiver インス タンスがロードされているのが見られるはずです。それはポート 4448 で構 成されて、ログメッセージを受け取る準備ができています。

これは、 Pylons スタックのログメッセージが定義済みの色でどのように見え るかを示しています (OS X で Chainsaw を使用):

_images/Pylons_Stack-Chainsaw-OSX.png

ログ出力設定の別のスタイル

Pylons のデフォルト ini ファイルは Python の logging モジュールのための 基本構成を含んでいます。 そのフォーマットは標準 Python logging モジュールの 設定ファイルフォーマット に適合し ています。より簡潔なフォーマットが好みなら、 Max Ischenko が実証したロ グ出力設定の別のスタイルがあります。

以下の関数はアプリケーション開始時に呼ばれます (例えば、Global コンスト ラクタ):

def setup_logging():
    logfile = config['logfile']
    if logfile == 'STDOUT': # special value, used for unit testing
        logging.basicConfig(stream=sys.stdout, level=logging.DEBUG,
               #format='%(name)s %(levelname)s %(message)s',
               #format='%(asctime)s,%(msecs)d %(levelname)s %(message)s',
               format='%(asctime)s,%(msecs)d %(name)s %(levelname)s %(message)s',
               datefmt='%H:%M:%S')
    else:
        logdir = os.path.dirname(os.path.abspath(logfile))
        if not os.path.exists(logdir):
            os.makedirs(logdir)
        logging.basicConfig(filename=logfile, mode='at+',
             level=logging.DEBUG,
             format='%(asctime)s,%(msecs)d %(name)s %(levelname)s %(message)s',
             datefmt='%Y-%b-%d %H:%M:%S')
    setup_thirdparty_logging()

setup_thirdparty_logging 関数は、アプリケーション .ini ファイルから 特定の logger (モジュール) に logging レベルを指定するキーを検索します。

def setup_thirdparty_logging():
    for key in config:
        if not key.endswith('logging'):
            continue
        value = config.get(key)
        key = key.rstrip('.logging')
        loglevel = logging.getLevelName(value)
        log.info('Set %s logging for %s', logging.getLevelName(loglevel), key)
        logging.getLogger(key).setLevel(loglevel)

.ini ファイルの関連セクション (例):

sqlalchemy.logging = WARNING
sqlalchemy.orm.unitofwork.logging = INFO
sqlalchemy.engine.logging = DEBUG
sqlalchemy.orm.logging = INFO
routes.logging = WARNING

これは routes logger (そして routes.mapper などのすべての sub-logger) が WARNING レベル以上のメッセージのみを通すことを表しています。 sqlalachemy はデフォルトで WARNING レベルですが、いくつかの logger は デバッグを支援するためにより冗長なレベルによって構成されています。

Read the Docs v: v1.0.1rc1
Versions
latest
v1.0.1rc1
v0.9.7
Downloads
PDF
HTML
Epub
On Read the Docs
Project Home
Builds

Free document hosting provided by Read the Docs.