Hatena::ブログ(Diary)

Lazy Technology

2007-05-02

[][]ar_fixturesが遅い

ユニットテストがしたくなったのでとりあえずar_fixturesとyaml_wamlをインストールして動かしてみて10分ほど放置。だがまったく終わらない。

インタラプトしてカウンタを仕込んで目検してみるに、どうも秒間5〜6件程度しか処理できていない気がする。

対象テーブルのテストデータは2万件…そりゃ終わるわけないだろ。。。常識的に考えて。。。

とりあえずの対処法

そもそもテストデータ二万件もいらねーだろ、って事でまず第一の対処法は、作成するテストデータの数を制限する事。

ruby script/runner "Model.to_fixture(5)"

こんな感じにto_fixtureメソッドに引数を付けると件数を制限することができる。


でもなんか気になるので

どこの処理が重たいのかを調べるためにプロファイラ初体験。

>ruby -r profile script/runner "Model.to_fixture(500)"
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
  5.98     7.10      7.10      475    14.94    27.76  String#gsub
  5.96    14.18      7.08    11014     0.64    11.87  Proc#call
  5.90    21.18      7.01     8500     0.82     1.35  String#taguri
  4.89    26.98      5.80    11001     0.53    12.58  YAML.quick_emit
  2.84    30.35      3.36     2460     1.37    29.03  Array#each
  2.64    33.47      3.13     5184     0.60     1.15  Mysql#get_length
  2.38    36.30      2.82    10500     0.27     0.45  YAML::Syck::Scalar#initialize
  2.21    38.92      2.62      646     4.06   340.34  Kernel.gem_original_require
  2.15    41.46      2.55     8500     0.30     4.44  String#to_yaml_without_decode
  2.14    44.00      2.54    17500     0.14     0.24  Object#to_yaml_properties
  2.01    46.39      2.39    35465     0.07     0.08  Array#pack
  1.89    48.63      2.24    25246     0.09     0.11  Kernel.===
  1.86    50.83      2.20     8500     0.26     4.77  String#to_yaml
  1.85    53.02      2.19     8500     0.26     0.58  String#is_complex_yaml?
  1.74    55.09      2.06     5011     0.41     1.08  ActiveRecord::ConnectionAdapters::Column#type_cast
  1.62    57.01      1.92     6115     0.31     0.41  Object#method_added
  1.60    58.91      1.90     5001     0.38     2.60  ActiveRecord::Base#read_attribute
  1.60    60.80      1.89    27566     0.07     0.07  Kernel.class
  1.58    62.68      1.88    11001     0.17    12.04  YAML::Syck::Emitter#emit

トップのgsubメソッドはyaml_wamlプラグインでやってるマルチバイト対応処理っぽい。

yaml_wamlではすべてのクラスのto_yamlメソッドを置き換えていて、オリジナルのto_yamlメソッドはAliasでto_yaml_without_decodeメソッドに置き換えられている。


とりあえずyaml_wamlプラグインをはずして再度プロファイル。

  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
  6.46     6.67      6.67    11014     0.61    12.32  Proc#call
  6.09    12.95      6.29     8263     0.76     1.16  String#taguri
  4.77    17.88      4.93    11001     0.45    12.88  YAML.quick_emit
  4.06    22.07      4.19     8500     0.49     0.86  String#is_binary_data?
  3.66    25.84      3.77    17263     0.22     0.31  Object#to_yaml_properties
  3.31    29.25      3.41     2456     1.39    28.61  Array#each
  3.07    32.42      3.16     5184     0.61     1.20  Mysql#get_length
  2.52    35.01      2.60     5001     0.52     2.70  ActiveRecord::Base#read_attribute
  2.44    37.53      2.51      644     3.90   311.50  Kernel.gem_original_require
  2.16    39.76      2.23     8500     0.26     5.06  String#to_yaml
  2.13    41.96      2.20    10500     0.21     0.43  YAML::Syck::Scalar#initialize
  2.06    44.08      2.12     5011     0.42     1.02  ActiveRecord::ConnectionAdapters::Column#type_cast

予想通りString#gsubはなくなったものの、突出して処理時間を食っているメソッドがあるわけではないようだ。

でも肝心のto_yamlメソッドの処理時間は全体のたった2%。うーむ…。

呼び出し元クラスが分かればまた違った結果が見えてくるのかもしれないが…。

スキル不足のようなのでレベルが上がったら再チャレンジしたいところ。