妻が先生をやっていらっしゃる。 Ruby on Rails 入門 ~ミニブログの制作~（全5回）
美人（公式見解）教師が丁寧に授業をやっていらっしゃいます。私も毎回 Ruby on Rails の勉強をさせてもらっています。
毎回見てるんだけど、こういうのを見ていると、また授業とかやりたくなるな。何か、単発の授業・講演のご用があれば、お声かけ下さい。コンピュータサイエンス基礎みたいな授業とか、Ruby 処理系に関するもの、OSS 開発に関する話、などの経験があります。ただ、長期の授業は職場の許可が下りなさそうな感じです（以前、半期の授業の申請が却下されてしまいました...）。
小ネタ。
Ruby で $3 みたいにかくと、$~[3]、つまり Regexp.last_match[3] の略、みたいに動きます。
/(a)(b)(c)/ =~ 'abc' p $3 #=> 'c' p $~[3] #=> 'c' p Regexp.last_match[3] #=> 'c'
さて、何もマッチさせていない時はどうでしょうか。
def foo $3 end p foo #=> nil
該当するものがないので nil が返ります。
さて、先日紹介した allocation_tracer gem を使ってみます。
require 'pp'
require 'allocation_tracer'
def foo
$3 # return nil <- ここが 6 行目
end
pp ObjectSpace::AllocationTracer.trace{
1_000.times{
foo
}
}
#=> {["../../trunk/test.rb", 6]=>[1000, 0, 0, 0, 0, 0]}
なんか、メソッドを実行ごとにオブジェクトを生成しています。これ、何かわかりますか？
ヒント：ちなみに、数を増やしてもオブジェクトは増えません。
require 'pp'
require 'allocation_tracer'
def foo
a = $3 # return nil
b = $4 # return nil
c = $~ # return nil
end
pp ObjectSpace::AllocationTracer.trace{
1_000.times{
foo
}
}
#=> {["../../trunk/test.rb", 6]=>[1000, 0, 0, 0, 0, 0]}
ネタばらしをすると、さっき気づいたパフォーマンスバグなんですが、まぁマッチもしていないのに $3 みたいなのを書く人いないから、まぁ問題無いよね。
ちなみに作るのは意外なオブジェクトです。
r49721 で修正した。
pwd が何の略か？ ということを聞かれた。確かに答えられない。
http://www.abbreviations.com/pwd の中で working directory を含むものをピックアップすると、
の３説が見つかる。
man を見ても、あんまりしっくりこない。なんで cwd （current working directory）にしなかったんだろう？ system call は getcwd(2) なのに。
This is Japanese-English translation of last two days entries: Ruby's performance tuning way
昨日の続き。
早速中田さんが r49614 を入れてくれて、こういう a, b = x, y の時には、
push x # stack: x push y # stack: x y newarray 2 # stack: [x, y] expandarray 2, 0 # stack: y, x set a # stack: y # a = x set b # stack: # b = y
だったのを、
push x # stack: x push y # stack: x y swap # stack: y x set a # stack: y # a = x set b # stack: # b = y
みたいにするようにしてくれました。reverse という命令を使って、n 個あったときにも newarray 使わないようにする、って案もあったのですが、まぁ、たいてい 2 個でしょう、ということで、現状、すでにあった swap 命令を使うだけにしています。
ちなみに、a, b, c = x, y みたいに、左右バランスの取れていない奴もあります。a, b = x とか。そういう場合には、今まで通り配列を作るようになっています。この辺は、多分起きない例外ケース、として処理している感じです。
では、trunk で試してみましょう。
##############################
# scomb.rb
def newGap gap
gap /= 1.3;
gap = gap.to_i;
return 11 if gap == 9 or gap == 10
return 1 if gap < 1
gap
end
def combSort a
len = a.length
gap = len
swapped = false
begin
swapped = false
gap = newGap gap
(0...(len-gap)).each do |i|
if a[i] > a[i+gap]
swapped = true
a[i], a[i+gap] = a[i+gap], a[i]
nil # これは入れている
end
end
end while gap > 1 or swapped
end
N = 10000000;
arr = N.times.map{|x| (N-x).to_s }
combSort arr
(1...N).each{ |z| print '!' if arr[z]<arr[z-1] }
実行すると。
CPU: 103.15s Real: 103.30s RAM: 527492KB
となりました。おめでとうございます。
さて、nil が格好悪いですね。GC tuning でなんとかならないでしょうか。
今回の例では、必要なオブジェクトの数はだいたい見積もれていました。10M 個＋α、というところです。
そこで、GC のヒープはあんまり広げない == RUBY_GC_HEAP_GROWTH_FACTOR=1.01 として、1% ずつしか広げないようにします。
しかし、これだと最初に凄い時間がかかってしまうので、最初に必要そうな 10M 個＋α、ここでは 12M 個としてみましょう、これを先に用意してあげます。これを RUBY_GC_HEAP_INIT_SLOTS=12000000 として指定します。
環境変数にこれを指定して、オリジナルのプログラムを実行してみると、
$ RUBY_GC_HEAP_INIT_SLOTS=12000000 RUBY_GC_HEAP_GROWTH_FACTOR=1.01 /usr/bin/time -f "\nCPU: %Us\tReal: %es\tRAM: %MKB" ./miniruby -I../../trunk/lib -I. -I.ext/common ../../trunk/test.rb CPU: 110.43s Real: 110.65s RAM: 670824KB
こうなりました。昨日の "RAM: 745388KB" よりマシになりましたね。でも、1度もヒープ拡張が起こらないくらい、初期値を与えているはずなので、12M 個 * 40 byte = 480 MB + 80 MB = 560 MB くらいで済むはずなので、ちょっと多いですね。GC で何が起きているでしょうか。
そこで登場するのが https://github.com/ko1/gc_tracer gem になります。
ファイルの先頭で、
require 'gc_tracer' GC::Tracer.start_logging
この2行を追加して下さい。標準エラー出力にこんなのが出てきます。
type tick count heap_allocated_pages heap_sorted_length heap_allocatable_pages heap_available_slots heap_live_slots heap_free_slots heap_final_slots heap_marked_slots heap_swept_slots heap_eden_pages heap_tomb_pages total_allocated_pages total_freed_pages total_allocated_objects total_freed_objects malloc_increase_bytes malloc_increase_bytes_limit minor_gc_count major_gc_count remembered_wb_unprotected_objects remembered_wb_unprotected_objects_limit old_objects old_objects_limit oldmalloc_increase_bytes oldmalloc_increase_bytes_limit major_by gc_by have_finalizer immediate_sweep state start 1424126502809096 1 29411 29411 0 11988251 11986265 1986 0 0 0 29411 0 29411 0 11988251 1986 0 33554432 0 0 0 0 0 0 0 16777216 0 newobj 0 0 none end_mark 1424126503057311 1 29411 29411 0 11988251 11986265 1986 0 10008677 0 29411 0 29411 0 11988251 1986 0 33554432 1 0 164 0 6099 0 0 16777216 0newobj 0 0 marking end_sweep 1424126503416026 1 29411 29411 2859 11988251 10415829 1572422 0 10008677 1979573 26552 2859 29411 0 12395402 1979573 0 33554432 1 0 164 0 6099 0 0 16777216 0newobj 0 0 sweeping start 1424126503416614 2 29411 29411 2859 11988251 10415829 1572422 0 10008677 1979573 26552 2859 29411 0 12395402 1979573 0 32883343 1 0 164 0 6099 0 0 16777216 oldgen newobj 0 0 none end_mark 1424126505920376 2 29412 29705 293 11988659 11988228 431 0 10011540 1979573 29412 0 29412 0 13967801 1979573 0 32883343 1 1 164 328 6099 12198 0 16777216 oldgen newobj 0 0 marking end_sweep 1424126509653076 2 29704 29705 1426 12107679 11526419 581260 0 10011540 2096662 28278 1426 29704 0 15482679 3956260 0 32883343 1 1 164 328 6099 12198 0 16777216 oldgen newobj 0 0 sweeping start 1424126510720439 3 29704 29705 0 12107679 12107679 0 0 10011540 2096662 29704 0 29704 0 16063939 3956260 0 32225676 1 1 164 328 6099 12198 0 16777216 0 newobj 0 0 none end_mark 1424126511016490 3 29705 30001 296 12108087 12107679 408 0 10008677 2096662 29705 0 29705 0 16063939 3956260 0 32225676 2 1 173 328 10008482 12198 0 16777216 0 newobj 0 0 marking end_sweep 1424126511495631 3 29705 30001 3035 12108087 10439327 1668760 0 10008677 2220177 26670 3035 29705 0 16494588 6055261 0 32225676 2 1 173 328 10008482 12198 0 16777216 0 newobj 0 0 sweeping start 1424126511496421 4 29705 30001 3035 12108087 10439327 1668760 0 10008677 2220177 26670 3035 29705 0 16494588 6055261 0 31581162 2 1 173 328 10008482 12198 0 16777216 oldgen newobj 0 0 none end_mark 1424126515062702 4 29706 30002 296 12108494 12108087 407 0 10011715 2220177 29706 0 29706 0 18163348 6055261 0 31581162 2 2 173 346 10008483 20016966 0 16777216 oldgen newobj 0 0 marking end_sweep 1424126517959578 4 30001 30002 1514 12228736 11611552 617184 0 10011715 2217546 28487 1514 30001 0 19763184 8151632 0 31581162 2 2 173 346 10008483 20016966 0 16777216 oldgen newobj 0 0 sweeping start 1424126518937223 5 30001 30002 0 12228736 12228736 0 0 10011715 2217546 30001 0 30001 0 20380368 8151632 0 30949538 2 2 173 346 10008483 20016966 0 16777216 0newobj 0 0 none end_mark 1424126518939379 5 30002 30301 299 12229144 12228736 408 0 10008677 2217546 30002 0 30002 0 20380368 8151632 0 30949538 3 2 173 346 10008483 20016966 0 16777216 0 newobj 0 0 marking end_sweep 1424126520330323 5 30002 30301 3714 12229144 10715191 1513953 0 10008677 2342458 26288 3714 30002 0 21086881 10371690 0 30949538 3 2 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126522730700 6 30002 30301 0 12229144 12229144 0 0 10008677 2342458 30002 0 30002 0 22600834 10371690 0 30330547 3 2 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126522733421 6 30003 30302 299 12229552 12229144 408 0 10008677 2342458 30003 0 30003 0 22600834 10371690 0 30330547 4 2 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126523700184 6 30003 30302 3715 12229552 10715222 1514330 0 10008677 2342866 26288 3715 30003 0 23307378 12592156 0 30330547 4 2 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126526054966 7 30003 30302 0 12229552 12229552 0 0 10008677 2342866 30003 0 30003 0 24821708 12592156 0 29723936 4 2 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126526057021 7 30004 30303 299 12229959 12229552 407 0 10008677 2342866 30004 0 30004 0 24821708 12592156 0 29723936 5 2 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126527206651 7 30004 30303 3715 12229959 10715610 1514349 0 10008677 2343273 26289 3715 30004 0 25528640 14813030 0 29723936 5 2 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126529599621 8 30004 30303 0 12229959 12229959 0 0 10008677 2343273 30004 0 30004 0 27042989 14813030 0 29129457 5 2 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126529601939 8 30004 30303 0 12229959 12229959 0 0 10008677 2343273 30004 0 30004 0 27042989 14813030 0 29129457 6 2 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126530234409 8 30004 30303 3213 12229959 10464694 1765265 0 10008677 2221281 26791 3213 30004 0 27499005 17034311 0 29129457 6 2 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126530235030 9 30004 30303 3213 12229959 10464768 1765191 0 10008677 2221281 26791 3213 30004 0 27499079 17034311 0 28546867 6 2 173 346 10008483 20016966 0 16777216 nofree newobj 0 0 none end_mark 1424126533329440 9 30005 30304 299 12230366 12229959 407 0 10011894 2221281 30005 0 30005 0 29264270 17034311 0 28546867 6 3 173 346 10008483 20016966 016777216 nofree newobj 0 0 marking end_sweep 1424126535800255 9 30303 30304 1604 12351831 11697946 653885 0 10011894 2340463 28699 1604 30303 0 30950321 19252375 0 28546867 6 3 173 346 10008483 20016966 016777216 nofree newobj 0 0 sweeping start 1424126536666685 10 30303 30304 0 12351831 12351831 0 0 10011894 2340463 30303 0 30303 0 31604206 19252375 0 27975929 6 3 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126536668752 10 30304 30606 302 12352239 12351831 408 0 10008677 2340463 30304 0 30304 0 31604206 19252375 0 27975929 7 3 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126537715101 10 30304 30606 3938 12352239 10746976 1605263 0 10008677 2466777 26366 3938 30304 0 32342504 21595528 0 27975929 7 3 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126539759913 11 30304 30606 0 12352239 12352239 0 0 10008677 2466777 30304 0 30304 0 33947767 21595528 0 27416410 7 3 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126539762060 11 30305 30607 302 12352646 12352239 407 0 10008677 2466777 30305 0 30305 0 33947767 21595528 0 27416410 8 3 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126540779275 11 30305 30607 3938 12352646 10747410 1605236 0 10008677 2467184 26367 3938 30305 0 34686499 23939089 0 27416410 8 3 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126542891783 12 30305 30607 0 12352646 12352646 0 0 10008677 2467184 30305 0 30305 0 36291735 23939089 0 26868081 8 3 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126542894134 12 30306 30608 302 12353054 12352646 408 0 10008677 2467184 30306 0 30306 0 36291735 23939089 0 26868081 9 3 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126543915024 12 30306 30608 3938 12353054 10747832 1605222 0 10008677 2467592 26368 3938 30306 0 37030889 26283057 0 26868081 9 3 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126545944224 13 30306 30608 0 12353054 12353054 0 0 10008677 2467592 30306 0 30306 0 38636111 26283057 0 26330719 9 3 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126545946459 13 30306 30608 0 12353054 12353054 0 0 10008677 2467592 30306 0 30306 0 38636111 26283057 0 26330719 10 3 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126546575020 13 30306 30608 3393 12353054 10489565 1863489 0 10008677 2344376 26913 3393 30306 0 39116998 28627433 0 26330719 10 3 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126546575643 14 30306 30608 3393 12353054 10489639 1863415 0 10008677 2344376 26913 3393 30306 0 39117072 28627433 0 25804104 10 3 173 346 10008483 20016966 0 16777216 nofree newobj 0 0 none end_mark 1424126549474776 14 30307 30609 302 12353462 12353054 408 0 10012072 2344376 30307 0 30307 0 40980487 28627433 0 25804104 10 4 173 346 10008483 20016966 016777216 nofree newobj 0 0 marking end_sweep 1424126551736504 14 30608 30609 1696 12476150 11784748 691402 0 10012072 2464605 28912 1696 30608 0 42753162 30968414 0 25804104 10 4 173 346 10008483 20016966 016777216 nofree newobj 0 0 sweeping start 1424126552572440 15 30608 30609 0 12476150 12476150 0 0 10012072 2464605 30608 0 30608 0 43444564 30968414 0 25288021 10 4 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126552574628 15 30609 30914 305 12476557 12476150 407 0 10008677 2464605 30609 0 30609 0 43444564 30968414 0 25288021 11 4 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126553574614 15 30609 30914 4163 12476557 10779627 1696930 0 10008677 2592319 26446 4163 30609 0 44215513 33435886 0 25288021 11 4 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126555693333 16 30609 30914 0 12476557 12476557 0 0 10008677 2592319 30609 0 30609 0 45912443 33435886 0 24782260 11 4 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126555695618 16 30610 30915 305 12476965 12476557 408 0 10008677 2592319 30610 0 30610 0 45912443 33435886 0 24782260 12 4 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126556637992 16 30610 30915 4164 12476965 10779632 1697333 0 10008677 2592727 26446 4164 30610 0 46683397 35903765 0 24782260 12 4 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126558691606 17 30610 30915 0 12476965 12476965 0 0 10008677 2592727 30610 0 30610 0 48380730 35903765 0 24286614 12 4 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126558693863 17 30611 30916 305 12477372 12476965 407 0 10008677 2592727 30611 0 30611 0 48380730 35903765 0 24286614 13 4 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126559661498 17 30611 30916 4165 12477372 10779603 1697769 0 10008677 2593134 26446 4165 30611 0 49151655 38372052 0 24286614 13 4 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126561720964 18 30611 30916 0 12477372 12477372 0 0 10008677 2593134 30611 0 30611 0 50849424 38372052 0 23800881 13 4 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126561723441 18 30611 30916 0 12477372 12477372 0 0 10008677 2593134 30611 0 30611 0 50849424 38372052 0 23800881 14 4 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126562369895 18 30611 30916 3576 12477372 10514399 1962973 0 10008677 2468694 27035 3576 30611 0 51355145 40840746 0 23800881 14 4 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126562370577 19 30611 30916 3576 12477372 10514473 1962899 0 10008677 2468694 27035 3576 30611 0 51355219 40840746 0 23324863 14 4 173 346 10008483 20016966 0 16777216 nofree newobj 0 0 none end_mark 1424126565561276 19 30612 30917 305 12477780 12477372 408 0 10012256 2468694 30612 0 30612 0 53318118 40840746 0 23324863 14 5 173 346 10008483 20016966 016777216 nofree newobj 0 0 marking end_sweep 1424126567940458 19 30916 30917 1787 12601690 11873250 728440 0 10012256 2589963 29129 1787 30916 0 55179111 43305861 0 23324863 14 5 173 346 10008483 20016966 016777216 nofree newobj 0 0 sweeping start 1424126568805749 20 30916 30917 0 12601690 12601690 0 0 10012256 2589963 30916 0 30916 0 55907551 43305861 0 22858365 14 5 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126568808097 20 30917 31225 308 12602098 12601690 408 0 10008677 2589963 30917 0 30917 0 55907551 43305861 0 22858365 15 5 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126569823157 20 30917 31225 4391 12602098 10812225 1789873 0 10008677 2719084 26526 4391 30917 0 56711098 45898873 0 22858365 15 5 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126571993522 21 30917 31225 0 12602098 12602098 0 0 10008677 2719084 30917 0 30917 0 58500971 45898873 0 22401197 15 5 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126571995939 21 30918 31226 308 12602506 12602098 408 0 10008677 2719084 30918 0 30918 0 58500971 45898873 0 22401197 16 5 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126572995120 21 30918 31226 4391 12602506 10812573 1789933 0 10008677 2719492 26527 4391 30918 0 59304866 48492293 0 22401197 16 5 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126575233588 22 30918 31226 0 12602506 12602506 0 0 10008677 2719492 30918 0 30918 0 61094799 48492293 0 21953173 16 5 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126575236602 22 30919 31227 308 12602913 12602506 407 0 10008677 2719492 30919 0 30919 0 61094799 48492293 0 21953173 17 5 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126576237601 22 30919 31227 4393 12602913 10812191 1790722 0 10008677 2719899 26526 4393 30919 0 61898312 51086121 0 21953173 17 5 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126578559341 23 30919 31227 0 12602913 12602913 0 0 10008677 2719899 30919 0 30919 0 63689034 51086121 0 21514109 17 5 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126578561550 23 30919 31227 0 12602913 12602913 0 0 10008677 2719899 30919 0 30919 0 63689034 51086121 0 21514109 18 5 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126579347093 23 30919 31227 3762 12602913 10539261 2063652 0 10008677 2594235 27157 3762 30919 0 64219617 53680356 0 21514109 18 5 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126579347996 24 30919 31227 3762 12602913 10539335 2063578 0 10008677 2594235 27157 3762 30919 0 64219691 53680356 0 21083826 18 5 173 346 10008483 20016966 0 16777216 nofree newobj 0 0 none end_mark 1424126582822956 24 30920 31228 308 12603320 12602913 407 0 10012442 2594235 30920 0 30920 0 66283269 53680356 0 21083826 18 6 173 346 10008483 20016966 016777216 nofree newobj 0 0 marking end_sweep 1424126585323074 24 31227 31228 1878 12728454 11962886 765568 0 10012442 2716541 29349 1878 31227 0 68233712 56270826 0 21083826 18 6 173 346 10008483 20016966 016777216 nofree newobj 0 0 sweeping start 1424126586349636 25 31227 31228 0 12728454 12728454 0 0 10012442 2716541 31227 0 31227 0 68999280 56270826 0 20662149 18 6 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126586351756 25 31228 31539 311 12728861 12728454 407 0 10008677 2716541 31228 0 31228 0 68999280 56270826 0 20662149 19 6 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126587374898 25 31228 31539 4621 12728861 10845248 1883613 0 10008677 2847071 26607 4621 31228 0 69835850 58990602 0 20662149 19 6 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126589528536 26 31228 31539 0 12728861 12728861 0 0 10008677 2847071 31228 0 31228 0 71719463 58990602 0 20248906 19 6 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126589530688 26 31229 31540 311 12729269 12728861 408 0 10008677 2847071 31229 0 31229 0 71719463 58990602 0 20248906 20 6 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126590517575 26 31229 31540 4622 12729269 10845240 1884029 0 10008677 2847479 26607 4622 31229 0 72556025 61710785 0 20248906 20 6 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126592712832 27 31229 31540 0 12729269 12729269 0 0 10008677 2847479 31229 0 31229 0 74440054 61710785 0 19843927 20 6 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126592715386 27 31230 31541 311 12729677 12729269 408 0 10008677 2847479 31230 0 31230 0 74440054 61710785 0 19843927 21 6 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126593675368 27 31230 31541 4623 12729677 10845232 1884445 0 10008677 2847887 26607 4623 31230 0 75276608 64431376 0 19843927 21 6 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126595912772 28 31230 31541 0 12729677 12729677 0 0 10008677 2847887 31230 0 31230 0 77161053 64431376 0 19447048 21 6 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126595915096 28 31230 31541 0 12729677 12729677 0 0 10008677 2847887 31230 0 31230 0 77161053 64431376 0 19447048 22 6 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126596550020 28 31230 31541 3948 12729677 10564079 2165598 0 10008677 2720999 27282 3948 31230 0 77716454 67152375 0 19447048 22 6 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126596550695 29 31230 31541 3948 12729677 10564079 2165598 0 10008677 2720999 27282 3948 31230 0 77716454 67152375 0 19058107 22 6 173 346 10008483 20016966 0 16777216 nofree newobj 0 0 none end_mark 1424126599572099 29 31231 31542 311 12730084 12729677 407 0 10012627 2720999 31231 0 31231 0 79882052 67152375 0 19058107 22 7 173 346 10008483 20016966 016777216 nofree newobj 0 0 marking end_sweep 1424126601548503 29 31541 31542 1973 12856442 12052174 804268 0 10012627 2844344 29568 1973 31541 0 81921598 69869424 0 19058107 22 7 173 346 10008483 20016966 016777216 nofree newobj 0 0 sweeping start 1424126602263195 30 31541 31542 0 12856442 12856442 0 0 10012627 2844344 31541 0 31541 0 82725866 69869424 0 18676944 22 7 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126602265341 30 31542 31856 314 12856849 12856442 407 0 10008677 2844344 31542 0 31542 0 82725866 69869424 0 18676944 23 7 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126603175460 30 31542 31856 4854 12856849 10878266 1978583 0 10008677 2976283 26688 4854 31542 0 83595454 72717188 0 18676944 23 7 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126605113748 31 31542 31856 0 12856849 12856849 0 0 10008677 2976283 31542 0 31542 0 85574037 72717188 0 18303405 23 7 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126605115927 31 31543 31857 314 12857257 12856849 408 0 10008677 2976283 31543 0 31543 0 85574037 72717188 0 18303405 24 7 173 346 10008483 20016966 016777216 0 newobj 0 0 marking end_sweep 1424126605955606 31 31543 31857 4855 12857257 10878238 1979019 0 10008677 2976691 26688 4855 31543 0 86443597 75565359 0 18303405 24 7 173 346 10008483 20016966 016777216 0 newobj 0 0 sweeping start 1424126607549599 32 31543 31857 0 12857257 12857257 0 0 10008677 2976691 31543 0 31543 0 88422616 75565359 0 17937336 24 7 173 346 10008483 20016966 0 16777216 0 newobj 0 0 none end_mark 1424126607551824 32 31544 31858 314 12857664 12857257 407 0 10008677 2976691 31544 0 31544 0 88422616 75565359 0 17937336 25 7 173 346 10008483 20016966 016777216 0 newobj 0 0 marking CPU: 114.08s Real: 114.44s RAM: 672072KB
沢山出てきてよくわからないかもしれません。tab separated な形式なので、Excel などに食わせるといいかもしれません。今回は、Google apps にシートを用意してみました。
https://docs.google.com/spreadsheets/d/1lVbgPWdumC19UMm-n_VxcsRUR9RR6G_E0gVTBxscvzs/edit?usp=sharing
最初のカラムだけ紹介すると、
という意味になります。type は
という意味になります。これらのタイミングごとに、GC の状態がどんなんであるか、ということを表示するんですね。ちなみに、他にもイベントがあって、それらを取ることもできます。
ここで注目したいのは、heap_marked_slots の欄です。これは、GC のために何個マークしましたか、ってことで、だいたい、生きているオブジェクトの数と考えて貰えると良いです。だいたい、10.01 M 個くらいで安定しています。つまり、生きているオブジェクトはだいたいこれくらいであるはずです。しかし、heap_available_slots 欄、つまり、用意しているスロット（オブジェクトの入れ物）の数はどんどん増えていきます。なぜでしょうか。
実は、Ruby のヒープは、ある一定量空いていないとヒープを拡張する、という戦略をとっています。一定量というのは、マーク終了時、マークされていない == 使えるスロット数が全体のスロット数（heap_available_slots）の割合が 0.3 より少ないと（0.7 より marked が多いと）、ヒープを拡張する、という戦略をとります。
マーク終了時の一例を取ってみると、
→ 10008677 / 11988251 = 0.83
なので、空き領域が少ない！ →ヒープを拡張しよう、となります。で、RUBY_GC_HEAP_GROWTH_FACTOR で指定した 1.01 倍拡張していきます。例えば、available slots が 11988659 から 12107679 に拡張されたところがありますが、1.009 倍、まぁだいたい 1.01 倍拡張されていることがわかります。
つまり、初期値は 1.3 倍の空きを用意してあげなければならないので、ちょっと多めに 1.4 倍にして、10.02 M 個 * 1.4 = 14.028 M 個最初にあれば、ヒープは拡張しないのではないでしょうか。では、やってみます。どうせヒープは増えないから、growth_factor は指定しない == 1.8 倍で増やす、としておきます。
RUBY_GC_HEAP_INIT_SLOTS=14028000 /usr/bin/time -f "\nCPU: %Us\tReal: %es\tRAM: %MKB" ruby ../../trunk/test.rb ... CPU: 115.00s Real: 115.36s RAM: 1126260KB
あれー、1GB 食ってますね。おかしいな。GC tracer の実行結果を sheet 「2回目」にはっておきました。確かに 3 回目の GC の時に available slots が増えてますね...。逆に言うと、2 回目に増やすっていう判断をしている気がしますね。あれー、なんでだろう？
heap_available_slots heap_live_slots heap_free_slots の並びが 2 回目の end_mark で "14014255 14013823 432" こうなっているのが怪しいですね。なんか数え間違えている気がするなあ。
計算間違えてた。available * 0.3 だけ、free が残っていないといけない、となると、available * 0.7 > marked とならなければならないので、available > marked/0.7 = marked * 1.43 とならなければならない。marked は 10.1M なので、available、つまり確保するべき数は 1.43 だとちょっと不安なので適当に 1.5 倍として 15.15 M 個用意しておけば、ヒープの拡張は起きないだろう。
やってみよう。
$ RUBY_GC_HEAP_INIT_SLOTS=15150000 /usr/bin/time -f "\nCPU: %Us\tReal: %es\tRAM: %MKB" ruby ../../trunk/test.rb... CPU: 132.72s Real: 133.03s RAM: 770084KB
細かい GC tracer の出力を見ると、heap slots の拡張はしていないことがわかりました。でも、メモリの消費量が多いですね。
15.15 M * 40 B + 80 MB = 686 MB で、まぁ、それに何か余計な 100MB がくっついているのかなぁ。そこはちょっと気になりますね。
さて、気になるので、きちんと深掘りしておきましょう。
valgrind というソフトウェアがあって、色々出来るのですが、色々できる中に、massif という、valgrind のインフラを使ってメモリ消費をキッチリかっちり調べる、というツールがあります。
なので、massif を使って、具体的にどこがメモリを食っているか調べてみましょう。
valgrind/massif を実行した結果に秘伝のスクリプトをかけると、こんな図が得られます（ちなみに、最近の ruby では valgrind が素直に動いてくれませんでした。ちょっと細工が必要）。
http://www.atdot.net/fp_store/f.h4owjn/file.copipa-temp-image.png
時系列で、どの関数がどの程度メモリを食っているのか示す図になっています。
見やすい図になっているので、大きいところを見てみると、
ことがわかります。time コマンド（のフォーマット M）が出す値は "M Maximum resident set size of the process during its lifetime, in Kilobytes." ということで、一番メモリくってるときの値なので、最大を見るのが適当でしょう。
ということで、600 MB + 80 MB + 80 MB = 760 MB と、だいたい実測値の値が出ました。
ruby_xrealloc2@gc.c の 80 MB は、まぁ当然 Array に割り当てられた 10M 要素の配列のサイズでしょう。
heap_assign_page@gc.c が 600 MB 食っているのは、だいたい 15M 個の RVALUE を用意しているからで、15M * 40 B = 600 MB ということで、検討通りです。
では、最後に残ったこの疑問「gc_mark@gc.c が最大 80 MB くらい、平均 50 MB くらい食ってる」というのは、一体何者でしょうか？
massif の出力を、秘伝のスクリプトをちょっと弄ってやると、こんな感じで行番号が得られます。
http://www.atdot.net/fp_store/f.foowjn/file.copipa-temp-image.png
この行を見てみると、stack_chunk_alloc() がメモリを食っていることがわかります。この関数は、GC のマークに必要となる、マークスタックを確保するための領域です。つまり、マークスタックが 50MB から最大 80MB 食っていた、ということなのですね。なかなか驚きの結果です。
さて、このマークスタックがどのように使われるか、ちょっと解説しておきます。
def mark_all
mark_stack = [root_set...]
while obj = mark_stack.pop
mark(obj)
obj.reachable_object{|refered_by_obj|
mark_stack.push refered_by_obj unless refered_by_obj.marked?
}
end
end
擬似コードで書くとこんな感じです。あるオブジェクトをマークするとき、そこから参照されているものをとりあえず mark スタックに突っ込んでおきます。で、mark_stack から取り出して、それをマークしていく、と。mark_stack が空になるまで続きます。
さて、今回の場合、10M 個の要素を持つ配列のマークが、必ず 1 回以上発生します（世代別の恩恵が得られるのは、何度か mark した後ですから）。このとき、10M 個の要素がマークスタックに一時的に突っ込まれるので、このときのマークスタックのサイズは 8B * 10M 個 = 80 MB となり、80 MB の追加の消費が必要になるわけですね。
というわけで、謎はすべて解けたのでした。
（いや、なんでこの 80MB は、50MB くらいに小さくなるとはいえ、残っているんだろう、という疑問はあるのだけれど）
shrink_stack_chunk_cache() の処理を見ると、あんまり積極的に掃除していなさそうなので、その辺かなぁ、などと。もうちょっと、どーっと解放してあげると良いんじゃないかと思う。
というわけで、Ruby ではメモリ解析のためのインフラがない、って声をよく聞くので、頑張ればここまで出来るんだよ、というデモンストレーションでした。
というわけで、これくらいは頑張って下さい。
いや、専門知識などが多少要るので、そんな頑張れないかもしれませんが、その時はお問い合わせ頂ければ、なんらかのアドバイスなど出来るかもしれません。
とりあえず、メモリ関係で文句言うときは、ぜひ gc_tracer のログを一緒に持ってきて下さい、少なくとも。
Ruby の高速化の道。
ボスから、 http://kokizzu.blogspot.jp/2015/02/c-java-hhvm-ruby-nodejsrhinojscspidermo.html をぱっと見せられて、「メモリを減らしたい」と言われる。いわゆる業務命令というやつだ。
今回考えるプログラムをこのページから引用する。
##############################
# scomb.rb
def newGap gap
gap /= 1.3;
gap = gap.to_i;
return 11 if gap == 9 or gap == 10
return 1 if gap < 1
gap
end
def combSort a
len = a.length
gap = len
swapped = false
begin
swapped = false
gap = newGap gap
(0...(len-gap)).each do |i|
if a[i] > a[i+gap]
swapped = true
a[i], a[i+gap] = a[i+gap], a[i]
end
end
end while gap > 1 or swapped
end
N = 10000000;
arr = N.times.map{|x| (N-x).to_s }
combSort arr
(1...N).each{ |z| print '!' if arr[z]<arr[z-1] }
比較的簡単だ。実行結果も引用する。
$ ruby --version ruby 2.2.0p0 (2014-12-25 revision 49005) [x86_64-linux] $ time ruby scomb.rb CPU: 114.67s Real: 115.21s RAM: 870612KB
これを、手元の環境でも同じように測ってみる（手元では trunk が動いている。ちなみに、Windows 上の VirtualBox 上の Ubuntu）。
CPU: 108.87s Real: 109.11s RAM: 860996KB
まぁ、ほぼ同じようなものだ。
さて、現状認識から始めよう。
まず、最後の行のほうで、10000000 = 10_000_000 = 10M 個の配列を作っている。64bit CPU 上で動いているので、必要なメモリ量を試算すると、
併せて、だいたい 500MB が必要なところだろう。あと、Ruby の GC の戦略は、10M 個確保されていたら、1.8 倍くらいは作れるようになっているので、10 M * 1.8 = 18 M 個の RVALUE が用意されていると思う。なんで、8M 個の RVALUE = 8M * 40B = 320 MB くらい、余分に確保されて、これらを足し合わせると、400 MB + 80 MB + 320 MB = 800 MB ということで、RAM: 860996KB ってのは、まぁまぁ納得いく数であろう。
さて、GC チューニングでなんとかなるだろうか。まず、1.8 倍確保するからしんどいのであって、これを 1.2 倍くらいにおさえるとどうだろう。RUBY_GC_HEAP_GROWTH_FACTOR では、メモリが足りない時、1.8 倍じゃなくて、別の倍率にするための仕組みなので、これを 1.2 倍程度にしてみるとどうだろうか。
$ RUBY_GC_HEAP_GROWTH_FACTOR=1.2 /usr/bin/time -f "\nCPU: %Us\tReal: %es\tRAM: %MKB" ./miniruby -I../../trunk/lib -I. -I.ext/common ../../trunk/test.rb CPU: 108.32s Real: 108.49s RAM: 745388KB
しめしめ。メモリ消費が減った。でも、あんまり減ってないですね。
そもそも、このプログラムでどこがメモリを食うのだろう？ combSort(arr) の中を見ても、とくにメモリを食いそうなところは無いんですよね。試しに、combSort(arr) を呼ばずに実行するとどうなるか見てみよう。
CPU: 3.09s Real: 3.16s RAM: 527452KB
さっき計算した、500MB というのが出てきた。ということは、やはり combSort(arr) の中でメモリを消費しているらしい。でも、どこでオブジェクトを作っているんだろう？
というときに、https://github.com/ko1/allocation_tracer gem を使う。
##############################
# scomb.rb
def newGap gap
gap /= 1.3;
gap = gap.to_i;
return 11 if gap == 9 or gap == 10
return 1 if gap < 1
gap
end
def combSort a
len = a.length
gap = len
swapped = false
begin
swapped = false
gap = newGap gap
(0...(len-gap)).each do |i|
if a[i] > a[i+gap]
swapped = true
a[i], a[i+gap] = a[i+gap], a[i]
end
end
end while gap > 1 or swapped
end
require 'allocation_tracer'
require 'pp'
pp ObjectSpace::AllocationTracer.trace{
N = 1000#0000;
arr = N.times.map{|x| (N-x).to_s }
combSort arr
(1...N).each{ |z| print '!' if arr[z]<arr[z-1] }
}
こんな感じで使う。ObjectSpace::AllocationTracer.trace で囲っただけ。ちなみに、傾向を見たいだけだから、10M 個じゃなくて 1K 個にしておく。そうすると、
{["../../trunk/test.rb", 31]=>[1004, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 17]=>[24, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 20]=>[2546, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 33]=>[1, 0, 0, 0, 0, 0]}
こんな結果が得られる。
これは、["../../trunk/test.rb", 31] という場所で、[1004, 0, 0, 0, 0, 0] こんな結果が出た、という意味だけど、ちょっと細かい情報が多くてわかりづらいと思う。
ということを意味しているんだけど、まぁ最初のカラム（生成数）だけ見ていればいいと思う。
31 行目は配列を map で作っているから 1004 個のオブジェクトが出来ているけれど、次に多いのが 20 行目の 2546 個生成されたオブジェクト。具体的には "a[i], a[i+gap] = a[i+gap], a[i]" これ。一体何が出来ているのか？
より詳しく知るためには、こんな風に使う。
ObjectSpace::AllocationTracer.setup(%i{path line type})
pp ObjectSpace::AllocationTracer.trace{
...
}
これで、type ごとに統計を取るようになる。結果は、こんなふうになった。
{["../../trunk/test.rb", 31, :T_DATA]=>[1, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 31, :T_ARRAY]=>[1, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 31, :T_NODE]=>[2, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 31, :T_STRING]=>[1000, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 17, :T_STRUCT]=>[24, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 20, :T_ARRAY]=>[2546, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 33, :T_STRUCT]=>[1, 0, 0, 0, 0, 0]}
20行目は T_ARRAY、つまり配列がガンガン出来ている、ということがわかる。はて、なんで配列？
実は、Ruby の多重代入は、配列を返す。何を言っているのかわからないのと思うので、具体例を出す。
x = (a, b = 1, 2) p x #=> [1, 2]
x は、(a, b = 1, 2) という式の値を参照している。allocation_tracer を使ってみれば、明らかだ。
require 'allocation_tracer'
require 'pp'
ObjectSpace::AllocationTracer.setup(%i{path line type})
pp ObjectSpace::AllocationTracer.trace{
a, b = 1, 2
}
これを実行すると：
{["../../trunk/test.rb", 5, :T_ARRAY]=>[1, 0, 0, 0, 0, 0]}
こうじゃ。5行目、つまり "a, b = 1, 2" で T_ARRAY のオブジェクトが 1 つ生成されていることがわかる。
この生成された [1, 2] というオブジェクトなんてつかわねーよ！ と思うかもしれないし、過去の私もそう思ったので、使わないことが明らかな場合、つまり、この値を捨てていることが明らかであるとき、配列を生成しないようにしている。
require 'allocation_tracer'
require 'pp'
ObjectSpace::AllocationTracer.setup(%i{path line type})
pp ObjectSpace::AllocationTracer.trace{
a, b = 1, 2
nil
}
の結果は、
{}
つまり、何のオブジェクトも生成されていないことがわかる。
以前のプログラムでは、多重代入の値が、それをくるむブロックの値として返されており、そこで必要かもしれないから、丁寧に配列を返す。しかし、nil を返すことを明示することで、配列を生成しないようになったということである。
よしわかった、nil を入れればいいんだな、ということで、入れてみたら
##############################
# scomb.rb
def newGap gap
gap /= 1.3;
gap = gap.to_i;
return 11 if gap == 9 or gap == 10
return 1 if gap < 1
gap
end
def combSort a
len = a.length
gap = len
swapped = false
begin
swapped = false
gap = newGap gap
(0...(len-gap)).each do |i|
if a[i] > a[i+gap]
swapped = true
a[i], a[i+gap] = a[i+gap], a[i]
nil # ここに nil を入れてみた
end
end
end while gap > 1 or swapped
end
require 'allocation_tracer'
require 'pp'
ObjectSpace::AllocationTracer.setup(%i{path line type})
pp ObjectSpace::AllocationTracer.trace{
N = 1000#0000;
arr = N.times.map{|x| (N-x).to_s }
combSort arr
(1...N).each{ |z| print '!' if arr[z]<arr[z-1] }
}
しかしやっぱり
{["../../trunk/test.rb", 32, :T_DATA]=>[1, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 32, :T_ARRAY]=>[1, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 32, :T_NODE]=>[2, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 32, :T_STRING]=>[1000, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 17, :T_STRUCT]=>[24, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 20, :T_ARRAY]=>[2546, 0, 0, 0, 0, 0], <-- これ
["../../trunk/test.rb", 34, :T_STRUCT]=>[1, 0, 0, 0, 0, 0]}
配列は生成される。はてな？
実は、a[x], a[y] = 1, 2 のような（左辺値にメソッド呼び出しなんかがある）多重代入では、真面目に配列を作っている。というのも、副作用の恐れがあるため、実行順序を適切に並べるため、具体的にはこの例だと、a[x] = 1, a[y] = 2 と順番に実行するためである。
逆に、そうじゃなくても良い場合を考える。
a, b = 1, 2
このとき、Rubyのスタックマシンの VM はこんなふうに実行する。
push 1 push 2 set b # スタックトップの 2 を pop して b にセット set a # スタックトップの 1 を pop して a にセット
このとき、設定順は b, a の順である。しかし、a[x], a[y] には副作用がある可能性がある。例えば、設定されたときにログを出力するかもしれない。なのでさっきと同じように、
push 1 push 2 set a[y] set a[x]
とすることはできない。なので、どうしているかというと、1度配列を作って、
push 1 push 2 newarray 2 # [1, 2] を作る expandarray 2 # スタックに配列を逆順に展開 2, 1 と置かれる set a[x] # a[x] = 1 をする set a[y] # a[y] = 2 をする
というふうに実装されている、というわけである。
さて、ここまでわかると、多重代入を使うからダメ、ってことがわかるので、これを分解してみる。
##############################
# scomb.rb
def newGap gap
gap /= 1.3;
gap = gap.to_i;
return 11 if gap == 9 or gap == 10
return 1 if gap < 1
gap
end
def combSort a
len = a.length
gap = len
swapped = false
begin
swapped = false
gap = newGap gap
(0...(len-gap)).each do |i|
if a[i] > a[i+gap]
swapped = true
x, y = a[i+gap], a[i] # ここをかっこ悪く変更した
a[i] = x
a[i+gap] = y
nil
end
end
end while gap > 1 or swapped
end
require 'allocation_tracer'
require 'pp'
ObjectSpace::AllocationTracer.setup(%i{path line type})
pp ObjectSpace::AllocationTracer.trace{
N = 1000#0000;
arr = N.times.map{|x| (N-x).to_s }
combSort arr
(1...N).each{ |z| print '!' if arr[z]<arr[z-1] }
}
が、
{["../../trunk/test.rb", 34, :T_DATA]=>[1, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 34, :T_ARRAY]=>[1, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 34, :T_NODE]=>[2, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 34, :T_STRING]=>[1000, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 17, :T_STRUCT]=>[24, 0, 0, 0, 0, 0],
["../../trunk/test.rb", 36, :T_STRUCT]=>[1, 0, 0, 0, 0, 0]}
こうなって、見事に配列が無くなったことがわかる。
さて、ではこれを、元々のお題である 10M 個で実行してみる。
$ /usr/bin/time -f "\nCPU: %Us\tReal: %es\tRAM: %MKB" ./miniruby -I../../trunk/lib -I. -I.ext/common ../../trunk/test.rb CPU: 102.89s Real: 103.14s RAM: 527712KB
見事、理想的なメモリ使用量になったのでした。
（続くかもしれない）
cool ^_^