業務で40万行のxmlファイルの第2層のタグを名前順にソートするシェルスクリプトの改修
問題点は、処理に20分以上かかるのでもっと速度を改善すること。
シェルスクリプトのフローはおおむね下記のとおり
①第2層のタグ配下の第3層タグ以下を第2層開始タグと第2層終了タグの間に1行にしてはさみ込む
②第2層開始タグ名順にソート
③第2層開始タグと第2層終了タグの間に1行にしてはさみ込んだ第3層タグ以下を元に戻す
ボトルネックを探すために、シェルスクリプトのシェバンに
#! /bin/bash -x
のようにデバッグオプションを付加して実行
①の処理にほとんどの時間が費やされていたことが判明
①の処理部分をさらに細かく分析。
while read line1 line2
do
処理 >> ファイル
done < file
のwhileループに時間がかかっていた。
上記のWhileループでは、約40万行のxmlファイルを1行ずつループを回して、第2層開始タグと第2層終了タグの間の行にだけ改行コード「\n」を削除して、すべて一行にフラット化させるループになっていた。
このループでは、一行ずつ、「\n」を削除した結果を、出力ファイルにリダイレクトで追記していたが、この追記に関しては、イテレーション一回で追記するバイト量が少なかったために、ボトルネックになっていなかった。
※vmstat 2 でこのイテレーションを実行したところ、usが約30％、syが数％、waがほぼ0％、残りはidだったので、cpuは頭打ちになっておらず、io waitが発生してなかった。
ためしにイテレーション一回分の書き込みを10倍くらいにしたらwaが数％に上がった。
write IOは5～6秒おきに割込みとwrite ioが発生しており遅延書き込みにより、write back cacheからまとめてディスクに書き出すので書き込みタイミングが十分長いか、書き込み量が少なければボトルネックになっていなかった。
ループに時間がかかっていた原因は、リダイレクトのwrite IOでなかったことは、リダイレクト先をファイルから、/dev/nullにしても処理時間が1割くらいしか改善されなかったことでも確認できた。
ループの中の処理は、
第2階層以下の行をheadコマンドの標準出力をtailコマンドの標準入力にパイプラインで渡して、取り出した行末の「\n」を削除するtrコマンドにさらにパイプラインで渡していたが、
この処理でイテレーションの度に、headとtailコマンドの標準入出力領域のメモリの確保と解放が発生していた。 さらに途中のパイプライン３連結でも、カーネルにパイプシステムコール、forkシステムコール、execシステムコールが発生しており、このためにプロセス生成コストが発生していた。
ためしに、上記の処理を先頭のheadコマンドの標準出力を/dev/nullに捨てる処理に書き換えたところ、処理時間が2/3に改善された。
さらに、headコマンドのユーザメモリ確保と解放をさせないで、外部コマンドのプロセス生成と解放だけにする試みとして、イテレーションの中の処理を「ls -l > /dev/null」に変更したら、処理時間が1/4の5分に改善された。 つまり、単純な外部コマンドであるlsのプロセス生成と解放だけでも5分が必要になった。
さらに、イテレーションの中の処理を「cd tmp;cd ..」のようなbash組込みコマンドに変更したら、処理時間は20秒に改善された。
つまり、ボトルネックは、ユーザメモリの確保と解放と、プロセス生成と解放を数万回のイテレーションで実行していたことだった。
そこで改善策として、①の処理全体で、メモリ確保/解放とプロセス生成/解放を1回だけにするために、前述のwhileループ部分を、perlスクリプトに置き換えた。
※perlを選んだ理由は、bashループ内で外部コマンドの実行をしないようにすることだが、この目的だけなら、awkでもpythonでもよかった。
awkは、bashからファイルをパイプで受け渡しできて便利だったが、複雑な論理演算の処理順序やループ処理を制御する部分が複雑になると分かりやすく書けなくなるので却下し、pythonは、まだ実行できる環境がperlほど多くなく、今回はWindows上のcygwinだったこともあり、移植性がperlと比べて劣るということで却下した。
話を戻すと、perlスクリプトの実行処理では、プロセスがperlプロセスを起動する最初に生成されperlスクリプトの最後までプロセス生成はこの一回だけになる。perlスクリプト内の処理はインタプリタの仮想メモリ内とCPUキャッシュやレジスタ間のやりとりだけで完結する。
一方、bashのループ内で外部コマンドを実行させると、イテレーションごとに、execシステムコールが発生して、そのたびにカーネルコードが実行され、カーネルメモリ領域へread/writeも発生する。
実際に試してみたら、処理時間は最初の20分以上から約20秒に改善された。
※bashスクリプトの他の部分をすべてperlにして、sortコマンドをexecしないで、perlのsort関数を使うように修正したら最終的に約5秒に改善された。
ちなみに、シェルスクリプトを見る前に立てた仮説では、sort部分がボトルネックになっているのではないかと予想したが、sortは理論上少なくともn*log(n)以上の計算量が必要なわけだが、メモリ領域の確保/解放は最初の1回ぽっきりで、nが小さければ数秒で終了した。
※上記の②の処理でsortする前に、①の処理でxmlファイルの行数を数千行まで減らしていた。
20160618追記
Linuxのcoreutilsパッケージに含まれてるsortコマンドは、コンパイル言語（たぶんc）で書かれたELF 64-bit LSB executable,なプログラムなので、sortコマンドはそこそこスピードが出る。
例えば、2.5GHz×4コアのマシンで実行したところ、数百万行のsortは1秒未満。
数千万行で十数秒。数億行で数十分のオーダーだった。
sortの処理時間が問題になるのは、数千万から数億以上のレコード数になるようなDBか、巨大ログを扱うときぐらいか。
問題点は、処理に20分以上かかるのでもっと速度を改善すること。
シェルスクリプトのフローはおおむね下記のとおり
①第2層のタグ配下の第3層タグ以下を第2層開始タグと第2層終了タグの間に1行にしてはさみ込む
②第2層開始タグ名順にソート
③第2層開始タグと第2層終了タグの間に1行にしてはさみ込んだ第3層タグ以下を元に戻す
ボトルネックを探すために、シェルスクリプトのシェバンに
#! /bin/bash -x
のようにデバッグオプションを付加して実行
①の処理にほとんどの時間が費やされていたことが判明
①の処理部分をさらに細かく分析。
while read line1 line2
do
処理 >> ファイル
done < file
のwhileループに時間がかかっていた。
上記のWhileループでは、約40万行のxmlファイルを1行ずつループを回して、第2層開始タグと第2層終了タグの間の行にだけ改行コード「\n」を削除して、すべて一行にフラット化させるループになっていた。
このループでは、一行ずつ、「\n」を削除した結果を、出力ファイルにリダイレクトで追記していたが、この追記に関しては、イテレーション一回で追記するバイト量が少なかったために、ボトルネックになっていなかった。
※vmstat 2 でこのイテレーションを実行したところ、usが約30％、syが数％、waがほぼ0％、残りはidだったので、cpuは頭打ちになっておらず、io waitが発生してなかった。
ためしにイテレーション一回分の書き込みを10倍くらいにしたらwaが数％に上がった。
write IOは5～6秒おきに割込みとwrite ioが発生しており遅延書き込みにより、write back cacheからまとめてディスクに書き出すので書き込みタイミングが十分長いか、書き込み量が少なければボトルネックになっていなかった。
ループに時間がかかっていた原因は、リダイレクトのwrite IOでなかったことは、リダイレクト先をファイルから、/dev/nullにしても処理時間が1割くらいしか改善されなかったことでも確認できた。
ループの中の処理は、
第2階層以下の行をheadコマンドの標準出力をtailコマンドの標準入力にパイプラインで渡して、取り出した行末の「\n」を削除するtrコマンドにさらにパイプラインで渡していたが、
この処理でイテレーションの度に、headとtailコマンドの標準入出力領域のメモリの確保と解放が発生していた。 さらに途中のパイプライン３連結でも、カーネルにパイプシステムコール、forkシステムコール、execシステムコールが発生しており、このためにプロセス生成コストが発生していた。
ためしに、上記の処理を先頭のheadコマンドの標準出力を/dev/nullに捨てる処理に書き換えたところ、処理時間が2/3に改善された。
さらに、headコマンドのユーザメモリ確保と解放をさせないで、外部コマンドのプロセス生成と解放だけにする試みとして、イテレーションの中の処理を「ls -l > /dev/null」に変更したら、処理時間が1/4の5分に改善された。 つまり、単純な外部コマンドであるlsのプロセス生成と解放だけでも5分が必要になった。
さらに、イテレーションの中の処理を「cd tmp;cd ..」のようなbash組込みコマンドに変更したら、処理時間は20秒に改善された。
つまり、ボトルネックは、ユーザメモリの確保と解放と、プロセス生成と解放を数万回のイテレーションで実行していたことだった。
そこで改善策として、①の処理全体で、メモリ確保/解放とプロセス生成/解放を1回だけにするために、前述のwhileループ部分を、perlスクリプトに置き換えた。
※perlを選んだ理由は、bashループ内で外部コマンドの実行をしないようにすることだが、この目的だけなら、awkでもpythonでもよかった。
awkは、bashからファイルをパイプで受け渡しできて便利だったが、複雑な論理演算の処理順序やループ処理を制御する部分が複雑になると分かりやすく書けなくなるので却下し、pythonは、まだ実行できる環境がperlほど多くなく、今回はWindows上のcygwinだったこともあり、移植性がperlと比べて劣るということで却下した。
話を戻すと、perlスクリプトの実行処理では、プロセスがperlプロセスを起動する最初に生成されperlスクリプトの最後までプロセス生成はこの一回だけになる。perlスクリプト内の処理はインタプリタの仮想メモリ内とCPUキャッシュやレジスタ間のやりとりだけで完結する。
一方、bashのループ内で外部コマンドを実行させると、イテレーションごとに、execシステムコールが発生して、そのたびにカーネルコードが実行され、カーネルメモリ領域へread/writeも発生する。
実際に試してみたら、処理時間は最初の20分以上から約20秒に改善された。
※bashスクリプトの他の部分をすべてperlにして、sortコマンドをexecしないで、perlのsort関数を使うように修正したら最終的に約5秒に改善された。
ちなみに、シェルスクリプトを見る前に立てた仮説では、sort部分がボトルネックになっているのではないかと予想したが、sortは理論上少なくともn*log(n)以上の計算量が必要なわけだが、メモリ領域の確保/解放は最初の1回ぽっきりで、nが小さければ数秒で終了した。
※上記の②の処理でsortする前に、①の処理でxmlファイルの行数を数千行まで減らしていた。
20160618追記
Linuxのcoreutilsパッケージに含まれてるsortコマンドは、コンパイル言語（たぶんc）で書かれたELF 64-bit LSB executable,なプログラムなので、sortコマンドはそこそこスピードが出る。
例えば、2.5GHz×4コアのマシンで実行したところ、数百万行のsortは1秒未満。
数千万行で十数秒。数億行で数十分のオーダーだった。
sortの処理時間が問題になるのは、数千万から数億以上のレコード数になるようなDBか、巨大ログを扱うときぐらいか。