[user@俺 ~]$ reboot

何年か新しいIT技術と向き合っていないうちに、浦島太郎になってしまった...そんなインフラ技術者の日記

反省:shell script で、インクリメントにexpr を使っていた件...

ちょっと調査をしていて、Linux 環境上で、実験をしようと思い、簡単なシェルを書いて動かしてみたところ、思った以上に時間がかかってしまいました。何故だろうと思い、pertコマンドを使って調べてみたところ、添字で使っていた変数のインクリメント処理で、expr を使っているのが、処理コストが高いということが判明。

なにも考えずに、何年も使ってきただけに、これはイカンと反省しました。

実験の目的は、RDBMSなり、KVSなりにデータをinsertする処理の性能(TPS)を測定しようとした時に、おそらくテキストデータにinsertする以上の性能はでないのではないかと思ったので、実現したい性能は、果たして現実的なものなのかどうか?というのを実験するために、下記の様なシェルを用意して実行しました。

#!/bin/sh

### iostat.sh

cnt=0;
datestring=`date`;

while [ $cnt -le 85000 ];
do
    echo "$datestring:$cnt:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA" >> output.dat
    cnt=`expr $cnt + 1`
done

下記が実行結果。

$ time ./iotest.sh 

real    0m44.039s
user    0m7.543s
sys 0m31.058s
$ 

目標としては、1秒間で数万レコードのinsert を受け付けられるような仕組みを作りたかったので、これでは流石に話になりません。が、time のレポートから、sysが妙に高いのが気になりました。なにゆえ?個人的には、userモードで殆ど動く外だし、文字列も小さいので、それ程、IOに跳ね返りがあるとも思えなかったので、気になってperfコマンドで調べてみました。

perfコマンドでレポート出力(上位)

Samples: 25K of event 'cpu-clock', Event count (approx.): 6361750000
Overhead  Command    Shared Object      Symbol
   5.95%  expr       libc-2.22.so       [.] _dl_addr
   5.66%  expr       [kernel.kallsyms]  [k] finish_task_switch
   5.17%  expr       ld-2.22.so         [.] do_lookup_x
   4.79%  iotest.sh  [kernel.kallsyms]  [k] perf_event_exec
   4.68%  expr       [kernel.kallsyms]  [k] __do_page_fault
   3.12%  expr       ld-2.22.so         [.] _dl_relocate_object
   3.02%  expr       [kernel.kallsyms]  [k] unmap_single_vma

添字のインクリメントで使っているexprの処理コストが高いんだと...処理の大半が、SYSで使われていて、高コスト処理がexpr であるということで、このやり方が良くないということに初めて気がつきました。 ということで、bashの組み込み?の和算方法に、書き方を次の様に変更

#!/bin/sh

### iotest.sh

cnt=0;
datestring=`date`;

while [ $cnt -le 85000 ];
do
    echo "$datestring:$cnt:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA" >> output.dat
    cnt=$((cnt+1))
done

再度計測してみると。

$ time ./iotest.sh 

real    0m1.729s
user    0m1.354s
sys 0m0.260s
$ 

ということで、1秒には届きませんが、最初のものより25倍程度、処理が高速になりました。ちなみに、インクリメントの方法を変えた上での、perfの出力は、次のようになりました。

Samples: 2K of event 'cpu-clock', Event count (approx.): 612000000
Overhead  Command    Shared Object      Symbol
   7.80%  iotest.sh  libc-2.22.so       [.] _int_free
   7.23%  iotest.sh  libc-2.22.so       [.] _int_malloc
   5.47%  iotest.sh  libc-2.22.so       [.] malloc
   3.55%  iotest.sh  bash               [.] dequote_string
   2.78%  iotest.sh  bash               [.] unquoted_glob_pattern_p
...

これ以上、早くするのであれば、シェルを違うものに変えれば、結果は変わってきそうですが、現状を仮想マシン上で実行している事を勘案して、一旦、あまりに無理な事をやろうとしている訳ではなさそうだと言う感触を得ることができました。

まとめると、shell script で変数の四則演算をする時は、expr ではなく、$((value [+-*/] value)) で行うのがいいのだという事がわかりました。多分、本来はこのやり方だと思われるので、なんとも、はずかしい...しかし、自分は何故、exprを使う方法で、計算していたのでしょう...(Bourne Shellには、この方法しかなかった??)

その他、perf の使い方を備忘の為。

# プロファイルデータの取得
$ perf record <<command>>

# レポートの表示
$ perf report