ちょっとメモリ食いな処理を見直す必要があったので、変数が実際にどのくらいのサイズを使用しているのかを調べてみたのでメモ。
試した環境は以下。
% cat /etc/lsb-release
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=14.04
DISTRIB_CODENAME=trusty
DISTRIB_DESCRIPTION="Ubuntu 14.04.3 LTS"
% uname -a
Linux ubuntu64 3.13.0-63-generic #103-Ubuntu SMP Fri Aug 14 21:42:59 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux
Devel::Size::Report という Devel::Size の結果をより判りやすく出力してくれるライブラリを使った。
Devel::Size::Report - search.cpan.org
http://search.cpan.org/~tels/Devel-Size-Report-0.13/lib/Devel/Size/Report.pm
インストール
% cpanm Devel::Size::Report
% perl -MDevel::Size::Report -le 'print $Devel::Size::Report::VERSION'
0.13
使ってみる
use strict;
use warnings;
use utf8;
use Data::Dumper;
use Devel::Size::Report qw/report_size/;
print report_size(1), "\n";
print report_size(100), "\n";
print report_size("a"), "\n";
print report_size("foo"), "\n";
print report_size("foobarba"), "\n";
print report_size("foobarbaz"), "\n";
print report_size("ABCDEFGHIJKLMNOPQRSTUVWXYZ"), "\n";
print report_size("あ"), "\n";
print report_size("あいうえお"), "\n";
my @array = (0, 1, 2);
print report_size(\@array), "\n";
my $array_ref = [0, 1, 2];
print report_size($array_ref), "\n";
my $hash_ref = +{
foo => "FOO",
bar => "BAR",
baz => "BAZ",
};
print report_size(\$hash_ref), "\n";
undef $hash_ref->{bar};
print Dumper($hash_ref);
print report_size(\$hash_ref), "\n";
delete $hash_ref->{bar};
print Dumper($hash_ref);
print report_size(\$hash_ref), "\n";
出力は以下のようになった。
#
# Integer は 24 byte
#
Size report v0.13 for '1':
Read-Only Scalar 24 bytes
Total: 24 bytes in 1 elements
Size report v0.13 for '100':
Read-Only Scalar 24 bytes
Total: 24 bytes in 1 elements
#
# String は 8 文字目までは 42 byte で以降は 1 文字 1 byte で増えていく模様
#
Size report v0.13 for 'a':
Read-Only Scalar 42 bytes
Total: 42 bytes in 1 elements
Size report v0.13 for 'foo':
Read-Only Scalar 42 bytes
Total: 42 bytes in 1 elements
Size report v0.13 for 'foobarba':
Read-Only Scalar 42 bytes
Total: 42 bytes in 1 elements
Size report v0.13 for 'foobarbaz':
Read-Only Scalar 43 bytes
Total: 43 bytes in 1 elements
Size report v0.13 for 'ABCDEFGHIJKLMNOPQRSTUVWXYZ':
Read-Only Scalar 60 bytes
Total: 60 bytes in 1 elements
#
# UTF-8 なので全角文字でも byte サイズは同じ
#
Size report v0.13 for 'あ':
Read-Only Scalar 42 bytes
Total: 42 bytes in 1 elements
Size report v0.13 for 'あいうえお':
Read-Only Scalar 49 bytes
Total: 49 bytes in 1 elements
#
# 配列、配列リファレンスは同じ要素なのに Total がちょっと違う
#
Size report v0.13 for 'ARRAY(0x25f59c0)':
Array ref 192 bytes (overhead: 120 bytes, 62.50%)
Scalar 24 bytes
Scalar 24 bytes
Scalar 24 bytes
Total: 192 bytes in 4 elements
Size report v0.13 for 'ARRAY(0x2650348)':
Array ref 184 bytes (overhead: 112 bytes, 60.87%)
Scalar 24 bytes
Scalar 24 bytes
Scalar 24 bytes
Total: 184 bytes in 4 elements
#
# ハッシュリファレンス
#
Size report v0.13 for 'REF(0x260d288)' (REF):
Hash ref Ref 48 bytes (overhead: unknown)
Hash ref 453 bytes (overhead: 327 bytes, 72.19%)
'foo' => Scalar 42 bytes
'bar' => Scalar 42 bytes
'baz' => Scalar 42 bytes
Total: 48 bytes in 5 elements
#
# undef で値を削除したらなんか増えた??
#
$VAR1 = {
'foo' => 'FOO',
'bar' => undef,
'baz' => 'BAZ'
};
Size report v0.13 for 'REF(0x260d288)' (REF):
Hash ref Ref 48 bytes (overhead: unknown)
Hash ref 499 bytes (overhead: 383 bytes, 76.75%)
'foo' => Scalar 42 bytes
'bar' => Scalar 32 bytes
'baz' => Scalar 42 bytes
Total: 48 bytes in 5 elements
#
# delete でキーを削除したら減った
#
$VAR1 = {
'foo' => 'FOO',
'baz' => 'BAZ'
};
Size report v0.13 for 'REF(0x260d288)' (REF):
Hash ref Ref 48 bytes (overhead: unknown)
Hash ref 406 bytes (overhead: 322 bytes, 79.31%)
'foo' => Scalar 42 bytes
'baz' => Scalar 42 bytes
Total: 48 bytes in 4 elements
あちこちで言われている事のようなので Perl 使いとしては常識なのかも知れないけど、確かに思っていた以上にメモリ食い過ぎな感じがする。
大量データをハッシュで保持してる場合、使い終わったものはこまめに delete で削除した方が良さそうだが本当にそういう方法でいいのだろうか。
この辺り何かベストプラクティス的な方法あるのかな・・・。
Apache のログを読み込んでみる
もう少し実際的なデータで試したかったので、 100 行の Apache のログを読み込み、一行毎に Hash に変換して配列に保持した場合を計測してみる。
まずは apache-loggen を使用して Apache のログを生成。
生成されるログのフォーマットは combined っぽい。
# インストール
% gem install apache-loggen
# ログは追記されるので同名ファイルがある場合削除しておく
% rm example.log
# 指定行数 + 1 行が生成されるようなので -1 した数を指定
% apache-loggen --limit=99 example.log
# 確認
% wc -l example.log
100 example.log
% ls -l example.log
-rw-rw-r-- 1 akishin akishin 22414 10月 8 23:15 example.log
100 行で約 22 KB。
これを以下のようなスクリプトで読み込んでサイズを計測してみる。
use strict;
use warnings;
use utf8;
use Data::Dumper;
use Devel::Size::Report qw/report_size/;
my $log_file = 'example.log';
my $pattern = qr/^(.*) (.*) (.*) \[(.*)\] "(.*)" (.*) (.*) "(.*)" "(.*)"$/;
my @logs;
open(my $fh, '<', $log_file) or die "cannot open $log_file: $!";
while(my $log = <$fh>) {
if ($log =~ $pattern) {
my $hash = +{};
$hash->{host} = $1;
$hash->{ident} = $2;
$hash->{user} = $3;
$hash->{time} = $4;
($hash->{method}, $hash->{path}, $hash->{version}) = split(/ /, $5);
$hash->{status} = $6;
$hash->{size} = $7;
$hash->{referer} = $8;
$hash->{user_agent} = $9;
push(@logs, $hash);
}
}
close($fh);
print report_size(\@logs), "\n";
実行すると出力は以下のようになった(長いので途中一部省略)。
Size report v0.13 for 'ARRAY(0x196c780)':
Array ref 184787 bytes (overhead: 896 bytes, 0.48%)
Hash ref 2053 bytes (overhead: 907 bytes, 44.18%)
'ident' => Scalar 82 bytes
'path' => Scalar 55 bytes
'referer' => Scalar 242 bytes
'time' => Scalar 100 bytes
'version' => Scalar 42 bytes
'user' => Scalar 82 bytes
'host' => Scalar 87 bytes
'user_agent' => Scalar 250 bytes
'method' => Scalar 42 bytes
'size' => Scalar 82 bytes
'status' => Scalar 82 bytes
・
・
・
Hash ref 1873 bytes (overhead: 907 bytes, 48.42%)
'user' => Scalar 82 bytes
'version' => Scalar 42 bytes
'host' => Scalar 88 bytes
'user_agent' => Scalar 236 bytes
'status' => Scalar 82 bytes
'size' => Scalar 82 bytes
'method' => Scalar 42 bytes
'ident' => Scalar 82 bytes
'path' => Scalar 48 bytes
'referer' => Scalar 82 bytes
'time' => Scalar 100 bytes
Total: 184787 bytes in 1201 elements
184 KB になった。
念の為 1000 行で試してみる。
% rm example.log
% apache-loggen --limit=999 example.log
% wc -l example.log
1000 example.log
% ls -l example.log
-rw-rw-r-- 1 akishin akishin 221957 10月 9 00:02 example.log
% ls -lh example.log
-rw-rw-r-- 1 akishin akishin 217K 10月 9 00:02 example.log
ファイルサイズは大体 10 倍で 217 KB になった。
Perl スクリプト実行結果は以下。
Size report v0.13 for 'ARRAY(0x2563780)':
Array ref 1846038 bytes (overhead: 8944 bytes, 0.48%)
Hash ref 1795 bytes (overhead: 907 bytes, 50.53%)
'ident' => Scalar 82 bytes
'version' => Scalar 42 bytes
'user_agent' => Scalar 150 bytes
'user' => Scalar 82 bytes
'size' => Scalar 82 bytes
'referer' => Scalar 82 bytes
'path' => Scalar 56 bytes
'time' => Scalar 100 bytes
'status' => Scalar 82 bytes
'host' => Scalar 88 bytes
'method' => Scalar 42 bytes
・
・
・
Total: 1846038 bytes in 12001 elements
約 1.8 MB。
こちらも単純に 10 倍になった。
一行ずつ必要な値のみ取り出して読み捨てにできるような処理の場合は良いけど、ある程度の範囲のログをまとめて読み込んで分析する必要があるような場合は結構辛そう。
GNU time でも測ってみる
OS から見た時のスクリプトのメモリ使用量はどうなってるのかも気になったので、GNU time でも測ってみた。
シェル組み込みの time
と違って GNU time の方は実行したプロセスの最大 RSS も出力してくれる。
手元の環境に入っていたバージョンは以下。
% /usr/bin/time --version
GNU time 1.7
計測してみると以下のようになった。
% /usr/bin/time perl parse_log.pl
・
・
・
Total: 1846038 bytes in 12001 elements
0.35user 0.04system 0:00.46elapsed 85%CPU (0avgtext+0avgdata 11436maxresident)k
0inputs+0outputs (0major+15909minor)pagefaults 0swaps
デフォルトの出力のフォーマットは以下とのこと。
%Uuser %Ssystem %Eelapsed %PCPU (%Xtext+%Ddata %Mmax)k
%Iinputs+%Ooutputs (%Fmajor+%Rminor)pagefaults %Wswaps
この中の %M
のところが
プロセス生存中のそのプロセスの resident set size の最大値。 キロバイト単位。
とのことなので、最大 RSS は 11,436 KB という事になる。
Devel::Size::Report
の結果とはちょっと違うけど、まぁでも大きいことには変わりはない。
TokyoCabinet のオンメモリハッシュを使ってみる
何かお手軽な対策はないのかと検索していたら以下の記事を見つけたので、TokyoCabinet のオンメモリハッシュで試してみる。
PerlとRubyで省メモリなハッシュを使おう - mixi Engineers' Blog
http://alpha.mixi.co.jp/entry/2009/10739/
先ほどのスクリプトを以下のように変更。
use strict;
use warnings;
use utf8;
use Data::Dumper;
use Devel::Size::Report qw/report_size/;
use TokyoCabinet;
my $log_file = 'example.log';
my $pattern = qr/^(.*) (.*) (.*) \[(.*)\] "(.*)" (.*) (.*) "(.*)" "(.*)"$/;
my @logs;
open(my $fh, '<', $log_file) or die "cannot open $log_file: $!";
while(my $log = <$fh>) {
if ($log =~ $pattern) {
my $hash;
tie(%{$hash}, "TokyoCabinet::ADB", "*");
$hash->{host} = $1;
$hash->{ident} = $2;
$hash->{user} = $3;
$hash->{time} = $4;
($hash->{method}, $hash->{path}, $hash->{version}) = split(/ /, $5);
$hash->{status} = $6;
$hash->{size} = $7;
$hash->{referer} = $8;
$hash->{user_agent} = $9;
push(@logs, $hash);
}
}
close($fh);
print report_size(\@logs), "\n";
実行してみる。
% /usr/bin/time perl parse_log2.pl
Size report v0.13 for 'ARRAY(0x24a6628)':
Array ref 3776944 bytes (overhead: 8944 bytes, 0.24%)
Hash ref 3768 bytes (overhead: 312 bytes, 8.28%)
'path' => Scalar 314 bytes
'user_agent' => Scalar 316 bytes
'host' => Scalar 314 bytes
'version' => Scalar 314 bytes
'user' => Scalar 314 bytes
'time' => Scalar 314 bytes
'method' => Scalar 314 bytes
'size' => Scalar 314 bytes
'referer' => Scalar 314 bytes
'ident' => Scalar 314 bytes
'status' => Scalar 314 bytes
・
・
・
Hash ref 3768 bytes (overhead: 312 bytes, 8.28%)
'path' => Scalar 314 bytes
'user_agent' => Scalar 316 bytes
'host' => Scalar 314 bytes
'version' => Scalar 314 bytes
'user' => Scalar 314 bytes
'time' => Scalar 314 bytes
'method' => Scalar 314 bytes
'size' => Scalar 314 bytes
'referer' => Scalar 314 bytes
'ident' => Scalar 314 bytes
'status' => Scalar 314 bytes
Total: 3776944 bytes in 12001 elements
0.44user 0.31system 0:00.76elapsed 98%CPU (0avgtext+0avgdata 423600maxresident)k
0inputs+848outputs (0major+121141minor)pagefaults 0swaps
Devel::Size::Report
の出力だと 3,776,944 byte なので約 3.7 MB。
予想と違ってなんか増えてしまった。
このスクリプトだと使い方が「Hash に大量のデータを詰め込む」ではなく「大量の Hash を生成する」になっているのでそのせいなのか?
それとも tie
した Hash のメモリ使用量は Devel::Size::Report
だと正確に取得できない、とかかなー?
time
の出力の方はというと 423,600 KBなので約 423 MB !?
さすがになんかおかしい気がする。
もしかして Devel::Size::Report
での解析時に実使用量が増えてるとかなのかと思い、print
している箇所をコメントアウトし、-v
オプション付きで実行してみる。
% /usr/bin/time -v perl parse_log2.pl
Command being timed: "perl parse_log2.pl"
User time (seconds): 0.08
System time (seconds): 0.44
Percent of CPU this job got: 99%
Elapsed (wall clock) time (h:mm:ss or m:ss): 0:00.53
Average shared text size (kbytes): 0
Average unshared data size (kbytes): 0
Average stack size (kbytes): 0
Average total size (kbytes): 0
Maximum resident set size (kbytes): 418284
Average resident set size (kbytes): 0
Major (requiring I/O) page faults: 0
Minor (reclaiming a frame) page faults: 119801
Voluntary context switches: 88
Involuntary context switches: 71
Swaps: 0
File system inputs: 0
File system outputs: 0
Socket messages sent: 0
Socket messages received: 0
Signals delivered: 0
Page size (bytes): 4096
Exit status: 0
Maximum resident set size (kbytes): 418284
なのでほぼ変わらず・・・。
この程度のスクリプトだと一瞬で終わってしまうので、本当にこれだけ使ってしまっているのか、ライブラリの使い方が間違っているのか、そもそも計測方法が間違っているのか・・・。
良く判らなくなってきたが、取り敢えず一旦ここまで。
参考
やはり Perl はメモリ喰いな言語。データ型の内部構造 - drk7jp
http://www.drk7.jp/MT/archives/000803.html
Devel::Size - Perl変数のメモリ使用量を調べる - perldoc.jp
http://perldoc.jp/docs/modules/Devel-Size-0.58/Size.pod
Devel::Sizeで変数のメモリ量を計測したら、でかくて驚いた - end0tknrのkipple - web写経開発
http://d.hatena.ne.jp/end0tknr/20111004/1317732034