bash storing the output of set -x to log file

Question

I have a simple download script and I use set -x which works great; I can see each step it performs, and I can identify errors in the script or in the download:

#!/bin/bash
set -x
#short_date=$(/bin/date +%m%d%y)
short_date=$(/bin/date -d "8 day ago" +%m%d%y)
#long_date=$(/bin/date +%Y%m%d)
long_date=$(/bin/date -d "8 day ago" +%Y%m%d)
scp -v -P 1332 -i /home/casper/.ssh/id_rsa_BANK [email protected]:/home/friendly/transfer/out/EXCHANGE_$short_date.csv /local/casper3/dailymetrics/BANK_$long_date.csv

I would like to automate this job. Is there a way I could save the set -x output to a log file? Maybe to one log file - or a different log file for each day. I don't know what would work best.

Below is sample set -x output from the above script.

++ /bin/date +%m%d%y
+ short_date=102814
++ /bin/date +%Y%m%d
+ long_date=20141028
+ scp -v -P 1332 -i /home/casper/.ssh/id_rsa_BANK [email protected]:/home/friendly/transfer/out/EXCHANGE_102814.csv /local/casper3/dailymetrics/BANK_20141028.csv
Executing: program /usr/bin/ssh host 192.168.1.10, user friendly, command scp -v -f /home/friendly/transfer/out/EXCHANGE_102814.csv
OpenSSH_5.3p1, OpenSSL 1.0.0-fips 29 Mar 2010
debug1: Reading configuration data /home/casper/.ssh/config
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Applying options for *
debug1: Connecting to 192.168.1.10 [192.168.1.10] port 7777.
debug1: Connection established.

Yirinec

Which version? With bash 4 you can do this without redirecting all of stderr; with old versions, it's all the same stream. – Intonation

By the way, you might consider something like PS4=':$BASH_SOURCE:$LINENO+' to log the file and line for each command. – Intonation

Take a look at: unix.stackexchange.com/a/155553/74329 – Mcphail

Answer 1

Assuming bash 4, BASH_XTRACEFD can be set to override the file descriptor (by default 2, stderr) to which set -x output is written:

short_date=$(/bin/date +%m%d%y)
exec {BASH_XTRACEFD}>>"$short_date".log
set -x

If running bash 4.0 rather than 4.1 or newer, you have BASH_XTRACEFD but not automatic file descriptor allocation, meaning you'll need to assign one yourself; in the below example, I'm picking file descriptor 100:

short_date=$(/bin/date +%m%d%y)
exec 100>>"$short_date".log
BASH_XTRACEFD=100
set -x

For older releases, your only choice is to redirect all of stderr, rather than only the xtrace stream:

short_date=$(/bin/date +%m%d%y)
exec 2>>"$short_date.log"
set -x

Intonation

Should that be ${BASH_XTRACEFD} or is there a peculiar feature I need to read about? – Swingle

@Alfe, yes, there's a feature at play here -- the automatic file descriptor allocation previously mentioned. Quoting from the redirection section of the bash manual: "Each redirection that may be preceded by a file descriptor number may instead be preceded by a word of the form {varname}. In this case, for each redirection operator except >&- and <&-, the shell will allocate a file descriptor greater than 10 and assign it to {varname}. If >&- or <&- is preceded by {varname}, the value of varname defines the file descriptor to close." – Intonation

It's also possible to use tee to keep a copy on STDERR, as per #3173631. – Freshman

@AdamSpiers, you lose sync between the copy going through tee and the content written directly if you log the traced output to different sinks even if later rejoining it to stderr; thus, using exec {BASH_XTRACEFD}> >(tee xtrace.log >&2) or any equivalent is not something I'd advise. (If you mean to log all stderr output -- both from xtrace and otherwise -- to both a file and console, you don't have that problem). Anyhow, the OP here is asking about logging only xtrace, which is why that's the question I answered. – Intonation

@AdamSpiers, ...POSIX guarantees ordering between writes only if they're to copies of the same FD; as soon as you redirect one but not the other, things get messy. You have the same problem if you try to log stdout and stderr to two different files. – Intonation

(err, log stdout and stderr to two different files, and also to a combined output file or the console). – Intonation

@CharlesDuffy Thanks - yes, I'm aware the OP didn't ask for this, which is why I added it as a comment rather than a new answer. I'm also aware of ordering challenges, e.g. see the end of my answer to the question I linked to. A link to that exact POSIX clause would be helpful though; to me it seems that the ordering difficulties are related to the use of asynchronous coprocesses (which necessitate the use of different FDs). – Freshman

Above was an oversimplification -- there are certainly cases defined by POSIX where it's safe to have two entirely separate handles on the same file appending concurrently (albeit only if O_APPEND is in use, the content being written is in chunks that each fit within a single write() call, and one doesn't otherwise get partial/interrupted writes). – Intonation

@AdamSpiers, ...that said, timestamp-based reassembly is necessarily fragile on account of the issues you've already acknowledged; given a requirement for perfect reconstruction, I'd probably use something like sysdig to record the actual syscalls (with much lower overhead than strace, and a pcap-derived storage format and toolchain surrounding same that lends itself to scripting.). – Intonation

Is >> required? Or can I use exec 100> ... instead? – Bartko

That's all a matter of whether you want to truncate. – Intonation