这是尽可能接近内置 bash 调试工具的答案,因为它提供了从脚本执行开始时间开始的总体时间信息。
在脚本顶部添加第二次计数:
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