A function mycommand which runs command and:

  • Gives me three log-files which are:
    • *.stdout.log: everything from stdout
    • *.stderr.log: everything from stderr
    • *.full.log: everything (i.e., both stderr and stdout)
  • Prints all output to screen

The idea is that I can quickly see through the errors, skim for additional info in stdout. But in some cases both (stdout and stderr) messages should be seen as one as it gives context, thus I want a third file to do that. For real-time overview I obviously want to see it on my screen too.

This works but it is rather clumsy and doesn't look nice. I'm unsure whether this is the right way to do it or I should improve the code.

The snippet is from my *.*shrc.

mycommand () { command "$@" \
          > >(tee command_"$@"_$(date +%F_%T).stdout.log command_"$@"_$(date +%F_%T).full.log) \
          2> >(tee command_"$@"_$(date +%F).stderr.log command_"$@"_$(date +%F_%T).full.log >&2 ) } \

There are a number of things here which concern me.

First up, the stderr log file does not have the time on the file name (missing _%T). This is a classic copy-paste+partial-fix issue, you copied the same code to multiple places, then needed to fix it, but you only fixed some of them.

The solution to that is to extract the code to just one place, and reuse that:

local basename=command_"$@"_$(date +%F_T)
tee ${basename}.stderr.log

Now, basename is reusable, and if you want to change all three (stderr, stdout, full), then you can change them in just one place.

Your code does not handle complex commands gracefully. What if the command is ls -laR /etc .... how will it save away to log files called:

command_ls -laR /etc_2015-09-22_10:25:30.stdout.log

You need to rationalize that. I started with the spaces and slashes first... using a bash regex/replace for [ \/] to be replaced with an _ underscore.

local command="$@"
local base=command_${command//[ \/]/_}_$(date +%F_%T)

Next up, I am concerned that you have two tee processes both writing to the same "full" file. The one that starts second will overwrite what the first one started with, but I suspect that they will subsequently "merge" the results. It would be better to start a clean file, and then have both tee processes append to the existing file.

I messed around with your function, and came up with:

threepipe () {
    local command="$@"
    local base=rcommand_${command//[ \/]/_}_$(date +%F_%T)
    local both=$base.both.log
    rm -f $both
    touch $both
    $command 2> >(tee -a $both | tee "$base.stderr.log" >&2) | tee -a $both | tee "$base.stdout.log"

Note that only the stderr needs to be handled by the anonymous fifo. The redirect back to stderr keeps it out of the way of the rest of the stdout. Also, note the use of the -a flag for tee.

  • \$\begingroup\$ Wow, this is some shell-magic here! \$\endgroup\$
    – ljrk
    Sep 22 '15 at 14:40
  • \$\begingroup\$ Pressed [enter] too early... I have some questions as I do not understand how this works (though it clearly does and is very elegant!): 1) why did you use | in between the `>( cmd1 | cmd2) in the last line? I didn't and it seemed to work just fine. ---- 2) Also I think the rm -rf shouldn't be needed as I doubt I will execute the command more than once a second - but who knows :D ---- I actually meant "command" just as a place-holder and I planned to hard-code it. But this is much better - thank you! \$\endgroup\$
    – ljrk
    Sep 22 '15 at 14:46
  • \$\begingroup\$ And why did you prepend base with 'rcommand' ? \$\endgroup\$
    – ljrk
    Sep 22 '15 at 14:48
  • \$\begingroup\$ @larkey - if you want, ping me in the 2nd monitor chat room. The explanation of the code is longer than I can put in a comment. \$\endgroup\$
    – rolfl
    Sep 22 '15 at 17:06

I'm not going to answer your question as you asked it, but I'm going to suggest something that might be just what you are looking for.

The solution in question is the utility annotate-output. It is included in devscripts.

You use it like so:

annotate-output command

All output from command (stderr + stdout) is displayed on stdout. It appears something like this:

$ annotate-output make
21:41:21 I: Started make
21:41:21 O: gcc -Wall program.c
21:43:18 E: program.c: Couldn't compile, and took me ages to find out
21:43:19 E: collect2: ld returned 1 exit status
21:43:19 E: make: *** [all] Error 1
21:43:19 I: Finished with exitcode 2

Note that every line is timestamped and prepended with O for stdout and E for stderr. I don't know if this will work for you, but I've found it to be a very helpful alternative to the hackish stuff you're contemplating. Also, the timestamp format is adjustable. Here is the alias I use... It includes milliseconds at the end.

alias annotate="annotate-output '+%Y-%m-%d %T.%3N'"
  • \$\begingroup\$ It's definitely useful, thanks! I wanted stderr and stdout to also be in seperate files to have less to skim through and not get overwhelmed by the mass of (partly unrelated) messages. I think one could even extend this via awk/grep to find stdout and stderr files which then are written to 2 stdout and stderr files too. Definitely useful, thanks :-) \$\endgroup\$
    – ljrk
    Sep 27 '15 at 6:29

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.