作为调试过程的重要步骤,仔细寻找时间和进度是必须具备的。
script
和 scriptreplay
,我想知道是否存在用于操作结果文件的工具。
示例(来自如何分析 bash shell 脚本缓慢启动?):
script -t script.log 2>script.tim -c 'bash -x -c "
for ((i=3;i--;));do sleep .1;done
for ((i=2;i--;)) ;do
tar -cf /tmp/test.tar -C / bin
gzip /tmp/test.tar
rm /tmp/test.tar.gz
done
"'
然后有两个文件:
-rw-r--r-- 1 user user 472 Sep 25 10:44 script.log
-rw-r--r-- 1 user user 213 Sep 25 10:44 script.tim
我可以通过以下方式重播脚本:
scriptreplay --timing script.tim --typescript script.log 10
使用
10
作为 执行时间除数 使重放速度加快 10 倍,或者
scriptreplay --timing script.tim --typescript script.log .1
使重放速度减慢 10 倍。
我想知道是否存在这样的工具:
好吧,从那里开始:
cut -d \ -f1 <script.tim | xargs | tr \ + | bc
3.616809
将输出整体执行时间或者如果行太多:
cut -d \ -f1 <script.tim | xargs | tr \ + | bc | xargs | tr \ + | bc
3.616809
和
cut -d \ -f2 <script.tim | xargs | tr \ + | bc
366
sed '1d;$d' script.log |wc -c
367
检查整体脚本输出大小。 (sed
删除日志的第一行和最后一行,其中包含:
Script started on Wed Sep 25 14:40:20 2019
和
Script done on Wed Sep 25 14:40:23 2019
。)然后,
计算某个时间的日志大小(指针):
perl -e 'my ($l,$t,$p)=(0,0,0); # line totTime pos
open FH,"<".$ARGV[0] || die;
while (<FH>) {
my ($d,$n)=split" "; # duration numBytes
$l++;
$t+=$d;
$p+=$n;
$t>=${ARGV[1]} && do {
print $l." ".$p."\n";
exit 0;
};
};' script.tim 1.2
12 216
计时文件中的第 12 行 (head -n 12
) 和打字稿文件中的字节位置 216 (
head -c 216
)。或者如果我
搜索已过去的时间直到某个字符串:
grep -ob 'tar.*test' script.log
217:tar -cf /tmp/test
320:tar -cf /tmp/test
perl -e 'my ($l,$t,$p)=(0,0,0);open FH,"<".$ARGV[0] || die;while (<FH>) {
my ($d,$n)=split" ";$l++;$t+=$d;$p+=$n;$p>=${ARGV[1]} && do {
print $l." ".$p."\n";exit 0;};};' script.tim 217
17 228
head -n 17 script.tim | cut -d \ -f1 | xargs | tr \ + | bc
1.091276
我的要求:
script
非常有用!在bash 下,你可以使用一些技巧。 我的示例基于本文第一个脚本创建的两个文件
script.log
和
script.log
(示例来自如何分析 bash shell 脚本缓慢启动?),在 raspberry pi 上运行:
整体执行时间
您不必多次分叉到 xargs | tr \ + | bc |
,您可以对bash 管理很长算术行的能力充满信心:
elaps=00000$(($(sed 's/ .*$/+/;s/\.//;s/^0*//' script.tim)0))
TZ=UTC printf '%(%T)T.%s\n' $((10#${elaps::-6})) ${elaps: -6}
00:01:38.595605
或者,如果您预计执行时间很长,只需添加天数:
TZ=UTC printf '%dd%(%T)T.%s\n' \
$((10#${elaps::-8}/864)) $((10#${elaps::-6})) ${elaps: -6}
0d00:01:38.595605
浏览错误。由于 script
将创建一个专用的terminal,因此默认情况下为其输出着色的所有命令(未通过管道传输时)都将在 red 中打印错误,方法是在输出中添加前缀
\E[31m
、
\E[31;1m
、
\E[1;31m
或类似的东西。不幸的是,示例文件中没有颜色错误...我在很长的过程中使用了它。我通过以下方式运行我的脚本:
printf -v filenam 'mklive-%(%F-%H%M)T' -1
script -t $filenam.log 2>$filenam.tm -c myLiveBuild.sh
然后可以通过以下方式浏览日志文件中red突出显示的行:
less -r $'+/\[([0-9;]+;|)31([0-9;]+;|)m' $filenam.log
这个技巧可以与以下两个脚本一起使用。
xterm
并在新终端中运行重放脚本输出,其大小与运行脚本的大小相同。交互非常简约。这里有两个选项:
-t
使用builtin
read
进行时间间隔,这样就可以通过点击Return 来加速。
-w
提交要搜索的单词或字符串。进度将停止,直到您按Return。
#!/bin/bash
export LANG=C LANGUAGE=C
die() { echo >&2 "$0 ERR: $@";exit 1;}
doTime=false
while getopts "tw:" opt;do case $opt in
t ) doTime=true;;
w ) searchFor=${OPTARG};;
esac;done
shift $((OPTIND-1))
exec {log}<"$1" || die "Can't open logfile '$1'."
exec {tim}<"$2" || die "Can't open timing file '$2'-"
IFS='' read -ru $log line || die "error reading logfile."
sTerm=${line#*TERM=\"} sTerm=${sTerm%%\"*}
sCols=${line#*COLUMNS=\"} sCols=${sCols%%\"*}
sLnes=${line#*LINES=\"} sLnes=${sLnes%%\"*}
[ "$sTerm" ] || die "No TERM var found."
((sCols * sLnes)) || die "No valid size"
exec {term}<> >(:)
xterm -fs 11 -geom ${sCols}x$sLnes -T ScripReplay -S00/$term &
XTPid=$!
read -u $term -t 1 XTWinId
declare -i TTime=0 TChar=0
while read -u $tim time chars;do
IFS='' read -d '' -rn $chars -u $log str
printf >&$term '%s' "$str"
TTime+=10#${time/.} TChar+=chars
ttm=00000$TTime
printf "\rCrt %12.6f, %3d chars - Tot: %12.6f %11d\n" $time $chars \
${ttm::-6}.${ttm: -6} $TChar
[ "$searchFor" ] &&
case $str in *$searchFor* ) read -p "Found: '$searchFor'. " _;;esac
$doTime && read -t $time _
done
exec {tim}<&-
exec {log}<&-
read -pDone.\ _
exec {term}>&-
kill $XTPid
在 python 中也一样,欢迎!
我的网站上有更多特色版本:scriptReplay.sh.txt,scriptReplay.sh。
Script Replay based debugging tool
Command line optional arguments:
-h Show this.
-t Reproduce delays between outputs ('$doTime', default false)
-d DIVISOR Integer divisor of delay [-t] ('$divisor', default 10)
-w STRING Stop output when STRING found, wait for user interaction
-n Don't wait when STRING found
Interactive interface: Once run, ${0##*/} will open another xterm
window to show console dialog as recorded by script.
While running, interaction in first console could be:
[t] Toggle reproducing time delays between outputs
[d] Enter a new INTEGER for divisor
[s] Enter a new STRING to search for
[q] Quit.
另一个 bc
):
#!/bin/bash
coproc exec bc
echo >&${COPROC[1]} t=0.0
{
declare -i Tlen=0
read -u $lg hl
echo HEAD $hl
while read -u $tm tim chrs ;do
echo "t+=$tim;t" >&${COPROC[1]}
read -u ${COPROC[0]} Ttim
Tlen+=$chrs
LANG=C IFS='' read -d '' -u $lg -rn $chrs str
printf '%10.6f %-4d|%12.6f %12d: %s\n' $tim $chrs $Ttim $Tlen "${str@Q}"
done
while read -u $lg str ;do
echo "TAIL: ${str@Q}"
done
} {lg}<"$1" {tm}<"$2"
在本文中第一个命令生成的 script.log
和
script.tim
上运行将在我的树莓派上渲染:
$ ./quickReplay.sh script.{log,tim}
HEAD Script started on 2022-04-07 14:37:19+02:00 [TERM="xterm" TTY="/dev/pts/0" COLUMNS="80" LINES="24"]
0.083946 11 | 0.083946 11: '+ (( i=3 ))'
0.001231 2 | 0.085177 13: $'\r\n'
0.001951 11 | 0.087128 24: '+ (( i-- ))'
0.001023 2 | 0.088151 26: $'\r\n'
0.001947 10 | 0.090098 36: '+ sleep .1'
0.001412 2 | 0.091510 38: $'\r\n'
0.123944 9 | 0.215454 47: '+ (( 1 ))'
0.005763 2 | 0.221217 49: $'\r\n'
0.001559 11 | 0.222776 60: '+ (( i-- ))'
0.001027 2 | 0.223803 62: $'\r\n'
0.001908 10 | 0.225711 72: '+ sleep .1'
0.001256 2 | 0.226967 74: $'\r\n'
0.126024 9 | 0.352991 83: '+ (( 1 ))'
0.001316 2 | 0.354307 85: $'\r\n'
0.001804 11 | 0.356111 96: '+ (( i-- ))'
0.001076 2 | 0.357187 98: $'\r\n'
0.002086 10 | 0.359273 108: '+ sleep .1'
0.002059 2 | 0.361332 110: $'\r\n'
0.125725 9 | 0.487057 119: '+ (( 1 ))'
0.001147 2 | 0.488204 121: $'\r\n'
0.001768 11 | 0.489972 132: '+ (( i-- ))'
0.001346 2 | 0.491318 134: $'\r\n'
0.002247 11 | 0.493565 145: '+ (( i=2 ))'
0.007743 2 | 0.501308 147: $'\r\n'
0.001628 11 | 0.502936 158: '+ (( i-- ))'
0.000259 2 | 0.503195 160: $'\r\n'
0.000810 32 | 0.504005 192: '+ tar -cf /tmp/test.tar -C / bin'
0.001128 2 | 0.505133 194: $'\r\n'
1.336998 20 | 1.842131 214: '+ gzip /tmp/test.tar'
0.001093 2 | 1.843224 216: $'\r\n'
34.593442 23 | 36.436666 239: $'+ rm /tmp/test.tar.gz\r\n'
0.041637 9 | 36.478303 248: '+ (( 1 ))'
0.001435 2 | 36.479738 250: $'\r\n'
0.001617 11 | 36.481355 261: '+ (( i-- ))'
0.010704 2 | 36.492059 263: $'\r\n'
0.001931 32 | 36.493990 295: '+ tar -cf /tmp/test.tar -C / bin'
0.001085 2 | 36.495075 297: $'\r\n'
0.737705 20 | 37.232780 317: '+ gzip /tmp/test.tar'
0.001179 2 | 37.233959 319: $'\r\n'
35.705253 21 | 72.939212 340: '+ rm /tmp/test.tar.gz'
0.001160 2 | 72.940372 342: $'\r\n'
0.053247 9 | 72.993619 351: '+ (( 1 ))'
0.001170 2 | 72.994789 353: $'\r\n'
0.002150 11 | 72.996939 364: '+ (( i-- ))'
0.001353 2 | 72.998292 366: $'\r\n'
TAIL: ''
TAIL: 'Script done on 2022-04-07 14:38:32+02:00 [COMMAND_EXIT_CODE="0"]'