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 暗黒面の一つ。

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

# 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 を使ってきたが、今後は考え直した方が良さそうだ。

そんなこんなで、最終的には次のようになった。

timestamp.py:

#!/usr/bin/python

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 arg in sys.argv[1:]:
        fh = arg == '-' and sys.stdin or open(arg, 'rb', 0)
        try:
            for line in iter(fh.readline, ''):
                sys.stdout.write(time.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 のおまじないが無くてもそれらしく動く。少なくともテストした限りではそうだった。結局のところ、

  • イテレーターが入力をバッファリングする
  • fileinput は readline でさえも、入力をバッファリングする

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

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


2016-07-18 追記

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

しかし、元々 fileinput が readlines を使うようになったのは高速化のためだろうから、全く readlines を使わないようにした上記の修正には疑問が残る。組み込みファイルオブジェクトのように、readline だけバッファリングしないように UI を合わせる手は無かったのだろうか。