Pythonのロガー出力先をOutputDebugStringに

この見出しそのもののことなら、需要がないのはわかってはいるんだけれども。

以前ロガーのカスタマイズについて職場で質問されて、「出来るはずよ」と曖昧に答えたのがなんとなく引っかかってたのね。だからいつか書こうと思ってたネタ。

「何か残るもの」に記録するのが普通はログの役割だから、向き先を「出したらそれっきり」の場所に固定しちゃうのは、「製品品質」ではあんまりやらない。けれど、目的が「デバッグ」の場合、「デバッガでしか拾えない」向き先って、結構価値がある。つまり、標準出力・標準エラー出力に混ぜ込むことなしに出力が欲しいが、ファイル出力ではそのファイルを覗き込むことが大変な場合もあるから。

Python logging の標準のハンドラはまぁ普通のニーズにはほとんど耐えられるほどに至れてて尽くせてるんだけれども、こうしたちょっとヘンな出力先にしたい場合は、ハンドラを書くか、ストリームを書く必要がある。

「カスタムハンドラが必要だ」のシチュエーションには例えば「私企業独自 C++ フレームワークのログ機能」なんかを相手にしなければならない場合、なんてのがあって、職場で質問されたのはそれ。そのケースが果たしてハンドラを書いた方がいいのか、ストリームを書けば済んだかは、結局その「独自フレームワークのロギング」の正体がわからずじまいだったので、わからない。なんにせよ「私企業独自 C++ フレームワークのログ機能に向ける」ロギングは、ネタとして面白い可能性がある。Cython ネタになったりするかもしれないしね。

なんだけど今回のこれ、「出力先を OutputDebugString に」では、ハンドラを書く必要はなくて、「StreamHandler」に渡せる stream だけ書けばいい。しかも幸いなことに、OutputDebugString は Windows native な CPython の場合、ctypes が何もしなくてもロードしている kernel32 にあるので、ほとんど何の苦労もない。

最も基礎的なバージョンだけ紹介しとく：

 1 # -*- coding: utf-8 -*-
 2 class WinOutputDebugStringStream(object):
 3     # mandatory:
 4     #     write(s)
 5     # optional:
 6     #     flush()
 7     #     encoding
 8     def __init__(self):
 9         from ctypes import windll
10         self._strm = windll.kernel32.OutputDebugStringW
11 
12     def write(self, s):
13         # FIXME: python2x dependancy.
14         # FIXME: OutputDebugString might prune if string is too long.
15         self._strm(unicode(s))
16 
17 
18 if __name__ == '__main__':
19     import logging
20     from logging import StreamHandler
21     sh = StreamHandler(WinOutputDebugStringStream())
22     logger = logging.getLogger(__name__)
23     logger.setLevel(logging.DEBUG)
24     logger.addHandler(sh)
25 
26     logger.debug(u"デバッグ")
27     import datetime
28     logger.debug(datetime.datetime.now())

OutputDebugStringA、OutputDebugStringW 出力を受け取れるもの、とは、Windows ネイティブのデバッガであればなんでもいいと思うんだけど、SysInternals の DbgView が手軽でいいと思う：

SysInternalsSuite は Microsoft 公式として入手出来ます(ただし、末尾の注意事項参照)。

普通 StreamHandler は「文字列の外部化」を伴うので、「Unicode(メモリ内部表現)から外部表現(utf-8など)へ」という流れになるんだけど、これの場合は面白いことにこれとは「逆にみえる」ことをする。Python 内部表現が「非 unicode」(ascii)だった場合、受け取る側の「OutputDebugStringW」は内部表現(Unicode)であることを期待するため、わざわざ Unicode 化してあげないといけない。

FIXME してある部分は、同じことをしたい人は自分でどうにかしてみて。一方は Python 2.x ならこのままでいい。もう一方は、受け取った s をスライスしながら出力すればいいと思うんだけど、何文字が制限だったか忘れちゃった。OutputDebugStringA は 256文字だったと思う。何も言わずに切り捨てられちゃうんで、実用的に使おうとするとすぐに問題になるよ。

バッファリングの問題、つまり「flushの実装」はやるならやればいい。でもバッファリングしたいなら MemoryHandler の方がいい気がする。あと、StreamHandler はストリームに encoding プロパティがいれば使うようになってる。これは今回の場合はいらない。というか必要なのは「decode」なので、StreamHandler が試みる「encode」を通しちゃむしろダメで。decode は全部 WinOutputDebugStringStream 内で完結させとかないとダメです。

SysInternalsSuite についての注意。

SysInternals は、その登場時点では「素晴らしく良いもの」でした。Windows 内部構造解析みたいなコアな技術情報提供をしてた「個人」だったのね、元々。それを Microsoft が「買収」みたいな形で「公式」になったのが SysInternalsSuite です。

Windows XP までは良かったんだけどね。ツール群の全てが Windows 7 以降向けに直されているわけではありません。全く動作しないものも入ってる。未だに「素晴らしい」くて Windows 7 でもバリバリ動くものもある一方で。(プロセスエクスプローラなんかはいまでも感動するほど使える。)

そんな理由もあって、かつてほど無条件に「これは良いもの」と薦めにくくなってる、というのが現状です。いまでも「凄まじくお奨め」なんですけどね、「動かないものが結構多いので注意」てことね。