Tuesday, March 15, 2022

[SOLVED] Log command line plus its output in a bash script

Issue

Is there a way for a script to log both, the command line run (including piped ones) plus its output without duplicating the line for the command?

The intention is that the script should have a clean output, but should log verbosely into a log file (so no set -x). Apart from the output, it shall also log the command line causing the output, which could be a piped command-one liner.

The most basic approach is to duplicate the command line in the script and then dump it into the log followed by the captured output of the actual command being run:

echo "command argument1 \"quoted argument2\" | grep -oE \"some output\"" >> file.log
output="$(command argument1 "quoted argument2" 2>&1 | grep -oE "some output")"
echo "${output}" >> file.log

This has the side effect that quoted sections would need to be escaped for the log, which can lead to errors resulting in confusion.

If none of the commands were piped, one could store the command line in an array and then "run" the array.

command=(command argument1 "quoted argument2")
echo "${command[@]}" >> file.log
output="$("${command[@]}" 2>&1)"
echo "${output}" >> file.log

Though with this approach "quoted argument2" would become quoted argument2 in the log.

Is there a way (in bash) to realize this without having to duplicate the commands?


Solution

You could play with redirections, switch the x option on and off on demand, unset PS4 to get rid of the leading + , and define log_on and log_off functions for easier coding. Something like this:

$ cat script.sh
#!/usr/bin/env bash

function log_on {
  exec 3>&1 4>&2
  exec &> >( sed -E '/^(set \+x|log_off)$/d' >> file.log )
  ps4=$PS4
  PS4=
  set -x
}

function log_off {
  set +x
  exec 1>&3 2>&4
  PS4=$ps4
}

echo something not logged
log_on
echo something logged
log_off
echo something else not logged
$ rm -f file.log
$ ./script.sh
something not logged
something else not logged
$ cat file.log
echo something logged
something logged

The exec <redirection> commands look a bit cryptic (as most redirections) but they are rather simple:

  • exec 3>&1 4>&2 makes copies of file descriptors fd1 and fd2 (stdout and stderr by default) to be able to restore these in log_off. After this fd3 and fd4 are copies of fd1 and fd2, respectively. Pick other fd than 3 or 4 if you already use them.

  • exec &> >( sed ... ) redirect fd1 and fd2 to the standard input of a sed command.

  • The sed command sed -E '/^(set \+x|log_off)$/d' >> file.log deletes lines containing only set + or log_off and appends its output to file.log. Without this sed command you would always see the two following lines:

      log_off
      set +x
    

    in your logs, after a group of logged commands.

  • exec 1>&3 2>&4 restores fd1 and fd2 from their copies in fd3 and fd4.

The rest is straightforward: save PS4 in ps4 such that it can be restored, enable/disable the x option. This should be easy to adapt or extend if needed.

The x option displays the simple commands separately. It breaks pipes, for instance. If you prefer a command log that looks more like the commands you wrote you can replace set -/+x by set -/+v.



Answered By - Renaud Pacalet
Answer Checked By - Candace Johnson (WPSolving Volunteer)