linux - bash スクリプトをデバッグし、コマンドごとの実行時間を取得する方法

Question

実行にbash5 秒近くかかるスクリプトがあります。デバッグして、どのコマンドが最も長くかかっているかを判断したいと思います。これを行う最善の方法は何ですか？設定できるフラグはありますか？設定#!/bin/bash -vxはあまり役に立ちません。私が欲しいのは、基本的に行番号ごとの実行時間です。

Answer 1

これは、スクリプトの実行開始時間から全体的なタイミング情報を提供するため、組み込みの bash デバッグ機能を使用した可能な限り近い回答です。

スクリプトの先頭に、2 番目のカウントとしてこれを追加します。

export PS4='+[${SECONDS}s][${BASH_SOURCE}:${LINENO}]: ${FUNCNAME[0]:+${FUNCNAME[0]}(): }'; set -x;

同じですが、代わりにミリ秒を使用します。

N=`date +%s%N`; export PS4='+[$(((`date +%s%N`-$N)/1000000))ms][${BASH_SOURCE}:${LINENO}]: ${FUNCNAME[0]:+${FUNCNAME[0]}(): }'; set -x;

最後の例は、マイクロ秒の精度で実行できますが、bash を使用していることに注意してください :)。

スクリプトの例:

#!/bin/bash
N=`date +%s%N`
export PS4='+[$(((`date +%s%N`-$N)/1000000))ms][${BASH_SOURCE}:${LINENO}]: ${FUNCNAME[0]:+${FUNCNAME[0]}(): }'; set -x;
sleep 1
exit

デバッグ出力の例:

+[3ms][/root/db_test.sh:5]: sleep 1
+[1012ms][/usr/local/bin/graphite_as_rand_stat.sh:6]: exit

デバッグ開始時に「set -x」で囲み、デバッグ終了時に「debug +x」で囲むことにより、スクリプトの特定の部分を選択的にデバッグできることに注意してください。タイミング データは、実行開始から数えて正しく表示されます。

補遺

完全を期すために、差分タイミング データが必要な場合は、デバッグ情報をファイルにリダイレクトし、後で処理することができます。

このスクリプト例を考えると:

#!/bin/bash
N=`date +%s%N`
export PS4='+[$(((`date +%s%N`-$N)/1000000))ms][${BASH_SOURCE}:${LINENO}]: ${FUNCNAME[0]:+${FUNCNAME[0]}(): }'; set -x;
sleep 1
for ((i=0;i<2;i++)); do
        o=$(($RANDOM*$RANDOM/$RANDOM))
        echo $o
        sleep 0.$o
done
exit

デバッグをファイルにリダイレクトしながら実行します。

./example.sh 2>example.dbg

そして、これで差分デバッグタイミングを出力します（複数行をカバーします）：

p=0; cat example.dbg | while read l; do [[ ! ${l%%[*} =~ ^\+ ]] && echo $l && continue; i=`echo $l | sed 's#[^0-9]*\([0-9]\+\).*#\1#'`; echo $l | sed "s#${i}ms#${i}ms+$(($i-$p))ms#"; p=$i; done

出力：

+[2ms+2ms][./example.sh:5]: sleep 1
+[1006ms+1004ms][./example.sh:6]: (( i=0 ))
+[1009ms+3ms][./example.sh:6]: (( i<2 ))
+[1011ms+2ms][./example.sh:7]: o=19258
+[1014ms+3ms][./example.sh:8]: echo 19258
+[1016ms+2ms][./example.sh:9]: sleep 0.19258
+[1213ms+197ms][./example.sh:6]: (( i++ ))
+[1217ms+4ms][./example.sh:6]: (( i<2 ))
+[1220ms+3ms][./example.sh:7]: o=176
+[1226ms+6ms][./example.sh:8]: echo 176
+[1229ms+3ms][./example.sh:9]: sleep 0.176
+[1442ms+213ms][./example.sh:6]: (( i++ ))
+[1460ms+18ms][./example.sh:6]: (( i<2 ))
+[1502ms+42ms][./example.sh:11]: exit