[Namazu-devel-ja 1564] Re: hash の負荷軽減

Tadamasa Teranishi yw3t-trns @ asahi-net.or.jp
2007年 4月 15日 (日) 12:39:04 JST


寺西です。

様々な条件のもと、次のマシンで約1万の文書のインデックス作成時間を
測定しました。

1) 測定マシン

# cat /proc/cpuinfo
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 6
model           : 8
model name      : Pentium III (Coppermine)
stepping        : 1
cpu MHz         : 601.371
cache size      : 256 KB
fdiv_bug        : no
hlt_bug         : no
f00f_bug        : no
coma_bug        : no
fpu             : yes
fpu_exception   : yes
cpuid level     : 2
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 sep mtrr pge mca
cmov pat pse36 mmx fxsr sse
bogomips        : 1199.30


Windows 98 世代の古いパソコンです。おそらく皆さんの環境よりは性能が
低いものと思います。


2) 測定データ
 http://www.namazu.org/ml.html#archive の以下のファイル

  namazu-devel-ja       4,136通
  namazu-users-ja       3,881通
  namazu-win32-users-ja 2,242通
  -----------------------------
                 合計  10,259

 メディアタイプは message/rfc822


3) 測定条件

 a) $ON_MEMORY_SIZE を標準(5000000), 10倍, 1/10, 1/100 のそれぞれ
 b) Namazu 2.0.17, 修正(D), 修正(E) のそれぞれ


4) 修正内容

 修正(SD) は前回のもの

 修正(SE) はインデックスの書き出し回数が増えると、
 mknmz::get_last_docid に時間がかかるため、修正(D)に加えて
 %PhraseHashLast, %KeyIndexLast をインデックスの書き出しの度に
 クリアしないように修正したもの

 デメリットとして、
  単語数 x ハッシュに必要なメモリ + 65536 x ハッシュに必要なメモリ
 分のメモリを更に余分に必要とします。ただし、全体の消費メモリから
 考えれば増加量はそれほど多くはないものと思います。


5) 結果

$ON_MEMORY_MAX|インデックス|   SA     SD     SE
              |書き出し回数|
--------------+------------+---------------------
     50000000 |          1 | 0.825  0.678  0.700
      5000000 |          7 | 1.000  0.815  0.761
       500000 |         65 | 1.971  1.840  1.388
        50000 |        613 | 9.357  9.355  7.500


※ $ON_MEMORY_MAX がデフォルトで、Namazu 2.0.17(SA)の時を 1.00 として
   比較したもの


6) 考察

 テストに用いた1万件の文書は約30MBです。
 このため、$ON_MEMORY_MAX の標準値では7回インデックスの書き出し
 を行います。
 $ON_MEMORY_MAX の値を10倍するとインデックスの書き出し回数は1回に
 1/10 にすると65回に、1/100にすると613回となりました。
 ($ON_MEMORY_MAX と インデックス書き出し回数は反比例)

 Namazu 2.0.17 では、インデックスの書き出し回数を1回にすると、
 17.5% 高速化しました。また、インデックスの書き出し回数を613回に
 すると、9.357倍も処理に時間がかかりました。
 インデックスの書き出し回数が多くなると、非常に効率が悪いことが
 わかります。

 SD, SE の場合、インデックスの書き出し回数を1回にすると、SA より
 30%ほど高速化しています。(SD, SE に差がありますが、これは誤差の
 範囲でしょう。)
 インデックスの書き出し回数を613回にすると、SD ではほぼ修正した
 効果が薄れて SA と同じとなっています。それに対して SE では
 約20%高速化しています。

 以上のことから SE の修正は有効なものだと思われます。

 老朽化したマシンでも、SE でインデックス書き出し1回の場合、1万件の
 ファイルから約9分40秒でインデックスを作成することができるという
 ことでした。(約17.2ファイル/秒)

 ※HTML,PDF,Word,Excel,PowerPoint,一太郎 等はテキスト抽出のため
   の処理が必要です。この処理は非常に重いので今回のテスト結果
   ほどの性能はでないものと思います。


7) 測定データ

[SA1] 修正前 インデックス書き出し7回

Total Elapsed Time = 1058.866 Seconds
  User+System Time = 830.9160 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 16.0   133.4 129.00 178427   0.0001 0.0001  mknmz::hash
 12.4   103.8 103.67  61557   0.0017 0.0017  mknmz::wordcount_sub
 8.36   69.45 196.82  10259   0.0068 0.0192  mknmz::make_phrase_hash
 6.25   51.92 212.47  10259   0.0051 0.0207  mknmz::count_words
 6.16   51.19 50.270 376036   0.0001 0.0001  mknmz::get_last_docid
 5.42   45.06 94.418      7   6.4378 13.488  mknmz::write_index_sub
 4.10   34.05 33.294 306552   0.0001 0.0001  Text::Kakasi::xs_do_kakasi
 3.39   28.17 99.581  10259   0.0027 0.0097  mknmz::put_field_index
 3.31   27.49 27.474  10262   0.0027 0.0027 
File::MMagic::checktype_data
 2.99   24.87 22.072 112310   0.0000 0.0000  mknmz::readw
 2.87   23.83 61.592      7   3.4052 8.7988 
mknmz::write_phrase_hash_sub
 2.68   22.22 22.307  10259   0.0022 0.0022 
mailnews::mailnews_citation_filter
 2.41   20.00 19.317 277209   0.0001 0.0001  IO::File::open
 2.31   19.20 20.137  10259   0.0019 0.0020  mailnews::mailnews_filter
 2.16   17.96 17.918  20900   0.0009 0.0009  NKF::nkf


[SA2] 修正前 インデックス書き出し1回

Total Elapsed Time = 1716.776 Seconds
  User+System Time = 685.7960 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 19.2   132.0 127.57 178427   0.0001 0.0001  mknmz::hash
 14.7   101.1 101.03  61557   0.0016 0.0016  mknmz::wordcount_sub
 9.96   68.27 194.19  10259   0.0067 0.0189  mknmz::make_phrase_hash
 7.88   54.01 210.61  10259   0.0053 0.0205  mknmz::count_words
 4.84   33.17 32.414 306552   0.0001 0.0001  Text::Kakasi::xs_do_kakasi
 3.98   27.29 99.351  10259   0.0027 0.0097  mknmz::put_field_index
 3.96   27.13 27.114  10262   0.0026 0.0026 
File::MMagic::checktype_data
 3.00   20.57 20.686  10259   0.0020 0.0020 
mailnews::mailnews_citation_filter
 2.82   19.34 18.657 277149   0.0001 0.0001  IO::File::open
 2.75   18.85 18.808  20900   0.0009 0.0009  NKF::nkf
 2.72   18.64 19.707  10259   0.0018 0.0019  mailnews::mailnews_filter
 2.52   17.25 17.234  10259   0.0017 0.0017  mailnews::uuencode_filter
 2.34   16.04 15.999  20518   0.0008 0.0008  gfilter::line_adjust_filter
 1.95   13.38 13.364  10262   0.0013 0.0013 
File::MMagic::checktype_byfilename
 1.95   13.36 12.677 277136   0.0000 0.0000  IO::Handle::close


[SA3] 修正前 インデックス書き出し65回

Total Elapsed Time = 1704.496 Seconds
  User+System Time = 1638.016 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 19.9   327.3 688.06     65   5.0369 10.585  mknmz::write_index_sub
 17.7   290.8 288.45 999352   0.0003 0.0003  mknmz::get_last_docid
 14.8   243.5 215.34 113108   0.0000 0.0000  mknmz::readw
 10.6   174.1 348.62     65   2.6793 5.3634 
mknmz::write_phrase_hash_sub
 7.98   130.6 126.25 178427   0.0001 0.0001  mknmz::hash
 6.14   100.5 100.39  61557   0.0016 0.0016  mknmz::wordcount_sub
 4.25   69.57 194.20  10259   0.0068 0.0189  mknmz::make_phrase_hash
 2.99   48.97 205.30  10259   0.0048 0.0200  mknmz::count_words
 2.05   33.50 32.744 306552   0.0001 0.0001  Text::Kakasi::xs_do_kakasi
 2.04   33.43 30.941 999352   0.0000 0.0000  mknmz::adjust_first_docid
 1.67   27.40 27.384  10262   0.0027 0.0027 
File::MMagic::checktype_data
 1.65   27.09 97.121  10259   0.0026 0.0095  mknmz::put_field_index
 1.32   21.61 21.617  10259   0.0021 0.0021 
mailnews::mailnews_citation_filter
 1.16   18.97 18.928  20900   0.0009 0.0009  NKF::nkf
 1.11   18.12 19.047  10259   0.0018 0.0019  mailnews::mailnews_filter


[SA4] 修正前 インデックス書き出し613回

Total Elapsed Time = 7944.362 Seconds
  User+System Time = 7774.672 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 37.0   2880. 5386.3    613   4.6992 8.7868  mknmz::write_index_sub
 29.1   2266. 1946.6 106746   0.0000 0.0000  mknmz::readw
 19.0   1483. 2385.5    613   2.4202 3.8916 
mknmz::write_phrase_hash_sub
 18.0   1403. 1398.3 167220   0.0008 0.0008  mknmz::get_last_docid
 1.68   130.2 124.97 178427   0.0001 0.0001  mknmz::hash
 1.31   101.7 101.60  61557   0.0017 0.0017  mknmz::wordcount_sub
 0.90   70.12 193.14  10259   0.0068 0.0188  mknmz::make_phrase_hash
 0.83   64.31 59.313 167220   0.0000 0.0000  mknmz::adjust_first_docid
 0.64   49.66 206.38  10259   0.0048 0.0201  mknmz::count_words
 0.44   34.23 33.320 306552   0.0001 0.0001  Text::Kakasi::xs_do_kakasi
 0.37   28.78 28.759  10262   0.0028 0.0028 
File::MMagic::checktype_data
 0.35   26.84 96.610  10259   0.0026 0.0094  mknmz::put_field_index
 0.27   21.21 21.320  10259   0.0021 0.0021 
mailnews::mailnews_citation_filter
 0.27   20.95 20.110 283269   0.0001 0.0001  IO::File::open
 0.24   18.37 18.317  20900   0.0009 0.0009  NKF::nkf


[SD1] 修正後 インデックス書き出し7回

Total Elapsed Time = 1232.204 Seconds
  User+System Time = 677.2240 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 10.4   70.97 107.75  10259   0.0069 0.0105  mknmz::make_phrase_hash
 9.68   65.56 65.395  61557   0.0011 0.0011  mknmz::wordcount_sub
 7.39   50.04 171.42  10259   0.0049 0.0167  mknmz::count_words
 7.24   49.02 47.912 376036   0.0001 0.0001  mknmz::get_last_docid
 6.50   44.03 38.509 184686   0.0000 0.0000  mknmz::hash
 6.46   43.73 91.111      7   6.2473 13.015  mknmz::write_index_sub
 5.01   33.91 33.000 306552   0.0001 0.0001  Text::Kakasi::xs_do_kakasi
 4.22   28.61 28.599  10262   0.0028 0.0028 
File::MMagic::checktype_data
 4.08   27.64 94.830  10259   0.0027 0.0092  mknmz::put_field_index
 3.66   24.75 21.390 112310   0.0000 0.0000  mknmz::readw
 3.41   23.06 59.742      7   3.2945 8.5346 
mknmz::write_phrase_hash_sub
 3.24   21.91 21.990  10259   0.0021 0.0021 
mailnews::mailnews_citation_filter
 2.78   18.79 17.968 277209   0.0001 0.0001  IO::File::open
 2.65   17.92 18.806  10259   0.0017 0.0018  mailnews::mailnews_filter
 2.63   17.80 17.747  20900   0.0009 0.0008  NKF::nkf


[SD2] 修正後 インデックス書き出し1回

Total Elapsed Time = 1867.030 Seconds
  User+System Time = 563.6400 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 12.4   70.31 109.16  10259   0.0069 0.0106  mknmz::make_phrase_hash
 11.6   65.43 65.296  61557   0.0011 0.0011  mknmz::wordcount_sub
 9.55   53.84 174.99  10259   0.0052 0.0171  mknmz::count_words
 7.97   44.89 40.292 184686   0.0000 0.0000  mknmz::hash
 6.09   34.33 33.574 306552   0.0001 0.0001  Text::Kakasi::xs_do_kakasi
 5.09   28.69 28.674  10262   0.0028 0.0028 
File::MMagic::checktype_data
 4.70   26.46 98.071  10259   0.0026 0.0096  mknmz::put_field_index
 3.84   21.61 21.666  10259   0.0021 0.0021 
mailnews::mailnews_citation_filter
 3.30   18.58 18.538  20900   0.0009 0.0009  NKF::nkf
 3.29   18.52 17.837 277149   0.0001 0.0001  IO::File::open
 3.21   18.09 19.027  10259   0.0018 0.0019  mailnews::mailnews_filter
 2.88   16.24 16.224  10259   0.0016 0.0016  mailnews::uuencode_filter
 2.84   15.98 15.939  20518   0.0008 0.0008  gfilter::line_adjust_filter
 2.56   14.41 14.394  10262   0.0014 0.0014 
File::MMagic::checktype_byfilename
 2.26   12.73 12.047 277136   0.0000 0.0000  IO::Handle::close


[SD3] 修正後 インデックス書き出し65回

Total Elapsed Time = 2385.560 Seconds
  User+System Time = 1528.630 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 21.6   330.2 691.89     65   5.0801 10.644  mknmz::write_index_sub
 19.0   291.6 289.21 999352   0.0003 0.0003  mknmz::get_last_docid
 16.0   245.2 217.07 113108   0.0000 0.0000  mknmz::readw
 11.5   176.8 352.30     65   2.7202 5.4201 
mknmz::write_phrase_hash_sub
 4.88   74.59 113.19  10259   0.0073 0.0110  mknmz::make_phrase_hash
 4.26   65.19 65.056  61557   0.0011 0.0011  mknmz::wordcount_sub
 3.22   49.21 171.79  10259   0.0048 0.0167  mknmz::count_words
 2.91   44.55 39.952 184686   0.0000 0.0000  mknmz::hash
 2.27   34.71 33.954 306552   0.0001 0.0001  Text::Kakasi::xs_do_kakasi
 2.15   32.92 30.431 999352   0.0000 0.0000  mknmz::adjust_first_docid
 1.77   27.08 98.101  10259   0.0026 0.0096  mknmz::put_field_index
 1.73   26.44 26.424  10262   0.0026 0.0026 
File::MMagic::checktype_data
 1.61   24.56 24.646  10259   0.0024 0.0024 
mailnews::mailnews_citation_filter
 1.25   19.05 20.067  10259   0.0019 0.0020  mailnews::mailnews_filter
 1.18   18.08 17.395 277789   0.0001 0.0001  IO::File::open


[SD4] 修正後 インデックス書き出し613回

Total Elapsed Time = 8015.131 Seconds
  User+System Time = 7773.371 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 37.1   2887. 5488.6    613   4.7111 8.9538  mknmz::write_index_sub
 29.4   2290. 1971.3 106746   0.0000 0.0000  mknmz::readw
 19.2   1496. 2397.9    613   2.4406 3.9118 
mknmz::write_phrase_hash_sub
 18.9   1476. 1471.6 167220   0.0009 0.0009  mknmz::get_last_docid
 0.94   73.28 111.11  10259   0.0071 0.0108  mknmz::make_phrase_hash
 0.82   64.11 63.945  61557   0.0010 0.0010  mknmz::wordcount_sub
 0.79   61.51 56.513 167220   0.0000 0.0000  mknmz::adjust_first_docid
 0.66   51.09 171.62  10259   0.0050 0.0167  mknmz::count_words
 0.58   45.00 39.479 184686   0.0000 0.0000  mknmz::hash
 0.44   33.97 33.060 306552   0.0001 0.0001  Text::Kakasi::xs_do_kakasi
 0.37   28.48 97.980  10259   0.0028 0.0096  mknmz::put_field_index
 0.36   27.99 27.969  10262   0.0027 0.0027 
File::MMagic::checktype_data
 0.28   21.66 21.740  10259   0.0021 0.0021 
mailnews::mailnews_citation_filter
 0.26   20.23 19.390 283269   0.0001 0.0001  IO::File::open
 0.24   18.39 18.337  20900   0.0009 0.0009  NKF::nkf


[SE1] 修正後 インデックス書き出し7回

Total Elapsed Time = 1496.921 Seconds
  User+System Time = 632.5312 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 11.3   71.53 110.34  10259   0.0070 0.0108  mknmz::make_phrase_hash
 10.4   66.21 66.076  61557   0.0011 0.0011  mknmz::wordcount_sub
 8.10   51.24 172.72  10259   0.0050 0.0168  mknmz::count_words
 7.09   44.83 40.232 184686   0.0000 0.0000  mknmz::hash
 6.63   41.92 56.296      7   5.9898 8.0424  mknmz::write_index_sub
 5.23   33.07 32.314 306552   0.0001 0.0001  Text::Kakasi::xs_do_kakasi
 4.46   28.19 28.174  10262   0.0027 0.0027 
File::MMagic::checktype_data
 4.42   27.93 99.511  10259   0.0027 0.0097  mknmz::put_field_index
 3.80   24.01 21.212 112310   0.0000 0.0000  mknmz::readw
 3.27   20.70 20.736  10259   0.0020 0.0020 
mailnews::mailnews_citation_filter
 3.07   19.42 26.304      7   2.7746 3.7577 
mknmz::write_phrase_hash_sub
 3.01   19.04 18.357 277209   0.0001 0.0001  IO::File::open
 2.99   18.91 18.868  20900   0.0009 0.0009  NKF::nkf
 2.79   17.65 18.557  10259   0.0017 0.0018  mailnews::mailnews_filter
 2.72   17.23 17.214  10259   0.0017 0.0017  mailnews::uuencode_filter


[SE2] 修正後 インデックス書き出し1回

Total Elapsed Time = 2487.854 Seconds
  User+System Time = 581.7140 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 12.4   72.67 112.75  10259   0.0071 0.0110  mknmz::make_phrase_hash
 11.3   65.74 65.637  61557   0.0011 0.0011  mknmz::wordcount_sub
 9.21   53.58 175.39  10259   0.0052 0.0171  mknmz::count_words
 7.72   44.92 41.236 184686   0.0000 0.0000  mknmz::hash
 5.80   33.72 33.117 306552   0.0001 0.0001  Text::Kakasi::xs_do_kakasi
 4.91   28.56 102.11  10259   0.0028 0.0100  mknmz::put_field_index
 4.91   28.53 28.519  10262   0.0028 0.0028 
File::MMagic::checktype_data
 3.77   21.93 21.923  10259   0.0021 0.0021 
mailnews::mailnews_citation_filter
 3.32   19.29 18.746 277149   0.0001 0.0001  IO::File::open
 3.27   19.00 18.968  20900   0.0009 0.0009  NKF::nkf
 3.14   18.25 19.257  10259   0.0018 0.0019  mailnews::mailnews_filter
 2.79   16.24 16.229  10259   0.0016 0.0016  mailnews::uuencode_filter
 2.65   15.38 15.349  20518   0.0007 0.0007  gfilter::line_adjust_filter
 2.43   14.10 14.089  10262   0.0014 0.0014 
File::MMagic::checktype_byfilename
 2.32   13.51 12.966 277136   0.0000 0.0000  IO::Handle::close


[SE3] 修正後 インデックス書き出し65回

Total Elapsed Time = 1395.026 Seconds
  User+System Time = 1153.626 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 27.5   317.7 454.83     65   4.8889 6.9974  mknmz::write_index_sub
 20.7   238.9 205.11 113108   0.0000 0.0000  mknmz::readw
 14.1   163.1 231.48     65   2.5102 3.5613 
mknmz::write_phrase_hash_sub
 6.13   70.74 107.88  10259   0.0069 0.0105  mknmz::make_phrase_hash
 5.67   65.38 65.215  61557   0.0011 0.0011  mknmz::wordcount_sub
 4.25   48.97 169.58  10259   0.0048 0.0165  mknmz::count_words
 3.85   44.37 38.849 184686   0.0000 0.0000  mknmz::hash
 2.90   33.48 32.570 306552   0.0001 0.0001  Text::Kakasi::xs_do_kakasi
 2.44   28.16 28.139  10262   0.0027 0.0027 
File::MMagic::checktype_data
 2.26   26.06 94.500  10259   0.0025 0.0092  mknmz::put_field_index
 1.88   21.65 21.710  10259   0.0021 0.0021 
mailnews::mailnews_citation_filter
 1.70   19.59 18.767 277789   0.0001 0.0001  IO::File::open
 1.60   18.41 18.357  20900   0.0009 0.0009  NKF::nkf
 1.54   17.71 18.716  10259   0.0017 0.0018  mailnews::mailnews_filter
 1.46   16.80 16.779  10259   0.0016 0.0016  mailnews::uuencode_filter


[SE4] 修正後 インデックス書き出し613回

Total Elapsed Time = 9090.216 Seconds
  User+System Time = 6231.456 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 45.8   2856. 4181.8    613   4.6605 6.8220  mknmz::write_index_sub
 36.7   2290. 1970.9 106746   0.0000 0.0000  mknmz::readw
 23.8   1485. 2134.2    613   2.4228 3.4816 
mknmz::write_phrase_hash_sub
 1.23   76.84 116.60  10259   0.0075 0.0114  mknmz::make_phrase_hash
 1.07   66.67 66.505  61557   0.0011 0.0011  mknmz::wordcount_sub
 0.87   54.30 177.19  10259   0.0053 0.0173  mknmz::count_words
 0.75   46.99 41.469 184686   0.0000 0.0000  mknmz::hash
 0.55   34.38 33.470 306552   0.0001 0.0001  Text::Kakasi::xs_do_kakasi
 0.46   28.50 28.479  10262   0.0028 0.0028 
File::MMagic::checktype_data
 0.43   27.09 97.130  10259   0.0026 0.0095  mknmz::put_field_index
 0.35   21.62 21.660  10259   0.0021 0.0021 
mailnews::mailnews_citation_filter
 0.33   20.42 19.580 283269   0.0001 0.0001  IO::File::open
 0.30   18.49 19.366  10259   0.0018 0.0019  mailnews::mailnews_filter
 0.29   18.01 17.957  20900   0.0009 0.0009  NKF::nkf
 0.27   16.85 16.829  10259   0.0016 0.0016  mailnews::uuencode_filter
-- 
=====================================================================
寺西 忠勝(TADAMASA TERANISHI)  yw3t-trns @ asahi-net.or.jp
http://www.asahi-net.or.jp/~yw3t-trns/index.htm
Key fingerprint =  474E 4D93 8E97 11F6 662D  8A42 17F5 52F4 10E7 D14E





Namazu-devel-ja メーリングリストの案内