2012年11月26日月曜日

Perlのprintfの謎4096バイト問題

/proc/net/devを定期的に読んで、テキトーに整形して
テキストファイルに吐き出すスクリプトを書いていた時に気付いた。

3秒に1回/proc/net/devを読んでprintfで書かせる様にしている割に、
なぜかtail -fで出力先ファイルを開いても何も表示されない。

かと思うと、しばらくしてからがばっと出力、またしばらく沈黙が続く。

コードはこんなの。


while() {

if (! -e $sPidFile) { exit 0; }

### open /proc/net/dev.
sysopen(IN, "/proc/net/dev", O_RDONLY);
printf(OUT "%s", time());

while ($sBuff = <IN>) {
if ($sBuff =~ /(.+):(.+)/) {
chomp($sBuff);
$sBuff =~ s/.+:\s+//;
printf(OUT "\t%s", $sBuff);
} else {
next;
}
}

printf(OUT "\n");
sleep($sInterval);
}

美しくないけど泣かない。

strace -t -e write,readで見てみたらこんなになってた。

14:59:12 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:12 read(5, "", 4096)              = 0
14:59:15 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:15 read(5, "", 4096)              = 0
14:59:18 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:18 read(5, "", 4096)              = 0
14:59:21 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:21 read(5, "", 4096)              = 0
14:59:24 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:24 read(5, "", 4096)              = 0
14:59:27 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:27 read(5, "", 4096)              = 0
14:59:30 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:30 read(5, "", 4096)              = 0
14:59:33 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:33 read(5, "", 4096)              = 0
14:59:36 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:36 write(4, "909543\t0       0    0    0    0 "..., 4096) = 4096
14:59:36 read(5, "", 4096)              = 0
14:59:39 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:39 read(5, "", 4096)              = 0
14:59:42 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:42 read(5, "", 4096)              = 0
14:59:45 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:45 read(5, "", 4096)              = 0
14:59:48 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:48 read(5, "", 4096)              = 0
14:59:51 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:51 read(5, "", 4096)              = 0
14:59:54 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:54 read(5, "", 4096)              = 0
14:59:57 read(5, "Inter-|   Receive               "..., 4096) = 569
14:59:57 read(5, "", 4096)              = 0
15:00:00 read(5, "Inter-|   Receive               "..., 4096) = 569
15:00:00 read(5, "", 4096)              = 0
15:00:03 read(5, "Inter-|   Receive               "..., 4096) = 569
15:00:03 read(5, "", 4096)              = 0
15:00:06 read(5, "Inter-|   Receive               "..., 4096) = 569
15:00:06 read(5, "", 4096)              = 0
15:00:09 read(5, "Inter-|   Receive               "..., 4096) = 569
15:00:09 read(5, "", 4096)              = 0
15:00:12 read(5, "Inter-|   Receive               "..., 4096) = 569
15:00:12 write(4, "   0    0    0     0       0    "..., 4096) = 4096

読んだものを加工してから書かせてるから、毎回569バイトずつ溜まってる訳じゃないはずなんだけど、
なんか4096バイトまで溜め込んでwrite()している雰囲気。

なんだろう。。

2 件のコメント :

  1. sleepの前で明示的にフラッシュするか、ファイルハンドラに
    対してバッファリングしないことを指定することで解消されます。
    サンプルコードとしては以下のような感じでしょうか.

    https://gist.github.com/4147516#file_buffer_flush.pl

    問題としては、Perlというより OS側の問題になるかと
    思います。他の言語で書いたとしても同様の問題が発生
    するはずです。

    返信削除
    返信
    1. どうもありがとうございます!

      サンプルコードまで書き下ろしていただいてありがたい限りです(つд`)
      これからも精進しますー。

      削除