Namazu-devel-ja(旧)


[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

WORD_LENG_MAX の制限が期待通りに動作しない



竹迫です。

Namazu 2.0.10 において、mknmzrc に記述する WORD_LENG_MAX の
制限が期待通りに動作せず、mknmz 実行時に CPU 時間を浪費して
しまうといった不具合がありましたので、ご報告します。


■ 実行環境
-----------
  CPU: Pentium III 1.0GHz
  Mem: 640MB
  OS : Miracle Linux 2.1 (kernel 2.4.7-2.24ml)

  読み込んだ設定ファイル: /etc/namazu/mknmzrc
  システム: linux
  Namazu: 2.0.10
  Perl: 5.006
  NKF: module_nkf
  KAKASI: no
  茶筌: module_chasen -j -F '%m '
  わかち書き: module_chasen -j -F '%m '
  メッセージの言語: ja_JP.eucJP
  言語: ja_JP.eucJP
  文字コード: euc


■ 不具合の内容
---------------
インデックスの対象ファイルに、スペースで区切られていない
約30万文字の単語が存在していると、mknmz 実行時の CPU占有率が 
100% 近くになり、一日経過してもインデックス処理が終了しない。


■ 修正パッチの内容
-------------------
* mknmz.in Revision 1.85.4.27 (Branch: stable-2-0)
  http://cvs.namazu.org/namazu/scripts/mknmz.in.diff?r1=1.85.4.26&r2=1.85.4.27

* mknmz.in Revision 1.108 (Branch: MAIN)
  http://cvs.namazu.org/namazu/scripts/mknmz.in.diff?r1=1.107&r2=1.108


■ 動作検証用スクリプト
-----------------------
Devel::DProf を用いて、パッチ修正前の mknmz と、修正後の
それぞれに対して profiler をかけて、実行時間を計測します。

  実行スクリプト: /tmp/mknmz (← /usr/bin/mknmz からコピー)
  パッチファイル: /tmp/mknmz.patch.gz
  テスト用文書 : /tmp/test.txt
  インデックス1 : /tmp/index1
  インデックス2 : /tmp/index2


■ 動作検証用スクリプト
-----------------------
以下のシェルスクリプトを実行させて動作検証を行います。

実際に約30万文字の単語を用いると、非常に時間がかかってしまうので、
単語の文字数を 10000 × 2 に減らして実行しています。

# -- 修正パッチを当てる前 (before)
cd /tmp
rm -f mknmz
cp -p /usr/bin/mknmz .
echo "test Namazu index" > /tmp/test.txt
perl -e 'print ("x" x 10000) . "\n";' >> /tmp/test.txt
perl -e 'print ("y" x 10000) . "\n";' >> /tmp/test.txt
rm   -rf /tmp/index1
mkdir -p /tmp/index1
perl -d:DProf mknmz -a -O /tmp/index1 /tmp/test.txt
dprofpp -u

# -- 修正パッチを当てた後 (after)
cat <<'X' | uudecode
begin 644 mknmz.patch.gz
M'XL("--.#3T"`VUK;FUZ+G!A=&-H`*U044_",!A\'K_B@DL<SC$V`NB(.A.-
MB5%)C`DFHLM@'5MD+:X%4=3?;K<"\F#BBWWYVM[U>G>692%[IME[G>7I6+N;
M$5R&%#B`T_*<CM=LP6TTW(IIFHJG]4F$RYFD%(C7=+R6HRB^#\MMM)O[;9CE
M[,#W*RA6]@;]E>51,,01>)+&`GYQYMT?/&*C-)*PV@0C-J,"YOHX##E9D6.6
M;P1A*)T:EA53HV0AD,8P%$9>4*WBXP,30L<B4;<U'$,?,1I[7K]W>Q9<G=]<
M!->G]S6IKA6R2<@3::,8QMIT7?U6<F9T0CB'$9$XI;(+76339?GJLW`!K?"X
M=2FUG*XJQW7;LA13SLZJG$U\%:-H9SI)!>P!-^U]*2,3_1';VL3>2MW]CS;*
MM_,P][S>5"QW*2/1F/"W;,@FNUM9=Y"3C,T)%,01"@R92$!HQ-=]E!:.OL#M
HIX>GP2)TK,$B)J'U'C2LP\<]H[YW4OL-T&W=L<?=RC>N]V_OJ`(`````
`
end
X
gzip -cd mknmz.patch.gz | patch
rm   -rf /tmp/index2
mkdir -p /tmp/index2
perl -d:DProf mknmz -a -O /tmp/index2 /tmp/test.txt
dprofpp -u

# -- インデックスに登録される単語は変わらない
diff -urN /tmp/index1/NMZ.w  /tmp/index2/NMZ.w 


■ 実行結果
-----------
計測した結果は、以下の通りでした。

□ 修正パッチを当てる前 (before)
--------------------------------
$ dprofpp -u
Total Elapsed Time = 25.67594 Seconds
         User Time = 25.39594 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 94.1   23.92 23.920      2   11.960 11.960  mknmz::wordcount_sub
 2.44   0.620  0.620      1   0.6200 0.6200  mknmz::write_phrase_hash_sub
 1.30   0.330  0.330      3   0.1100 0.1100  mknmz::hash
 0.47   0.120  0.120      1   0.1200 0.1200  Text::ChaSen::getopt_argv
 0.28   0.070  0.070      1   0.0700 0.0700  File::MMagic::checktype_data
 0.24   0.060  0.060      1   0.0599 0.0597  mknmz::load_filters
 0.20   0.050  0.100     12   0.0042 0.0083  mknmz::BEGIN
 0.08   0.020  0.019    600   0.0000 0.0000  mknmz::mo_format_value
 0.08   0.020  0.030     33   0.0006 0.0009  Exporter::import
 0.08   0.020  0.020    117   0.0002 0.0002  File::MMagic::magicMatchStr
 0.08   0.020  0.029    146   0.0001 0.0002  File::MMagic::readMagicEntry
 0.08   0.020  0.020      8   0.0025 0.0025  mknmz::make_headfoot
 0.04   0.010  0.010      3   0.0033 0.0033  Getopt::Long::FindOption
 0.04   0.010  0.010      4   0.0025 0.0025  AutoLoader::AUTOLOAD
 0.04   0.010  0.010      5   0.0020 0.0020  Exporter::export

□ 修正パッチを当てた後 (after)
-------------------------------
$ dprofpp -u
Total Elapsed Time = 1.332976 Seconds
         User Time = 1.182976 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 52.4   0.620  0.620      1   0.6200 0.6200  mknmz::write_phrase_hash_sub
 10.1   0.120  0.120      1   0.1200 0.1200  Text::ChaSen::getopt_argv
 5.92   0.070  0.070      1   0.0700 0.0700  File::MMagic::checktype_data
 5.07   0.060  0.070      1   0.0600 0.0699  mknmz::load_filters
 3.38   0.040  0.100     12   0.0033 0.0083  mknmz::BEGIN
 2.54   0.030  0.030    117   0.0003 0.0003  File::MMagic::magicMatchStr
 1.69   0.020  0.020      4   0.0050 0.0050  AutoLoader::AUTOLOAD
 1.69   0.020  0.020      4   0.0050 0.0050  IO::Seekable::BEGIN
 1.69   0.020  0.029    146   0.0001 0.0002  File::MMagic::readMagicEntry
 0.85   0.010  0.010      1   0.0100 0.0100  NKF::nkf
 0.85   0.010  0.010     10   0.0010 0.0010  vars::import
 0.85   0.010  0.010     10   0.0010 0.0010  File::MMagic::addFileExts
 0.85   0.010  0.010    600   0.0000 0.0000  mknmz::mo_format_value
 0.85   0.010  0.010    140   0.0001 0.0001  Symbol::gensym
 0.85   0.010  0.010      2   0.0050 0.0050  Cwd::BEGIN


■ 結論
-------
以上の結果から、修正パッチ前を当てる前では、
mknmz::wordcount_sub と mknmz::hash の処理が
実行時間の 約 95% 以上を占めていましたが、
修正パッチを当てることにより、上記サブルーチンの
処理時間がすべて 1% 未満に収まっていることがわかります。


こちらで試した限りでは、副作用は起きていないようですが、
他の環境でも問題がないかどうかテストしていただけると有り難いです。

--
  株式会社ドリーム・アーツ 製品企画開発本部
    竹迫 良範  <takesako@xxxxxxxxxx>