2015-02-18

Python: Unbuffered read and write

今回の環境。少し古いのは、そんな環境でも動かす必要があるから。

# cat /etc/redhat-release
CentOS release 5.5 (Final)

# rpm -q python
python-2.4.3-27.el5

長年システムの仕事をしていると、例えば「出力にタイムスタンプを付けたい」とかいうことが一度くらいはあるはず。普段そんな時は Perl でサクッと作るのだが、今回は訳あって Python を使う必要があった。

この手のスクリプトで考えるべきは、バッファリング制御。Python にもこの手のパターンというのがあって、少しググれば stackoverflow とかに山ほどスレッドが見つかる。

timestamp.py:

#!/usr/bin/python

import fileinput
import os
import signal
import sys
import time

sys.stdin = os.fdopen(sys.stdin.fileno(), 'rb', 0)
sys.stdout = os.fdopen(sys.stdout.fileno(), 'wb', 0)
signal.signal(signal.SIGPIPE, signal.SIG_DFL)

def main():
    for line in fileinput.input(sys.argv[1:]):
        sys.stdout.write(time.strftime('%F %T ') + line)
    return 0

if __name__ == '__main__':
    sys.exit(main())

上記で、fdopen の「おまじない」部分がそれに当たる。これで標準入出力のバッファリングを無効にしている。その下の signal 云々は、忌まわしき broken pipe を封じる呪文。これも Python 暗黒面の 1 つ。

と作ったスクリプトだが、

# ping -c 5 127.0.0.1 | python timestamp.py -
2015-02-18 18:41:42 PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
2015-02-18 18:41:42 64 bytes from 127.0.0.1: icmp_seq=1 ttl=64 time=0.016 ms
2015-02-18 18:41:42 64 bytes from 127.0.0.1: icmp_seq=2 ttl=64 time=0.014 ms
2015-02-18 18:41:42 64 bytes from 127.0.0.1: icmp_seq=3 ttl=64 time=0.009 ms
2015-02-18 18:41:42 64 bytes from 127.0.0.1: icmp_seq=4 ttl=64 time=0.009 ms
2015-02-18 18:41:42 64 bytes from 127.0.0.1: icmp_seq=5 ttl=64 time=0.016 ms
2015-02-18 18:41:42 
2015-02-18 18:41:42 --- 127.0.0.1 ping statistics ---
2015-02-18 18:41:42 5 packets transmitted, 5 received, 0% packet loss, time 3999ms
2015-02-03 18:41:42 rtt min/avg/max/mdev = 0.009/0.012/0.016/0.005 ms

全然効いてなーい。めっちゃバッファリングしてる。

前述のおまじない以外にも、Python の起動オプション -u でバッファリングを無効にできるが、それでやっても結果は変わらず。訳が分からないので help & man を良く読んでみる。

# python -h

<...snip...>

-u     : unbuffered binary stdout and stderr (also PYTHONUNBUFFERED=x)
         see man page for details on internal buffering relating to '-u'

# man python

<...snip...>

       -u     Force stdin, stdout and stderr to  be  totally  unbuffered.   On
              systems  where  it matters, also put stdin, stdout and stderr in
              binary mode.  Note that there is internal  buffering  in  xread-
              lines(),  readlines()  and  file-object  iterators ("for line in
              sys.stdin") which is not influenced by  this  option.   To  work
              around  this, you will want to use "sys.stdin.readline()" inside
              a "while 1:" loop.

man の方に衝撃的なことが書いてある。「xreadlines, readlines, ファイルオブジェクトイテレーターは内部バッファリングするから、while + readline を使えよ」って、それってあんまりじゃね? readlines の方はともかく、イテレーターの方は裏切られた気持ちで一杯だ。

と文句を言っても仕方がないので、while + readline で書き直してみる。

def main():
    readline = fileinput.input(sys.argv[1:]).readline
    while True:
        line = readline()
        if not line:
            break
        sys.stdout.write(time.strftime('%F %T ') + line)
    return 0

しかし結果は全く変わらず。もしかして、と思い fileinput の実装を見てみると、

案の定、FileInput.readline で readlines を呼んでおり、ここでバッファリングされるらしい。Python3 でも改善は見られず。なんだよ、fileinput 使えねー。今までファイル入力にはずっと fileinput を使ってきたのに、今後は考え直した方が良さそうだ。

そんなこんなで、最終的には下記のようになった。iter(fh.readline, '') の意味は各自で調べて欲しい。私も今回初めてこの使い方を知った。

timestamp.py:

#!/usr/bin/python

import signal
import sys
import time

signal.signal(signal.SIGPIPE, signal.SIG_DFL)

def main():
    strftime = time.strftime
    write = sys.stdout.write
    for arg in sys.argv[1:]:
        fh = arg == '-' and sys.stdin or open(arg)
        try:
            for line in iter(fh.readline, ''):
                write(strftime('%F %T ') + line)
        finally:
            if fh is not sys.stdin:
                fh.close()
    return 0

if __name__ == '__main__':
    sys.exit(main())
# ping -c 5 127.0.0.1 | python timestamp.py -
2015-02-18 18:46:36 PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
2015-02-18 18:46:36 64 bytes from 127.0.0.1: icmp_seq=1 ttl=64 time=0.019 ms
2015-02-18 18:46:37 64 bytes from 127.0.0.1: icmp_seq=2 ttl=64 time=0.012 ms
2015-02-18 18:46:38 64 bytes from 127.0.0.1: icmp_seq=3 ttl=64 time=0.011 ms
2015-02-18 18:46:39 64 bytes from 127.0.0.1: icmp_seq=4 ttl=64 time=0.009 ms
2015-02-18 18:46:40 64 bytes from 127.0.0.1: icmp_seq=5 ttl=64 time=0.009 ms
2015-02-18 18:46:40 
2015-02-18 18:46:40 --- 127.0.0.1 ping statistics ---
2015-02-18 18:46:40 5 packets transmitted, 5 received, 0% packet loss, time 3999ms
2015-02-03 18:46:40 rtt min/avg/max/mdev = 0.009/0.012/0.019/0.003 ms

fdopen のおまじない部分は、なくても動いたので削除した。公式ドキュメントによれば、標準入出力は「行バッファリング」が規定値らしいので、今回の用途ではこれで良さそうだ。

A negative bufsize means to use the system default, which is usually line buffered for tty devices and fully buffered for other files. If omitted, the system default is used.

結局のところ、

  • ファイルオブジェクトイテレーターが入力をバッファリングする
  • fileinput に至っては、Fileinput.readline でさえも入力をバッファリングする

というのが事の元凶だったらしい。特に fileinput、お前はこの手のリアルタイム入力には二度と使わねえ。

まさかこんな単純なスクリプトでここまでハマるとは思わなかった。これでまた 1 つ Python が嫌いになった。使えば使うほど嫌いになっていくのが Python、使うほど手に馴染むのが Perl。:-)


2016-07-18 追記

fileinput の方は、最近になって修正されたっぽい。たぶん 2.7.12 と 3.5.2 から。動作は未確認。