Pipe ssh's output (stderr and stdout) to different commands

Question

I'm a writing script for some kind of backup involving ssh and rsync. Every time that script runs I redirect all output to a log file. To standardize the log-entries I wrote a log-function that adds a timestamp and log-level. My idea was to also read the stdout and stderr of each command line by line and call that log-function. Therefor I followed the answers from https://serverfault.com/questions/526592/pipe-stderr-and-stdout-to-different-commands-not-just-to-files.

My script looks like this (it's reduced, assume all used vars are set properly):

#!/bin/bash

# function: print a formatted log message including timestamp with given level and message to stdout 
# arguments: <LEVEL> <MESSAGE>
log()
{
    timestamp=$(date +"%F %T.%3N")
    level=$1
    message=$2
    echo $timestamp $level: $message
}

# function: read command output from stdin and log it with given level
# arguments: <LEVEL>
logoutput()
{
    sed 1d | \
    while read i
    do
        log "$1" "$i"
    done
}

log INFO "START ssh"
(ssh $connection mkdir -p $destStaticDirectory | logoutput INFO) 3>&1 1>&2 2>&3 | logoutput ERROR

log INFO "START rsync"
(rsync $rsyncArguments $linkDest $fromDirectory $connection:$destStaticDirectory | logoutput INFO) 3>&1 1>&2 2>&3 | logoutput ERROR

The function log() is used to echo a log entry and the function logoutput() is used to read stdout line by line and log each.

Now the thing is everything works as expectet for the rsync-command. But not for the ssh-command. I know there is no output to stdout when calling ssh $connection mkdir -p $destStaticDirectory correctly. So I tested it by letting ssh connect to an an unkown host which results in ssh: Could not resolve hostname XXX: Name or service not known. But again nothing. I also added the same ssh-command "unwrapped" to the script which prints all output as expected. Finally I switched on ssh's verbose mode which resulted in error-log-entries. But that's not an option as I dont't want ssh's bebug messages in my log.

Am I missing something? Is there same strange stdout,err handling ssh is doing I'm not aware of? I hope I made myself clear what I'm trying to do.

Answer 1

Your problem is most likely in the logoutput function where "sed 1d" removes the output you are looking for. Try to remove the line "sed 1d" and see if your script behaves as expected.

Answer 2

Have you considerd using logger(1) to do the logging for you and add timestamps etc.

Then something like

{ ssh ... | logger ...; }  2>&1 | logger ...

should to what you want as the first part sends stdout to a log file via logger and the second part send stderr to a log file. You can use the logger command line options to select which log facility or file etc.

---

There is a neater way of doing this too. Use Process Substitution e.g.

ssh ... > >(logger ...) 2> >(logger ...)

This saves having to messa around with all the file descriptors.