読者です 読者をやめる 読者になる 読者になる

Catalyst debug log 有効で大きなデータを POST したら予想外にメモリ使って驚いた

タイトルがすべてですよ。
Debug mode ではログに query param が出力されるので、(ファイルアップロードじゃなく) 大きなデータを渡すと、一旦全部文字列にしてメモリに持つため予想以上にメモリを食って「どこでこんな使ってるんだ?」と悩んだお話。

  • 1MB の文字列を変数にいれて
  • Text::SimpleTable で整形して
  • Catalyst::Log で出力に渡す

というコードを書いて実験したら、以下のような消費量推移。
10MB 〜 15MB ぐらい消費量が増えてますね。

# This is perl, v5.8.5 built for i386-linux-thread-multi
7.89MB start
9.90MB create 1MB string
16.43MB push row
24.11MB draw table & debug log

# This is perl, v5.10.0 built for x86_64-linux-gnu-thread-multi
55.55MB start
57.55MB create 1MB string
65.65MB push row
74.72MB draw table & debug log

実際に debug 有効の Catalyst で試すと、1MB の query string を POST した場合で 30MB 〜 45MB ぐらい(環境による)メモリを食うようです。無効にすれば 6MB 〜 13MB 程度でした。
まあ、だからなんだという話なのですが。別にリークしてるわけではないので、POST が繰り返されても際限なくメモリを消費していく、などということはありません。念のため。
間違って本番環境で debug 有効になっちゃってると、危ないかもしれませんね。

use strict;
use warnings;
use Text::SimpleTable;
use GTop;
use Catalyst::Log;
sub mem {
    my $msg = shift;
    printf "%.2fMB %s\n", (GTop->new->proc_mem($$)->size / 1024**2), $msg;
}
my $t = Text::SimpleTable->new( [ 10, "name" ], [ 70, "value" ] );
mem("start");
my $text = "x" x (1024**2); # 1MB
mem("create 1MB string");
$t->row( "foo", $text );
mem("push row");
my $log = Catalyst::Log->new;
$log->debug("table\n" . $t->draw);
mem("draw table & debug log");