2007年4月15日

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

寺西です。

様々な条件のもと、次のマシンで約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@xxxxx
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 mailing list
Namazu-devel-ja@xxxxx
http://www.namazu.org/cgi-bin/mailman/listinfo/namazu-devel-ja

投稿者 xml-rpc : 2007年4月15日 12:39
役に立ちました?:
過去のフィードバック 平均:(0) 総合:(0) 投票回数:(0)
本記事へのTrackback: http://hoop.euqset.org/blog/mt-tb2006.cgi/57066
トラックバック
コメント
コメントする




画像の中に見える文字を入力してください。