Perl や Python における標準ライブラリの IO Buffering

先日、pt-deadlock-logger を用いて Deadlock Events のログシステムを構築していた際に、明らかに Database への接続に成功しているのに、なぜか Deadlock Events が STDOUT に表示されない（実際には遅延している）、という現象にあたった。

それも、docker run および ECS Cluster にデプロイした時にだけ発生する現象で、docker run -t で端末を割り当てたり、手元の Terminal.app から直接 pt-deadlock-logger を実行している場合（= 端末が割り当てられている場合）には、実行後すぐに出力結果が確認できるのである。

しばらく後に判明したのだが、理由はこうだ。pt-deadlock-logger は Perl で実装されているのだが、Perl はデフォルトで STDOUT などの I/O Event を buffering するため、ログの出力結果が少ない場合は遅延して表示される、という結論に行き着いた。

• Perl: https://perl.plover.com/FAQs/Buffering.html

I/O Event を Programming Language の標準ライブラリのレベルで実装するのはたしかに理にかなっていて、Ruby でも Python でも実装されている。syscalls の回数を減らすことで CPU 利用効率を高めるのは、よく見られる最適化の一つだ。そして、端末が割り当てられているかどうかで、Perl/Ruby/Python いずれもこの buffering を有効/無効にしているようだ（それが docker run -t で動作した理由だ）。

• Ruby: IO.sync=
• Python: $PYTHONUNBUFFERED or python -u

もちろん、Production で動作するアプリケーションで無闇に buffering を無効にするべきではないものの、特定の条件下で無効にする必要がある場合もある。

Python の場合、便利なことに環境変数で挙動を変えられる。しかし、Perl は source code を変更する必要がある。例えば、$io->autoflush() を利用することで実質 buffering を無効にできる。

  use IO::Handle;STDOUT->autoflush(1);

Perl は詳しくないのでこれが Best Practice なのかは分からないが、pt-deadlock-logger の方にも PR を送ってある。