Bash 重定向 stdout 和 stderr 以使用时间戳分隔文件

Question

想要记录所有stdout 和stderr 以分隔文件并为每一行添加时间戳。

尝试了以下方法，但没有时间戳。

#!/bin/bash

debug_file=./stdout.log
error_file=./stderr.log

exec > >(tee -a "$debug_file") 2> >(tee -a "$error_file")

echo "hello"
echo "hello world"

this-will-fail
and-so-will-this

添加时间戳。 （只希望在日志输出前加上时间戳。）

#!/bin/bash

debug_file=./stdout.log
error_file=./stderr.log

log () {
  file=$1; shift 
  while read -r line; do
    printf '%(%s)T %s\n' -1 "$line"
  done >> "$file"
}

exec > >(tee >(log "$debug_file")) 2> >(tee >(log "$error_file"))

echo "hello"
echo "hello world"

this-will-fail
and-so-will-this

后者将时间戳添加到日志中，但它也有可能弄乱我的终端窗口。重现这种行为并不是直截了当的，它只是偶尔发生。我怀疑它必须与子程序/缓冲区仍然有输出流过它。

弄乱我的终端的脚本示例。

# expected/desired behavior
user@system:~ ./log_test
hello
hello world
./log_test: line x: this-will-fail: command not found
./log_test: line x: and-so-will-this: command not found
user@system:~ # <-- cursor blinks here

# erroneous behavior
user@system:~ ./log_test
hello
hello world
user@system:~ ./log_test: line x: this-will-fail: command not found
./log_test: line x: and-so-will-this: command not found
# <-- cursor blinks here

# erroneous behavior
user@system:~ ./log_test
hello
hello world
./log_test: line x: this-will-fail: command not found
user@system:~
./log_test: line x: and-so-will-this: command not found
# <-- cursor blinks here

# erroneous behavior
user@system:~ ./log_test
hello
hello world
user@system:~
./log_test: line x: this-will-fail: command not found
./log_test: line x: and-so-will-this: command not found
# <-- cursor blinks here

为了好玩，我在脚本末尾放了一个sleep 2，看看会发生什么，问题再也没有发生过。

希望有人知道答案或可以指出正确的方向。

谢谢

编辑

从 Charles Duffy 回答的另一个问题来看，我想要实现的目标在 bash 中是不可能实现的。 Separately redirecting and recombining stderr/stdout without losing ordering

Answer 1

诀窍是确保tee 和运行log 函数的进程替换在整个脚本之前退出——这样当启动的shell脚本打印它的提示，没有任何后台进程可以在它完成后写入更多输出。

作为一个工作示例（尽管一个更注重明确而不是简洁）：

#!/usr/bin/env bash
stdout_log=stdout.log; stderr_log=stderr.log

log () {
  file=$1; shift
  while read -r line; do
    printf '%(%s)T %s\n' -1 "$line"
  done >> "$file"
}

# first, make backups of your original stdout and stderr
exec {stdout_orig_fd}>&1 {stderr_orig_fd}>&2
# for stdout: start your process substitution, record its PID, start tee, record *its* PID
exec {stdout_log_fd}> >(log "$stdout_log"); stdout_log_pid=$!
exec {stdout_tee_fd}> >(tee "/dev/fd/$stdout_log_fd"); stdout_tee_pid=$!
exec {stdout_log_fd}>&- # close stdout_log_fd so the log process can exit when tee does
# for stderr: likewise
exec {stderr_log_fd}> >(log "$stderr_log"); stderr_log_pid=$!
exec {stderr_tee_fd}> >(tee "/dev/fd/$stderr_log_fd" >&2); stderr_tee_pid=$!
exec {stderr_log_fd}>&- # close stderr_log_fd so the log process can exit when tee does
# now actually swap out stdout and stderr for the processes we started
exec 1>&$stdout_tee_fd 2>&$stderr_tee_fd {stdout_tee_fd}>&- {stderr_tee_fd}>&-

# ...do the things you want to log here...
echo "this goes to stdout"; echo "this goes to stderr" >&2

# now, replace the FDs going to tee with the backups...
exec >&"$stdout_orig_fd" 2>&"$stderr_orig_fd"

# ...and wait for the associated processes to exit.
while :; do
  ready_to_exit=1
  for pid_var in stderr_tee_pid stderr_log_pid stdout_tee_pid stdout_log_pid; do
    # kill -0 just checks whether a PID exists; it doesn't actually send a signal
    kill -0 "${!pid_var}" &>/dev/null && ready_to_exit=0
  done
  (( ready_to_exit )) && break
  sleep 0.1 # avoid a busy-loop eating unnecessary CPU by sleeping before next poll
done

---

那么文件描述符操作是怎么回事？

确保我们清楚的几个关键概念：

• 所有子shell 都有自己的文件描述符表副本，这些副本是在它们从父级fork()ed 离开时创建的。从那时起，每个文件描述符表实际上是独立的。
• 从 FIFO（或管道）的（读取端）读取的进程将不会看到 EOF，直到 所有 写入该 FIFO（的写入端）的程序都关闭了它们的副本描述符。

...所以，如果您创建一个 FIFO 对，fork() 关闭子进程，并让子进程写入 FIFO 的写入端，从读取端读取的任何内容都不会看到 EOF，直到没有只有孩子，还有父母，都会关闭他们的副本。

因此，您在这里看到的体操：

• 当我们运行 exec {stdout_log_fd}>&- 时，我们正在关闭 父 shell 的 FIFO 副本写入标准输出的 log 函数，因此唯一剩下的副本是tee 子进程——这样当tee 退出时，运行log 的子shell 也会退出。
• 当我们运行exec 1>&$stdout_tee_fd {stdout_tee_fd}>&- 时，我们正在做两件事：首先，我们将FD 1 作为文件描述符的副本，其编号存储在变量stdout_tee_fd 中；其次，我们从文件描述符表中删除 stdout_tee_fd 条目，因此只保留 FD 1 上的副本。这确保了以后，当我们运行 exec >&"$stdout_orig_fd" 时，我们正在删除 stdout tee 函数的最后一个剩余写入句柄，导致 tee 在 stdin 上获得一个 EOF（因此它退出，从而关闭它持有的句柄在log 函数的子shell 上并让该子shell 退出）。

---

关于流程管理的一些最后说明

不幸的是，bash 处理为进程替换创建的子shell 的方式在仍然积极部署的版本之间发生了很大变化；所以虽然理论上可以使用wait "$pid" 让进程替换退出并收集其退出状态，但这并不总是可靠的——因此使用kill -0。

但是，如果 wait "$pid" 工作，那将是非常可取的，因为 wait() 系统调用是从进程表中删除先前退出进程的条目：保证 PID如果没有发生 wait() 或 waitpid() 调用，则不会被重用（并且僵尸进程表条目将作为占位符）。

现代操作系统非常努力地避免短期 PID 重用，因此在大多数情况下，回绕并不是一个积极的问题。但是，如果您对此感到担心，请考虑使用https://stackoverflow.com/a/31552333/14122 中讨论的基于flock 的机制来等待您的进程替换退出，而不是kill -0。