プロファイル

rubyプログラム中でrequire 'profile'と書くだけでプログラム実行に対するプロファイリング結果が標準出力に表示されます。

5月29日の「テストデータ作成」で書いた記事の改良版の方がなんとなく早そうな気はしてたんですが、実際のところどうなんやろ、と思って計ってみました。

  10240.times{ f << "a" }

とした方（1024*1024*10は遅すぎたので10KBのファイル出力にした）の結果は、

  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
 44.70     0.59      0.59        1   594.00  1329.00  Integer#times
 38.83     1.11      0.52    10240     0.05     0.07  IO#<<
 16.48     1.33      0.22    10240     0.02     0.02  IO#write
  0.00     1.33      0.00        1     0.00  1329.00  IO#open
  0.00     1.33      0.00        1     0.00     0.00  IO#close
  0.00     1.33      0.00        1     0.00     0.00  File#initialize
  0.00     1.33      0.00        1     0.00  1329.00  #toplevel

となり、確かに<<メソッドが10240回呼ばれているのが分かります。1秒33かかってますねー。
一方、

  f << "a" * 10240

とした方の結果は、

  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
  0.00     0.00      0.00        1     0.00     0.00  String#*
  0.00     0.00      0.00        1     0.00     0.00  File#initialize
  0.00     0.00      0.00        1     0.00     0.00  IO#close
  0.00     0.00      0.00        1     0.00     0.00  IO#open
  0.00     0.00      0.00        1     0.00     0.00  IO#<<
  0.00     0.00      0.00        1     0.00     0.00  IO#write
  0.00     0.01      0.00        1     0.00    10.00  #toplevel

となりました。やっぱこっちの方が断然早いですね。