Bash - 在脚本中记录所有命令和退出代码

Question

我有一个很长(约 2,000 行)的脚本，我正在尝试记录它以供将来调试。现在我有:

function log_with_time()
{
    while read a; do
        echo `date +'%H:%M:%S.%4N '` " $a" >> $LOGFILE
    done
}

exec 7> >(log_with_time)
BASH_XTRACEFD=7
PS4=' exit($?)ln:$LINENO: '
set -x
echo "helloWorld 1"

这让我可以很好地记录所有运行的命令:

15:18:03.6359  exit(0)ln:28: echo 'helloWorld 1'

我遇到的问题是 xtrace 似乎是异步的。对于较长的脚本，记录时间会落后于调用命令的实际时间，并且退出代码与记录的命令不匹配。

必须有更好的方法来做到这一点，但如果我可以同步 xtrace，我会很高兴。

...

tldr:我通常如何记录脚本中所有命令的时间、命令和退出代码？

...

(第一次发帖，欢迎反馈)

更新:

exec {BASH_XTRACEFD}>>$LOGFILE
PS4=' time:$(date +%H:%M:%S.%4N) ln:$LINENO: '
set -x
fail()
{
    echo "fail" >> $LOGFILE
    return 1
}
trap 'echo exit:$? >> $LOGFILE' DEBUG
fail

解决了我所有的同步问题。退出代码和时间戳工作得很好。我现在唯一的问题是格式化之一:陷阱本身正在被 xtrace 报告。

  time:18:30:07.6080 ln:27: fail
  time:18:30:07.6089 ln:12: echo fail
fail
  time:18:30:07.6126 ln:13: return 1
   time:18:30:07.6134 ln:28: echo exit:1
exit:1

我尝试在陷阱中设置 +x，但随后设置 +x 被记录。如果我能找到一种方法从 xtrace 中省略一行，这个日志就完美了。

Answer 1

异步行为来自进程替换——>(...) 中的任何内容都在 FIFO 另一端的自己的子 shell 中运行。由于它是一个单独的进程，因此本质上是不同步的。

不过，您在这里根本不需要 log_with_time，因此您首先不需要 BASH_XTRACEFD 重定向到进程替换。考虑:

# aside: $(date ...) has a *huge* amount of performance overhead here. Personally, I'd
#        advise against using it, unless you really need all that precision; $SECONDS will
#        be orders-of-magnitude cheaper.
PS4=' prior-exit:$? time:$(date +%H:%M:%S.%4N) ln:$LINENO: '

...此后:

$ true
 prior-exit:0 time:16:01:17.2509 ln:28: true
$ false
 prior-exit:0 time:16:01:18.4242 ln:29: false
$ false
 prior-exit:1 time:16:01:19.2963 ln:30: false
$ true
 prior-exit:1 time:16:01:20.2159 ln:31: true
$ true
 prior-exit:0 time:16:01:20.8650 ln:32: true