ロギングクックブック
- 著者
- ビナイサジップ
このページには、過去に役立つことがわかっているロギングに関連するレシピがいくつか含まれています。
複数のモジュールへのログインの使用
logging.getLogger('someLogger')を複数回呼び出すと、同じロガーオブジェクトへの参照が返されます。 これは、同じモジュール内だけでなく、同じPythonインタープリタープロセス内にある限り、モジュール間でも当てはまります。 同じオブジェクトへの参照にも当てはまります。 さらに、アプリケーションコードは、1つのモジュールで親ロガーを定義および構成し、別のモジュールで子ロガーを作成（構成はしない）することができ、子へのすべてのロガー呼び出しは親に渡されます。 メインモジュールは次のとおりです。
import logging
import auxiliary_module
# create logger with 'spam_application'
logger = logging.getLogger('spam_application')
logger.setLevel(logging.DEBUG)
# create file handler which logs even debug messages
fh = logging.FileHandler('spam.log')
fh.setLevel(logging.DEBUG)
# create console handler with a higher log level
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)
# create formatter and add it to the handlers
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
fh.setFormatter(formatter)
ch.setFormatter(formatter)
# add the handlers to the logger
logger.addHandler(fh)
logger.addHandler(ch)
logger.info('creating an instance of auxiliary_module.Auxiliary')
a = auxiliary_module.Auxiliary()
logger.info('created an instance of auxiliary_module.Auxiliary')
logger.info('calling auxiliary_module.Auxiliary.do_something')
a.do_something()
logger.info('finished auxiliary_module.Auxiliary.do_something')
logger.info('calling auxiliary_module.some_function()')
auxiliary_module.some_function()
logger.info('done with auxiliary_module.some_function()')補助モジュールは次のとおりです。
import logging
# create logger
module_logger = logging.getLogger('spam_application.auxiliary')
class Auxiliary:
def __init__(self):
self.logger = logging.getLogger('spam_application.auxiliary.Auxiliary')
self.logger.info('creating an instance of Auxiliary')
def do_something(self):
self.logger.info('doing something')
a = 1 + 1
self.logger.info('done doing something')
def some_function():
module_logger.info('received a call to "some_function"')出力は次のようになります。
2005-03-23 23:47:11,663 - spam_application - INFO -
creating an instance of auxiliary_module.Auxiliary
2005-03-23 23:47:11,665 - spam_application.auxiliary.Auxiliary - INFO -
creating an instance of Auxiliary
2005-03-23 23:47:11,665 - spam_application - INFO -
created an instance of auxiliary_module.Auxiliary
2005-03-23 23:47:11,668 - spam_application - INFO -
calling auxiliary_module.Auxiliary.do_something
2005-03-23 23:47:11,668 - spam_application.auxiliary.Auxiliary - INFO -
doing something
2005-03-23 23:47:11,669 - spam_application.auxiliary.Auxiliary - INFO -
done doing something
2005-03-23 23:47:11,670 - spam_application - INFO -
finished auxiliary_module.Auxiliary.do_something
2005-03-23 23:47:11,671 - spam_application - INFO -
calling auxiliary_module.some_function()
2005-03-23 23:47:11,672 - spam_application.auxiliary - INFO -
received a call to 'some_function'
2005-03-23 23:47:11,673 - spam_application - INFO -
done with auxiliary_module.some_function()複数のスレッドからのロギング
複数のスレッドからのロギングには、特別な労力は必要ありません。 次の例は、メイン（initIal）スレッドと別のスレッドからのロギングを示しています。
import logging
import threading
import time
def worker(arg):
while not arg['stop']:
logging.debug('Hi from myfunc')
time.sleep(0.5)
def main():
logging.basicConfig(level=logging.DEBUG, format='%(relativeCreated)6d %(threadName)s %(message)s')
info = {'stop': False}
thread = threading.Thread(target=worker, args=(info,))
thread.start()
while True:
try:
logging.debug('Hello from main')
time.sleep(0.75)
except KeyboardInterrupt:
info['stop'] = True
break
thread.join()
if __name__ == '__main__':
main()実行すると、スクリプトは次のように出力されます。
0 Thread-1 Hi from myfunc
3 MainThread Hello from main
505 Thread-1 Hi from myfunc
755 MainThread Hello from main
1007 Thread-1 Hi from myfunc
1507 MainThread Hello from main
1508 Thread-1 Hi from myfunc
2010 Thread-1 Hi from myfunc
2258 MainThread Hello from main
2512 Thread-1 Hi from myfunc
3009 MainThread Hello from main
3013 Thread-1 Hi from myfunc
3515 Thread-1 Hi from myfunc
3761 MainThread Hello from main
4017 Thread-1 Hi from myfunc
4513 MainThread Hello from main
4518 Thread-1 Hi from myfuncこれは、予想どおりにログ出力が散在していることを示しています。 もちろん、このアプローチは、ここに示されているよりも多くのスレッドで機能します。
複数のハンドラーとフォーマッター
ロガーはプレーンなPythonオブジェクトです。 addHandler（）メソッドには、追加できるハンドラーの数に対する最小または最大のクォータがありません。 アプリケーションがすべての重大度のすべてのメッセージをテキストファイルに記録すると同時に、エラー以上をコンソールに記録すると便利な場合があります。 これを設定するには、適切なハンドラーを構成するだけです。 アプリケーションコードのロギング呼び出しは変更されません。 これは、前の単純なモジュールベースの構成例へのわずかな変更です。
import logging
logger = logging.getLogger('simple_example')
logger.setLevel(logging.DEBUG)
# create file handler which logs even debug messages
fh = logging.FileHandler('spam.log')
fh.setLevel(logging.DEBUG)
# create console handler with a higher log level
ch = logging.StreamHandler()
ch.setLevel(logging.ERROR)
# create formatter and add it to the handlers
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
ch.setFormatter(formatter)
fh.setFormatter(formatter)
# add the handlers to logger
logger.addHandler(ch)
logger.addHandler(fh)
# 'application' code
logger.debug('debug message')
logger.info('info message')
logger.warn('warn message')
logger.error('error message')
logger.critical('critical message')'application'コードは複数のハンドラーを気にしないことに注意してください。 変更されたのは、 fh という名前の新しいハンドラーの追加と構成だけでした。
重大度の高いまたは低いフィルターを使用して新しいハンドラーを作成する機能は、アプリケーションを作成およびテストするときに非常に役立ちます。 デバッグに多くのprintステートメントを使用する代わりに、logger.debugを使用します。後で削除またはコメントアウトする必要があるprintステートメントとは異なり、logger.debugステートメントはソースコードにそのまま残すことができます。再び必要になるまで休眠状態を保ちます。 その時点で発生する必要がある唯一の変更は、デバッグするロガーやハンドラーの重大度レベルを変更することです。
複数の宛先へのロギング
さまざまなメッセージ形式でさまざまな状況でコンソールとファイルにログを記録するとします。 レベルがDEBUG以上のメッセージをファイルに記録し、レベルがINFO以上のメッセージをコンソールに記録するとします。 また、ファイルにはタイムスタンプが含まれている必要がありますが、コンソールメッセージには含まれていないと仮定しましょう。 これを実現する方法は次のとおりです。
import logging
# set up logging to file - see previous section for more details
logging.basicConfig(level=logging.DEBUG,
format='%(asctime)s %(name)-12s %(levelname)-8s %(message)s',
datefmt='%m-%d %H:%M',
filename='/temp/myapp.log',
filemode='w')
# define a Handler which writes INFO messages or higher to the sys.stderr
console = logging.StreamHandler()
console.setLevel(logging.INFO)
# set a format which is simpler for console use
formatter = logging.Formatter('%(name)-12s: %(levelname)-8s %(message)s')
# tell the handler to use this format
console.setFormatter(formatter)
# add the handler to the root logger
logging.getLogger('').addHandler(console)
# Now, we can log to the root logger, or any other logger. First the root...
logging.info('Jackdaws love my big sphinx of quartz.')
# Now, define a couple of other loggers which might represent areas in your
# application:
logger1 = logging.getLogger('myapp.area1')
logger2 = logging.getLogger('myapp.area2')
logger1.debug('Quick zephyrs blow, vexing daft Jim.')
logger1.info('How quickly daft jumping zebras vex.')
logger2.warning('Jail zesty vixen who grabbed pay from quack.')
logger2.error('The five boxing wizards jump quickly.')これを実行すると、コンソールに表示されます
root : INFO Jackdaws love my big sphinx of quartz.
myapp.area1 : INFO How quickly daft jumping zebras vex.
myapp.area2 : WARNING Jail zesty vixen who grabbed pay from quack.
myapp.area2 : ERROR The five boxing wizards jump quickly.ファイルには次のようなものが表示されます
10-22 22:19 root INFO Jackdaws love my big sphinx of quartz.
10-22 22:19 myapp.area1 DEBUG Quick zephyrs blow, vexing daft Jim.
10-22 22:19 myapp.area1 INFO How quickly daft jumping zebras vex.
10-22 22:19 myapp.area2 WARNING Jail zesty vixen who grabbed pay from quack.
10-22 22:19 myapp.area2 ERROR The five boxing wizards jump quickly.ご覧のとおり、DEBUGメッセージはファイルにのみ表示されます。 他のメッセージは両方の宛先に送信されます。
この例では、コンソールハンドラーとファイルハンドラーを使用していますが、選択したハンドラーの数と組み合わせを任意に使用できます。
構成サーバーの例
ロギング構成サーバーを使用するモジュールの例を次に示します。
import logging
import logging.config
import time
import os
# read initial config file
logging.config.fileConfig('logging.conf')
# create and start listener on port 9999
t = logging.config.listen(9999)
t.start()
logger = logging.getLogger('simpleExample')
try:
# loop through logging calls to see the difference
# new configurations make, until Ctrl+C is pressed
while True:
logger.debug('debug message')
logger.info('info message')
logger.warn('warn message')
logger.error('error message')
logger.critical('critical message')
time.sleep(5)
except KeyboardInterrupt:
# cleanup
logging.config.stopListening()
t.join()そして、これがファイル名を受け取り、そのファイルをサーバーに送信するスクリプトです。新しいロギング構成として、適切にバイナリエンコードされた長さが前に付けられます。
#!/usr/bin/env python
import socket, sys, struct
with open(sys.argv[1], 'rb') as f:
data_to_send = f.read()
HOST = 'localhost'
PORT = 9999
s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
print('connecting...')
s.connect((HOST, PORT))
print('sending config...')
s.send(struct.pack('>L', len(data_to_send)))
s.send(data_to_send)
s.close()
print('complete')
ネットワークを介したロギングイベントの送受信
ネットワークを介してロギングイベントを送信し、受信側でそれらを処理するとします。 これを行う簡単な方法は、SocketHandlerインスタンスを送信側のルートロガーにアタッチすることです。
import logging, logging.handlers
rootLogger = logging.getLogger('')
rootLogger.setLevel(logging.DEBUG)
socketHandler = logging.handlers.SocketHandler('localhost',
logging.handlers.DEFAULT_TCP_LOGGING_PORT)
# don't bother with a formatter, since a socket handler sends the event as
# an unformatted pickle
rootLogger.addHandler(socketHandler)
# Now, we can log to the root logger, or any other logger. First the root...
logging.info('Jackdaws love my big sphinx of quartz.')
# Now, define a couple of other loggers which might represent areas in your
# application:
logger1 = logging.getLogger('myapp.area1')
logger2 = logging.getLogger('myapp.area2')
logger1.debug('Quick zephyrs blow, vexing daft Jim.')
logger1.info('How quickly daft jumping zebras vex.')
logger2.warning('Jail zesty vixen who grabbed pay from quack.')
logger2.error('The five boxing wizards jump quickly.')受信側では、 SocketServer モジュールを使用して受信機をセットアップできます。 基本的な作業例を次に示します。
import pickle
import logging
import logging.handlers
import SocketServer
import struct
class LogRecordStreamHandler(SocketServer.StreamRequestHandler):
"""Handler for a streaming logging request.
This basically logs the record using whatever logging policy is
configured locally.
"""
def handle(self):
"""
Handle multiple requests - each expected to be a 4-byte length,
followed by the LogRecord in pickle format. Logs the record
according to whatever policy is configured locally.
"""
while True:
chunk = self.connection.recv(4)
if len(chunk) < 4:
break
slen = struct.unpack('>L', chunk)[0]
chunk = self.connection.recv(slen)
while len(chunk) < slen:
chunk = chunk + self.connection.recv(slen - len(chunk))
obj = self.unPickle(chunk)
record = logging.makeLogRecord(obj)
self.handleLogRecord(record)
def unPickle(self, data):
return pickle.loads(data)
def handleLogRecord(self, record):
# if a name is specified, we use the named logger rather than the one
# implied by the record.
if self.server.logname is not None:
name = self.server.logname
else:
name = record.name
logger = logging.getLogger(name)
# N.B. EVERY record gets logged. This is because Logger.handle
# is normally called AFTER logger-level filtering. If you want
# to do filtering, do it at the client end to save wasting
# cycles and network bandwidth!
logger.handle(record)
class LogRecordSocketReceiver(SocketServer.ThreadingTCPServer):
"""
Simple TCP socket-based logging receiver suitable for testing.
"""
allow_reuse_address = 1
def __init__(self, host='localhost',
port=logging.handlers.DEFAULT_TCP_LOGGING_PORT,
handler=LogRecordStreamHandler):
SocketServer.ThreadingTCPServer.__init__(self, (host, port), handler)
self.abort = 0
self.timeout = 1
self.logname = None
def serve_until_stopped(self):
import select
abort = 0
while not abort:
rd, wr, ex = select.select([self.socket.fileno()],
[], [],
self.timeout)
if rd:
self.handle_request()
abort = self.abort
def main():
logging.basicConfig(
format='%(relativeCreated)5d %(name)-15s %(levelname)-8s %(message)s')
tcpserver = LogRecordSocketReceiver()
print('About to start TCP server...')
tcpserver.serve_until_stopped()
if __name__ == '__main__':
main()最初にサーバーを実行し、次にクライアントを実行します。 クライアント側では、コンソールには何も印刷されません。 サーバー側では、次のように表示されます。
About to start TCP server...
59 root INFO Jackdaws love my big sphinx of quartz.
59 myapp.area1 DEBUG Quick zephyrs blow, vexing daft Jim.
69 myapp.area1 INFO How quickly daft jumping zebras vex.
69 myapp.area2 WARNING Jail zesty vixen who grabbed pay from quack.
69 myapp.area2 ERROR The five boxing wizards jump quickly.一部のシナリオでは、pickleにセキュリティ上の問題があることに注意してください。 これらが影響する場合は、 makePickle（）メソッドをオーバーライドしてそこに代替を実装し、上記のスクリプトを代替のシリアル化を使用するように適合させることで、代替のシリアル化スキームを使用できます。
ログ出力にコンテキスト情報を追加する
ロギング呼び出しに渡されるパラメーターに加えて、ロギング出力にコンテキスト情報を含めたい場合があります。 たとえば、ネットワークアプリケーションでは、クライアント固有の情報をログに記録することが望ましい場合があります（たとえば、 リモートクライアントのユーザー名、またはIPアドレス）。 extra パラメーターを使用してこれを実現することもできますが、この方法で情報を渡すことが常に便利であるとは限りません。 接続ごとに Logger インスタンスを作成したくなるかもしれませんが、これらのインスタンスはガベージコレクションされていないため、これはお勧めできません。 これは実際には問題ではありませんが、 Logger インスタンスの数が、アプリケーションのロギングで使用する粒度のレベルに依存している場合、の数が管理しにくい場合があります。 Logger インスタンスは事実上無制限になります。
LoggerAdaptersを使用してコンテキスト情報を伝達する
ロギングイベント情報とともに出力されるコンテキスト情報を渡すことができる簡単な方法は、 LoggerAdapter クラスを使用することです。 このクラスは Logger のように設計されているため、 debug（）、 info（）、 warning（）を呼び出すことができます。 、 error（）、 exception（）、 critical（）および log（）。 これらのメソッドは、 Logger の対応するメソッドと同じ署名を持っているため、2つのタイプのインスタンスを同じ意味で使用できます。
LoggerAdapter のインスタンスを作成するときは、 Logger インスタンスと、コンテキスト情報を含むdictのようなオブジェクトを渡します。 LoggerAdapter のインスタンスでロギングメソッドの1つを呼び出すと、コンストラクターに渡された Logger の基になるインスタンスに呼び出しが委任され、コンテキスト情報が委任された呼び出し。 LoggerAdapter のコードからの抜粋は次のとおりです。
def debug(self, msg, *args, **kwargs):
"""
Delegate a debug call to the underlying logger, after adding
contextual information from this adapter instance.
"""
msg, kwargs = self.process(msg, kwargs)
self.logger.debug(msg, *args, **kwargs)LoggerAdapter の process（）メソッドは、コンテキスト情報がロギング出力に追加される場所です。 ロギング呼び出しのメッセージとキーワードの引数が渡され、基になるロガーへの呼び出しで使用するために、これらの（潜在的に）変更されたバージョンが返されます。 このメソッドのデフォルトの実装では、メッセージはそのままになりますが、コンストラクターに渡されるdictのようなオブジェクトを値とするキーワード引数に「extra」キーが挿入されます。 もちろん、アダプターの呼び出しで「extra」キーワード引数を渡した場合は、サイレントに上書きされます。
'extra'を使用する利点は、dictのようなオブジェクトの値が LogRecord インスタンスの__dict__にマージされ、 Formatter インスタンスでカスタマイズされた文字列を使用できることです。 dictのようなオブジェクトのキー。 別の方法が必要な場合、例えば メッセージ文字列にコンテキスト情報を追加または追加する場合は、 LoggerAdapter をサブクラス化し、 process（）をオーバーライドして必要な処理を実行する必要があります。 簡単な例を次に示します。
class CustomAdapter(logging.LoggerAdapter):
"""
This example adapter expects the passed in dict-like object to have a
'connid' key, whose value in brackets is prepended to the log message.
"""
def process(self, msg, kwargs):
return '[%s] %s' % (self.extra['connid'], msg), kwargsあなたはこのように使うことができます：
logger = logging.getLogger(__name__)
adapter = CustomAdapter(logger, {'connid': some_conn_id})次に、アダプタにログを記録するイベントには、ログメッセージの前にsome_conn_idの値が付加されます。
dict以外のオブジェクトを使用してコンテキスト情報を渡す
実際のdictを LoggerAdapter に渡す必要はありません。__getitem__と__iter__を実装するクラスのインスタンスを渡して、dictのように見せることができます。ロギングに。 これは、値を動的に生成する場合に役立ちます（dictの値は一定です）。
フィルタを使用してコンテキスト情報を伝達する
ユーザー定義の Filter を使用して、コンテキスト情報をログ出力に追加することもできます。 Filterインスタンスは、渡されたLogRecordsを変更できます。これには、適切なフォーマット文字列を使用して出力できる属性を追加したり、必要に応じてカスタム Formatter を追加したりできます。
たとえば、Webアプリケーションでは、処理中の要求（または少なくともその興味深い部分）をthreadlocal（ threading.local ）変数に格納し、 [からアクセスできます。 X202X]たとえば、 [のように属性名「ip」と「user」を使用して、リクエストからの情報（たとえば、リモートIPアドレスとリモートユーザーのユーザー名）をLogRecordに追加します。 X382X]上記の例。 その場合、同じフォーマット文字列を使用して、上記と同様の出力を取得できます。 スクリプトの例を次に示します。
import logging
from random import choice
class ContextFilter(logging.Filter):
"""
This is a filter which injects contextual information into the log.
Rather than use actual contextual information, we just use random
data in this demo.
"""
USERS = ['jim', 'fred', 'sheila']
IPS = ['123.231.231.123', '127.0.0.1', '192.168.0.1']
def filter(self, record):
record.ip = choice(ContextFilter.IPS)
record.user = choice(ContextFilter.USERS)
return True
if __name__ == '__main__':
levels = (logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR, logging.CRITICAL)
logging.basicConfig(level=logging.DEBUG,
format='%(asctime)-15s %(name)-5s %(levelname)-8s IP: %(ip)-15s User: %(user)-8s %(message)s')
a1 = logging.getLogger('a.b.c')
a2 = logging.getLogger('d.e.f')
f = ContextFilter()
a1.addFilter(f)
a2.addFilter(f)
a1.debug('A debug message')
a1.info('An info message with %s', 'some parameters')
for x in range(10):
lvl = choice(levels)
lvlname = logging.getLevelName(lvl)
a2.log(lvl, 'A message at %s level with %d %s', lvlname, 2, 'parameters')これを実行すると、次のようなものが生成されます。
2010-09-06 22:38:15,292 a.b.c DEBUG IP: 123.231.231.123 User: fred A debug message
2010-09-06 22:38:15,300 a.b.c INFO IP: 192.168.0.1 User: sheila An info message with some parameters
2010-09-06 22:38:15,300 d.e.f CRITICAL IP: 127.0.0.1 User: sheila A message at CRITICAL level with 2 parameters
2010-09-06 22:38:15,300 d.e.f ERROR IP: 127.0.0.1 User: jim A message at ERROR level with 2 parameters
2010-09-06 22:38:15,300 d.e.f DEBUG IP: 127.0.0.1 User: sheila A message at DEBUG level with 2 parameters
2010-09-06 22:38:15,300 d.e.f ERROR IP: 123.231.231.123 User: fred A message at ERROR level with 2 parameters
2010-09-06 22:38:15,300 d.e.f CRITICAL IP: 192.168.0.1 User: jim A message at CRITICAL level with 2 parameters
2010-09-06 22:38:15,300 d.e.f CRITICAL IP: 127.0.0.1 User: sheila A message at CRITICAL level with 2 parameters
2010-09-06 22:38:15,300 d.e.f DEBUG IP: 192.168.0.1 User: jim A message at DEBUG level with 2 parameters
2010-09-06 22:38:15,301 d.e.f ERROR IP: 127.0.0.1 User: sheila A message at ERROR level with 2 parameters
2010-09-06 22:38:15,301 d.e.f DEBUG IP: 123.231.231.123 User: fred A message at DEBUG level with 2 parameters
2010-09-06 22:38:15,301 d.e.f INFO IP: 123.231.231.123 User: fred A message at INFO level with 2 parameters
複数のプロセスから単一のファイルにログを記録する
ロギングはスレッドセーフであり、単一プロセスの複数のスレッドから単一ファイルへのロギングはサポートされていますが、複数プロセスから単一ファイルへのロギングはではありません ]サポートされています。これは、Pythonの複数のプロセス間で単一のファイルへのアクセスをシリアル化する標準的な方法がないためです。 複数のプロセスから単一のファイルにログを記録する必要がある場合、これを行う1つの方法は、すべてのプロセスを SocketHandler にログに記録し、ソケットから読み取るソケットサーバーを実装する別のプロセスを用意することです。そしてファイルに記録します。 （必要に応じて、既存のプロセスの1つに1つのスレッドを割り当てて、この機能を実行できます。）このセクションでは、このアプローチについて詳しく説明し、開始点として使用できる動作中のソケットレシーバーが含まれています。あなたがあなた自身のアプリケーションに適応するために。
マルチプロセッシングモジュールを含む最新バージョンのPythonを使用している場合は、このモジュールの Lock クラスを使用して、プロセスからファイルへのアクセスをシリアル化する独自のハンドラーを作成できます。 。 既存の FileHandler およびサブクラスは、現在マルチプロセッシングを使用していませんが、将来使用する可能性があります。 現在、マルチプロセッシングモジュールは、すべてのプラットフォームで機能するロック機能を提供しているわけではないことに注意してください（ https://bugs.python.org/issue3770 を参照）。
ファイルローテーションの使用
ログファイルを特定のサイズに拡大してから、新しいファイルを開いてそれにログを記録したい場合があります。 これらのファイルを一定数保持することをお勧めします。その数のファイルが作成されたら、ファイルの数とサイズの両方が制限されるようにファイルをローテーションします。 この使用パターンの場合、ロギングパッケージは RotatingFileHandler を提供します。
import glob
import logging
import logging.handlers
LOG_FILENAME = 'logging_rotatingfile_example.out'
# Set up a specific logger with our desired output level
my_logger = logging.getLogger('MyLogger')
my_logger.setLevel(logging.DEBUG)
# Add the log message handler to the logger
handler = logging.handlers.RotatingFileHandler(
LOG_FILENAME, maxBytes=20, backupCount=5)
my_logger.addHandler(handler)
# Log some messages
for i in range(20):
my_logger.debug('i = %d' % i)
# See what files are created
logfiles = glob.glob('%s*' % LOG_FILENAME)
for filename in logfiles:
print(filename)結果は6つの個別のファイルになり、それぞれにアプリケーションのログ履歴の一部が含まれます。
logging_rotatingfile_example.out
logging_rotatingfile_example.out.1
logging_rotatingfile_example.out.2
logging_rotatingfile_example.out.3
logging_rotatingfile_example.out.4
logging_rotatingfile_example.out.5最新のファイルは常にlogging_rotatingfile_example.outであり、サイズ制限に達するたびに、サフィックス.1で名前が変更されます。 既存の各バックアップファイルの名前を変更してサフィックスをインクリメントし（.1は.2などになります）、.6ファイルは消去されます。
明らかに、この例では、極端な例としてログの長さを非常に小さく設定しています。 maxBytes を適切な値に設定することをお勧めします。
辞書ベースの構成の例
以下は、ロギング構成ディクショナリの例です。これは、Djangoプロジェクトのドキュメントから抜粋したものです。 このディクショナリは dictConfig（）に渡され、構成が有効になります。
LOGGING = {
'version': 1,
'disable_existing_loggers': True,
'formatters': {
'verbose': {
'format': '%(levelname)s %(asctime)s %(module)s %(process)d %(thread)d %(message)s'
},
'simple': {
'format': '%(levelname)s %(message)s'
},
},
'filters': {
'special': {
'()': 'project.logging.SpecialFilter',
'foo': 'bar',
}
},
'handlers': {
'null': {
'level':'DEBUG',
'class':'django.utils.log.NullHandler',
},
'console':{
'level':'DEBUG',
'class':'logging.StreamHandler',
'formatter': 'simple'
},
'mail_admins': {
'level': 'ERROR',
'class': 'django.utils.log.AdminEmailHandler',
'filters': ['special']
}
},
'loggers': {
'django': {
'handlers':['null'],
'propagate': True,
'level':'INFO',
},
'django.request': {
'handlers': ['mail_admins'],
'level': 'ERROR',
'propagate': False,
},
'myproject.custom': {
'handlers': ['console', 'mail_admins'],
'level': 'INFO',
'filters': ['special']
}
}
}この構成の詳細については、Djangoドキュメントの関連セクションを参照してください。
SysLogHandlerに送信されるメッセージへのBOMの挿入
RFC 5424 では、Unicodeメッセージを次の構造を持つバイトのセットとしてsyslogデーモンに送信する必要があります。オプションのpure-ASCIIコンポーネントと、それに続くUTF-8バイトオーダーマーク（BOM）、続いて、UTF-8を使用してエンコードされたUnicode。 （仕様の関連セクションを参照してください。）
Python 2.6および2.7では、メッセージにBOMを挿入するコードが SysLogHandler に追加されましたが、残念ながら、BOMがメッセージの先頭に表示されるため、純粋なものが許可されないため、正しく実装されていませんでした。その前に表示されるASCIIコンポーネント。
この動作が壊れているため、Python2.7.4以降から誤ったBOM挿入コードが削除されています。 ただし、これは置き換えられていません。BOM、その前にオプションの純粋なASCIIシーケンス、その後に任意のUnicodeを含み、UTF-8を使用してエンコードされた、RFC 5424準拠のメッセージを生成する場合は、次のことを行う必要があります。続く：
Formatter インスタンスを SysLogHandler インスタンスに、次のようなフォーマット文字列でアタッチします。
u'ASCII section\ufeffUnicode section'Unicodeコードポイント
u'\ufeff'は、UTF-8を使用してエンコードされると、UTF-8 BOM（バイト文字列'\xef\xbb\xbf'）としてエンコードされます。ASCIIセクションを任意のプレースホルダーに置き換えますが、置換後にそこに表示されるデータが常にASCIIであることを確認してください（そうすると、UTF-8エンコード後も変更されません）。
Unicodeセクションを任意のプレースホルダーに置き換えます。 置換後に表示されるデータにASCII範囲外の文字が含まれている場合は、問題ありません。UTF-8を使用してエンコードされます。
フォーマットされたメッセージがUnicodeの場合、はSysLogHandlerによるUTF-8エンコーディングを使用してエンコードされます。 上記のルールに従うと、RFC5424準拠のメッセージを生成できるはずです。 そうしないと、ロギングは文句を言わないかもしれませんが、メッセージはRFC 5424に準拠せず、syslogデーモンが文句を言うかもしれません。
構造化ロギングの実装
ほとんどのロギングメッセージは人間が読むことを目的としているため、機械で簡単に解析することはできませんが、プログラムで解析できる構造化された形式でメッセージを出力したい場合があります（ログメッセージを解析するために複雑な正規表現が必要です）。 これは、ロギングパッケージを使用して簡単に実現できます。 これを実現する方法はいくつかありますが、以下はJSONを使用してマシンで解析可能な方法でイベントをシリアル化する簡単なアプローチです。
import json
import logging
class StructuredMessage(object):
def __init__(self, message, **kwargs):
self.message = message
self.kwargs = kwargs
def __str__(self):
return '%s >>> %s' % (self.message, json.dumps(self.kwargs))
_ = StructuredMessage # optional, to improve readability
logging.basicConfig(level=logging.INFO, format='%(message)s')
logging.info(_('message 1', foo='bar', bar='baz', num=123, fnum=123.456))上記のスクリプトを実行すると、次のように出力されます。
message 1 >>> {"fnum": 123.456, "num": 123, "bar": "baz", "foo": "bar"}使用するPythonのバージョンによって、アイテムの順序が異なる場合があることに注意してください。
より特殊な処理が必要な場合は、次の完全な例のように、カスタムJSONエンコーダーを使用できます。
from __future__ import unicode_literals
import json
import logging
# This next bit is to ensure the script runs unchanged on 2.x and 3.x
try:
unicode
except NameError:
unicode = str
class Encoder(json.JSONEncoder):
def default(self, o):
if isinstance(o, set):
return tuple(o)
elif isinstance(o, unicode):
return o.encode('unicode_escape').decode('ascii')
return super(Encoder, self).default(o)
class StructuredMessage(object):
def __init__(self, message, **kwargs):
self.message = message
self.kwargs = kwargs
def __str__(self):
s = Encoder().encode(self.kwargs)
return '%s >>> %s' % (self.message, s)
_ = StructuredMessage # optional, to improve readability
def main():
logging.basicConfig(level=logging.INFO, format='%(message)s')
logging.info(_('message 1', set_value=set([1, 2, 3]), snowman='\u2603'))
if __name__ == '__main__':
main()上記のスクリプトを実行すると、次のように出力されます。
message 1 >>> {"snowman": "\u2603", "set_value": [1, 2, 3]}使用するPythonのバージョンによって、アイテムの順序が異なる場合があることに注意してください。
dictConfig（）を使用したハンドラーのカスタマイズ
ロギングハンドラーを特定の方法でカスタマイズしたい場合があります。 dictConfig（）を使用すると、サブクラス化せずにこれを実行できる場合があります。 例として、ログファイルの所有権を設定したい場合があると考えてください。 POSIXでは、これは os.chown（）を使用して簡単に実行できますが、stdlibのファイルハンドラーは組み込みのサポートを提供していません。 次のような単純な関数を使用して、ハンドラーの作成をカスタマイズできます。
def owned_file_handler(filename, mode='a', encoding=None, owner=None):
if owner:
import os, pwd, grp
# convert user and group names to uid and gid
uid = pwd.getpwnam(owner[0]).pw_uid
gid = grp.getgrnam(owner[1]).gr_gid
owner = (uid, gid)
if not os.path.exists(filename):
open(filename, 'a').close()
os.chown(filename, *owner)
return logging.FileHandler(filename, mode, encoding)次に、 dictConfig（）に渡されるロギング構成で、次の関数を呼び出すことによってロギングハンドラーを作成するように指定できます。
LOGGING = {
'version': 1,
'disable_existing_loggers': False,
'formatters': {
'default': {
'format': '%(asctime)s %(levelname)s %(name)s %(message)s'
},
},
'handlers': {
'file':{
# The values below are popped from this dictionary and
# used to create the handler, set the handler's level and
# its formatter.
'()': owned_file_handler,
'level':'DEBUG',
'formatter': 'default',
# The values below are passed to the handler creator callable
# as keyword arguments.
'owner': ['pulse', 'pulse'],
'filename': 'chowntest.log',
'mode': 'w',
'encoding': 'utf-8',
},
},
'root': {
'handlers': ['file'],
'level': 'DEBUG',
},
}この例では、説明のために、pulseユーザーとグループを使用して所有権を設定しています。 それをまとめて動作するスクリプトchowntest.py：
import logging, logging.config, os, shutil
def owned_file_handler(filename, mode='a', encoding=None, owner=None):
if owner:
if not os.path.exists(filename):
open(filename, 'a').close()
shutil.chown(filename, *owner)
return logging.FileHandler(filename, mode, encoding)
LOGGING = {
'version': 1,
'disable_existing_loggers': False,
'formatters': {
'default': {
'format': '%(asctime)s %(levelname)s %(name)s %(message)s'
},
},
'handlers': {
'file':{
# The values below are popped from this dictionary and
# used to create the handler, set the handler's level and
# its formatter.
'()': owned_file_handler,
'level':'DEBUG',
'formatter': 'default',
# The values below are passed to the handler creator callable
# as keyword arguments.
'owner': ['pulse', 'pulse'],
'filename': 'chowntest.log',
'mode': 'w',
'encoding': 'utf-8',
},
},
'root': {
'handlers': ['file'],
'level': 'DEBUG',
},
}
logging.config.dictConfig(LOGGING)
logger = logging.getLogger('mylogger')
logger.debug('A debug message')これを実行するには、おそらくrootとして実行する必要があります。
$ sudo python3.3 chowntest.py
$ cat chowntest.log
2013-11-05 09:34:51,128 DEBUG mylogger A debug message
$ ls -l chowntest.log
-rw-r--r-- 1 pulse pulse 55 2013-11-05 09:34 chowntest.log
この例ではPython3.3を使用していることに注意してください。これは、shutil.chown()が表示される場所だからです。 このアプローチは、 dictConfig（）をサポートするすべてのPythonバージョン、つまりPython 2.7、3.2以降で機能するはずです。 3.3より前のバージョンでは、たとえばを使用して実際の所有権の変更を実装する必要があります。 os.chown（）。
実際には、ハンドラー作成関数は、プロジェクトのどこかにあるユーティリティモジュールにある場合があります。 構成の行の代わりに：
'()': owned_file_handler,たとえば、次のように使用できます。
'()': 'ext://project.util.owned_file_handler',ここで、project.utilは、関数が存在するパッケージの実際の名前に置き換えることができます。 上記の動作スクリプトでは、'ext://__main__.owned_file_handler'を使用すると動作するはずです。 ここで、実際の呼び出し可能オブジェクトは、ext://仕様の dictConfig（）によって解決されます。
この例は、他の種類のファイル変更を実装する方法も示していることを願っています。 特定のPOSIX許可ビットを設定する-同じ方法で、 os.chmod（）を使用します。
もちろん、このアプローチは、 FileHandler 以外のタイプのハンドラー（たとえば、回転するファイルハンドラーの1つ、またはまったく別のタイプのハンドラー）に拡張することもできます。
dictConfig（）を使用したフィルターの構成
は dictConfig（）を使用してフィルターを構成できますが、その方法は一見して明らかではないかもしれません（したがってこのレシピ）。 Filter は標準ライブラリに含まれる唯一のフィルタークラスであり、多くの要件に対応する可能性は低いため（基本クラスとしてのみ存在します）、通常は独自の Filterを定義する必要があります。 サブクラスとオーバーライドされた filter（）メソッド。 これを行うには、フィルターの構成ディクショナリで()キーを指定し、フィルターの作成に使用される呼び出し可能オブジェクトを指定します（クラスが最も明白ですが、[ X227X] Filter インスタンス）。 完全な例を次に示します。
import logging
import logging.config
import sys
class MyFilter(logging.Filter):
def __init__(self, param=None):
self.param = param
def filter(self, record):
if self.param is None:
allow = True
else:
allow = self.param not in record.msg
if allow:
record.msg = 'changed: ' + record.msg
return allow
LOGGING = {
'version': 1,
'filters': {
'myfilter': {
'()': MyFilter,
'param': 'noshow',
}
},
'handlers': {
'console': {
'class': 'logging.StreamHandler',
'filters': ['myfilter']
}
},
'root': {
'level': 'DEBUG',
'handlers': ['console']
},
}
if __name__ == '__main__':
logging.config.dictConfig(LOGGING)
logging.debug('hello')
logging.debug('hello - noshow')この例は、インスタンスを構成するcallableに構成データをキーワードパラメーターの形式で渡す方法を示しています。 実行すると、上記のスクリプトが出力されます。
changed: helloこれは、フィルターが構成どおりに機能していることを示しています。
注意すべきいくつかの追加ポイント：
- 構成で呼び出し可能オブジェクトを直接参照できない場合（例： 別のモジュールにあり、構成ディクショナリがある場所に直接インポートできない場合は、外部オブジェクトへのアクセスの説明に従って
ext://...の形式を使用できます。 たとえば、上記の例では、MyFilterの代わりにテキスト'ext://__main__.MyFilter'を使用できます。 - フィルタの場合と同様に、この手法を使用してカスタムハンドラとフォーマッタを構成することもできます。 ロギングが構成でのユーザー定義オブジェクトの使用をサポートする方法の詳細については、ユーザー定義オブジェクトを参照してください。また、上記の他のクックブックレシピ dictConfig（）を使用したハンドラーのカスタマイズを参照してください。
カスタマイズされた例外フォーマット
カスタマイズされた例外フォーマットを実行したい場合があります-引数のために、例外情報が存在する場合でも、ログに記録されたイベントごとに正確に1行が必要だとします。 次の例に示すように、カスタムフォーマッタクラスを使用してこれを行うことができます。
import logging
class OneLineExceptionFormatter(logging.Formatter):
def formatException(self, exc_info):
"""
Format an exception so that it prints on a single line.
"""
result = super(OneLineExceptionFormatter, self).formatException(exc_info)
return repr(result) # or format into one line however you want to
def format(self, record):
s = super(OneLineExceptionFormatter, self).format(record)
if record.exc_text:
s = s.replace('\n', '') + '|'
return s
def configure_logging():
fh = logging.FileHandler('output.txt', 'w')
f = OneLineExceptionFormatter('%(asctime)s|%(levelname)s|%(message)s|',
'%d/%m/%Y %H:%M:%S')
fh.setFormatter(f)
root = logging.getLogger()
root.setLevel(logging.DEBUG)
root.addHandler(fh)
def main():
configure_logging()
logging.info('Sample message')
try:
x = 1 / 0
except ZeroDivisionError as e:
logging.exception('ZeroDivisionError: %s', e)
if __name__ == '__main__':
main()実行すると、正確に2行のファイルが生成されます。
28/01/2015 07:21:23|INFO|Sample message|
28/01/2015 07:21:23|ERROR|ZeroDivisionError: integer division or modulo by zero|'Traceback (most recent call last):\n File "logtest7.py", line 30, in main\n x = 1 / 0\nZeroDivisionError: integer division or modulo by zero'|上記の処理は単純ですが、例外情報を好みに合わせてフォーマットする方法を示しています。 traceback モジュールは、より専門的なニーズに役立つ場合があります。
ロギングメッセージを話す
ロギングメッセージを可視形式ではなく可聴形式でレンダリングすることが望ましい場合があります。 これは、Pythonバインディングがなくても、システムでテキスト読み上げ（TTS）機能を使用できる場合は簡単に実行できます。 ほとんどのTTSシステムには、実行できるコマンドラインプログラムがあり、これはサブプロセスを使用してハンドラーから呼び出すことができます。 ここでは、TTSコマンドラインプログラムがユーザーとの対話や完了までに長い時間がかかることを想定しておらず、ログに記録されるメッセージの頻度がユーザーをメッセージでいっぱいにするほど高くはなく、メッセージは同時にではなく一度に1つずつ話されます。以下の実装例では、次のメッセージが処理される前に1つのメッセージが話されるのを待ちます。これにより、他のハンドラーが待機し続ける可能性があります。 これは、espeak TTSパッケージが利用可能であることを前提としたアプローチを示す短い例です。
import logging
import subprocess
import sys
class TTSHandler(logging.Handler):
def emit(self, record):
msg = self.format(record)
# Speak slowly in a female English voice
cmd = ['espeak', '-s150', '-ven+f3', msg]
p = subprocess.Popen(cmd, stdout=subprocess.PIPE,
stderr=subprocess.STDOUT)
# wait for the program to finish
p.communicate()
def configure_logging():
h = TTSHandler()
root = logging.getLogger()
root.addHandler(h)
# the default formatter just returns the message
root.setLevel(logging.DEBUG)
def main():
logging.info('Hello')
logging.debug('Goodbye')
if __name__ == '__main__':
configure_logging()
sys.exit(main())実行すると、このスクリプトは女性の声で「こんにちは」、次に「さようなら」と言うはずです。
もちろん、上記のアプローチは、他のTTSシステム、さらにはコマンドラインから実行される外部プログラムを介してメッセージを処理できる他のシステムにも適用できます。
ロギングメッセージをバッファリングし、条件付きで出力する
一時的な領域にメッセージを記録し、特定の条件が発生した場合にのみメッセージを出力したい場合があります。 たとえば、関数でデバッグイベントのログ記録を開始し、関数がエラーなしで完了した場合、収集したデバッグ情報でログを乱雑にしたくないが、エラーがある場合は、すべてのデバッグが必要な場合があります。出力する情報とエラー。
これは、ロギングをこのように動作させたい関数のデコレータを使用してこれを行う方法を示す例です。 logging.handlers.MemoryHandler を利用します。これにより、何らかの条件が発生するまでログに記録されたイベントをバッファリングできます。条件が発生すると、バッファリングされたイベントはflushed-別のハンドラー（[X212X ] ハンドラー）処理用。 デフォルトでは、MemoryHandlerは、バッファーがいっぱいになるか、レベルが指定されたしきい値以上のイベントが表示されるとフラッシュされます。 カスタムフラッシュ動作が必要な場合は、MemoryHandlerのより特殊なサブクラスでこのレシピを使用できます。
サンプルスクリプトには、fooという単純な関数があります。この関数は、すべてのログレベルを循環し、sys.stderrに書き込み、ログを記録しようとしているレベルを示し、実際にそのレベルでメッセージをログに記録します。レベル。 パラメータをfooに渡すことができます。これは、trueの場合、ERRORおよびCRITICALレベルでログに記録されます。それ以外の場合は、DEBUG、INFO、およびWARNINGレベルでのみログに記録されます。
スクリプトは、必要な条件付きロギングを実行するデコレータでfooをデコレートするように調整するだけです。 デコレータはロガーをパラメータとして受け取り、デコレートされた関数の呼び出し中にメモリハンドラをアタッチします。 デコレータは、ターゲットハンドラ、フラッシュが発生するレベル、およびバッファの容量を使用して、さらにパラメータ化できます。 これらはデフォルトで StreamHandler になり、それぞれsys.stderr、logging.ERROR、および100に書き込みます。
スクリプトは次のとおりです。
import logging
from logging.handlers import MemoryHandler
import sys
logger = logging.getLogger(__name__)
logger.addHandler(logging.NullHandler())
def log_if_errors(logger, target_handler=None, flush_level=None, capacity=None):
if target_handler is None:
target_handler = logging.StreamHandler()
if flush_level is None:
flush_level = logging.ERROR
if capacity is None:
capacity = 100
handler = MemoryHandler(capacity, flushLevel=flush_level, target=target_handler)
def decorator(fn):
def wrapper(*args, **kwargs):
logger.addHandler(handler)
try:
return fn(*args, **kwargs)
except Exception:
logger.exception('call failed')
raise
finally:
super(MemoryHandler, handler).flush()
logger.removeHandler(handler)
return wrapper
return decorator
def write_line(s):
sys.stderr.write('%s\n' % s)
def foo(fail=False):
write_line('about to log at DEBUG ...')
logger.debug('Actually logged at DEBUG')
write_line('about to log at INFO ...')
logger.info('Actually logged at INFO')
write_line('about to log at WARNING ...')
logger.warning('Actually logged at WARNING')
if fail:
write_line('about to log at ERROR ...')
logger.error('Actually logged at ERROR')
write_line('about to log at CRITICAL ...')
logger.critical('Actually logged at CRITICAL')
return fail
decorated_foo = log_if_errors(logger)(foo)
if __name__ == '__main__':
logger.setLevel(logging.DEBUG)
write_line('Calling undecorated foo with False')
assert not foo(False)
write_line('Calling undecorated foo with True')
assert foo(True)
write_line('Calling decorated foo with False')
assert not decorated_foo(False)
write_line('Calling decorated foo with True')
assert decorated_foo(True)このスクリプトを実行すると、次の出力が表示されます。
Calling undecorated foo with False
about to log at DEBUG ...
about to log at INFO ...
about to log at WARNING ...
Calling undecorated foo with True
about to log at DEBUG ...
about to log at INFO ...
about to log at WARNING ...
about to log at ERROR ...
about to log at CRITICAL ...
Calling decorated foo with False
about to log at DEBUG ...
about to log at INFO ...
about to log at WARNING ...
Calling decorated foo with True
about to log at DEBUG ...
about to log at INFO ...
about to log at WARNING ...
about to log at ERROR ...
Actually logged at DEBUG
Actually logged at INFO
Actually logged at WARNING
Actually logged at ERROR
about to log at CRITICAL ...
Actually logged at CRITICALご覧のとおり、実際のログ出力は、重大度がERROR以上のイベントがログに記録された場合にのみ発生しますが、その場合、重大度の低い以前のイベントもログに記録されます。
もちろん、従来の装飾手段を使用することもできます。
@log_if_errors(logger)
def foo(fail=False):
...
構成によるUTC（GMT）を使用した時間のフォーマット
UTCを使用して時刻をフォーマットしたい場合があります。これは、以下に示す UTCFormatter などのクラスを使用して実行できます。
import logging
import time
class UTCFormatter(logging.Formatter):
converter = time.gmtimeその後、 Formatter の代わりにUTCFormatterをコードで使用できます。 構成を介してこれを行う場合は、 dictConfig（） APIを使用して、次の完全な例で示すアプローチを使用できます。
import logging
import logging.config
import time
class UTCFormatter(logging.Formatter):
converter = time.gmtime
LOGGING = {
'version': 1,
'disable_existing_loggers': False,
'formatters': {
'utc': {
'()': UTCFormatter,
'format': '%(asctime)s %(message)s',
},
'local': {
'format': '%(asctime)s %(message)s',
}
},
'handlers': {
'console1': {
'class': 'logging.StreamHandler',
'formatter': 'utc',
},
'console2': {
'class': 'logging.StreamHandler',
'formatter': 'local',
},
},
'root': {
'handlers': ['console1', 'console2'],
}
}
if __name__ == '__main__':
logging.config.dictConfig(LOGGING)
logging.warning('The local time is %s', time.asctime())このスクリプトを実行すると、次のように出力されます。
2015-10-17 12:53:29,501 The local time is Sat Oct 17 13:53:29 2015
2015-10-17 13:53:29,501 The local time is Sat Oct 17 13:53:29 2015ハンドラーごとに1つずつ、現地時間とUTCの両方として時刻がどのようにフォーマットされるかを示します。
選択的ロギングのためのコンテキストマネージャーの使用
ロギング構成を一時的に変更し、何かを行った後に元に戻すと便利な場合があります。 このため、コンテキストマネージャは、ロギングコンテキストを保存および復元する最も明白な方法です。 このようなコンテキストマネージャーの簡単な例を次に示します。これにより、オプションでログレベルを変更し、純粋にコンテキストマネージャーのスコープ内にログハンドラーを追加できます。
import logging
import sys
class LoggingContext(object):
def __init__(self, logger, level=None, handler=None, close=True):
self.logger = logger
self.level = level
self.handler = handler
self.close = close
def __enter__(self):
if self.level is not None:
self.old_level = self.logger.level
self.logger.setLevel(self.level)
if self.handler:
self.logger.addHandler(self.handler)
def __exit__(self, et, ev, tb):
if self.level is not None:
self.logger.setLevel(self.old_level)
if self.handler:
self.logger.removeHandler(self.handler)
if self.handler and self.close:
self.handler.close()
# implicit return of None => don't swallow exceptionsレベル値を指定すると、ロガーのレベルは、コンテキストマネージャーがカバーするwithブロックのスコープ内でその値に設定されます。 ハンドラーを指定すると、ブロックに入るときにロガーに追加され、ブロックから出るときに削除されます。 ブロック終了時にハンドラーを閉じるようにマネージャーに依頼することもできます。ハンドラーが不要になった場合は、これを行うことができます。
それがどのように機能するかを説明するために、上記に次のコードブロックを追加できます。
if __name__ == '__main__':
logger = logging.getLogger('foo')
logger.addHandler(logging.StreamHandler())
logger.setLevel(logging.INFO)
logger.info('1. This should appear just once on stderr.')
logger.debug('2. This should not appear.')
with LoggingContext(logger, level=logging.DEBUG):
logger.debug('3. This should appear once on stderr.')
logger.debug('4. This should not appear.')
h = logging.StreamHandler(sys.stdout)
with LoggingContext(logger, level=logging.DEBUG, handler=h, close=True):
logger.debug('5. This should appear twice - once on stderr and once on stdout.')
logger.info('6. This should appear just once on stderr.')
logger.debug('7. This should not appear.')最初にロガーのレベルをINFOに設定したため、メッセージ＃1は表示され、メッセージ＃2は表示されません。 次に、次のwithブロックで一時的にレベルをDEBUGに変更すると、メッセージ＃3が表示されます。 ブロックが終了すると、ロガーのレベルがINFOに復元されるため、メッセージ＃4は表示されません。 次のwithブロックでは、レベルをDEBUGに再度設定しますが、sys.stdoutに書き込むハンドラーも追加します。 したがって、メッセージ＃5はコンソールに2回表示されます（1回はstderr経由、もう1回はstdout経由）。 withステートメントの完了後、ステータスは以前と同じであるため、メッセージ＃6は表示されますが（メッセージ＃1のように）、メッセージ＃7は表示されません（メッセージ＃2のように）。
結果のスクリプトを実行すると、結果は次のようになります。
$ python logctx.py
1. This should appear just once on stderr.
3. This should appear once on stderr.
5. This should appear twice - once on stderr and once on stdout.
5. This should appear twice - once on stderr and once on stdout.
6. This should appear just once on stderr.
もう一度実行しても、stderrを/dev/nullにパイプすると、stdoutに書き込まれる唯一のメッセージである次のメッセージが表示されます。
$ python logctx.py 2>/dev/null
5. This should appear twice - once on stderr and once on stdout.
繰り返しますが、stdoutを/dev/nullにパイプすると、次のようになります。
$ python logctx.py >/dev/null
1. This should appear just once on stderr.
3. This should appear once on stderr.
5. This should appear twice - once on stderr and once on stdout.
6. This should appear just once on stderr.
この場合、stdoutに出力されたメッセージ＃5は期待通りに表示されません。
もちろん、ここで説明するアプローチは、たとえばロギングフィルターを一時的にアタッチするなど、一般化することができます。 上記のコードはPython2とPython3で機能することに注意してください。
