3

I'm working on a wrapper script to log cronjob output to journald.

I have several goals:

  • must log stderr and stdout to journald with different priority levels and prefix-tags
  • must also output stderr of the wrapped command to stderr of the wrapper script (to be caught by cron and emailed in an alert)
  • must preserve line order throughout

So far I seem to have two problems:

  1. I'm not sure how to redirect stderr and stdout separately to my logging function. Everything I've tried thus far fails to redirect anything more than NULL. In my defense, redirection is not one of my strong points. (Resolved, see comments)
  2. My current approach { $_EXEC $_ARGS 2>&1 1>&7 7>&- | journaldlog error; } 7>&1 1>&2 | journaldlog info appears to run the logging function exactly twice, once for stderr and once for stdout. This will not preserve line order. I would rather it run the function once per output line.

Should I just give up on doing this in bash and try Perl instead? I'm sure my Perl experience would come back to me... eventually.

I've tried a lot of different approaches. Most of which found online and, in particular, on stack exchange. I honestly can't remember what else I've tried... it's just a blur at this point. And the bash docs haven't been much help either.

  • I've updated the gist. I've resolved the issue with the function receiving NULL as it's second parameter. Turns out I misunderstood the docs and can't use params for this. I'm now using $(cat) to read stdin in the function. – Cliff Armstrong Jan 21 '18 at 23:49
5

You can just use process substitution directly in the redirections:

gen > >(one) 2> >(two)

That will give the standard output of gen as the standard input to one and the standard error of gen as the input to two. Those could be executable commands or functions; here are the functions I used:

one() {
    while read line
    do
        echo $'\e[31m'"$line"$'\e[22m'
    done
}

two() {
    while read line
    do
        echo $'\e[32m'"$line"$'\e[22m'
        echo "$line" >&2
    done
}

They output their input lines in red and green respectively, and two also writes to ordinary standard error. You could do whatever you wanted inside the loops, or send the input on to another program or whatever you required.


Note that there's not really any such thing as "preserving line order" once you're at this point - they're two separate streams and separate processes, and it's quite possible that the scheduler runs one process for a while before it gives the other one a go, with the data kept in the kernel pipe buffer until it's read. I've been using a function outputting odd numbers to stdout and even to stderr to test with, and it's common to get a run of a dozen or more in a row from each.

It would be possible to get something closer to the ordering as it appears in the terminal, but probably not in Bash. A C program using pipe and select could reconstruct an ordering (though still not guaranteed to be the same as displayed, for the same reason: your process might not be scheduled for a while and once there's a backlog, there's no telling what came first1). If the ordering is vitally important you'll need another approach, and likely the coöperation of the base executable. If it's a hard requirement you may need to reconsider.

1There may also be platform-specific methods for controlling the pipe buffering, but they're unlikely to help you enough either. On Linux, you can shrink the buffer size as low as the system page size but no lower. I don't know of one that lets you force writes through immediately (or blocks until they're read). In any case, they could well be buffered on the source end in the fashion of stdio streams and then you'd never see an ordering.

  • The issue here is if I have... say... a mailer daemon log, and I have 5 messages saying user connected from x.x.x.x or whatever. But then I have an error that says unreadable data or some such... it would be really helpful to know which of those connections the "unreadable data" is closest to when debugging. If I can't even remotely count on related error and non-error output to be close to each other then I'm losing a significant tool in my problem-solving toolkit. For that matter, how does the terminal/shell/cron manage this? Aren't they working with the same output? – Cliff Armstrong Jan 25 '18 at 7:24
  • 1
    Writes to one file are ordered; writes to two different pipes read by two different processes aren’t (usefully). Your tool was lost as soon as you split them up. – Michael Homer Jan 25 '18 at 7:30
  • But you're saying this can't be done even in a language that is compiled to machine code. That it's fundamentally impossible to spawn another application as a child process and read that child process' stdout and stderr in a predictable order... but then you say writing to a single file is ordered. What's doing the writing? Magic? There is a miscommunication here. Cause what I'm understanding you to say is self-contradictory. – Cliff Armstrong Jan 25 '18 at 7:45
  • 1
    If standard error and standard output are the same file, they are the same file. Two writes to the same file are ordered, or else files would be useless. If they are not the same file, they are different files with no relationship to each other. When you read from two different files there is no connection between what you get from one and the other, and when you do anything in two different processes there is no fixed ordering of events between them. – Michael Homer Jan 25 '18 at 7:56
  • 1
    Standard input and standard output are the files in question. If you want them separated, you want two files, one for each; if they’re going to the (same) TTY, they’re both one and the same. If you don’t want them separated this is all much easier, but it’s definitely been my reading of the question & your code that you did. I’m not really interested in continuing this, so good luck with solving your problem. You might want to ask another question that’s more fine-grained if you have something else in mind. – Michael Homer Jan 25 '18 at 8:23
1

Here is what I am using to redirect separately stderr and stdout to a function:

tag() { awk '$0="['$1'] "$0; fflush();' ; }

{
    {
        echo std1; sleep 0.1;
        echo error2 >&2; sleep 0.1;
        echo error3 >&2; sleep 0.1;
        echo std4; sleep 0.1;
    } 2>&1 1>&3 | tag STDERR 1>&2 ;
} 3>&1 | tag STDOUT 3>&- ;

This should give the following output:

[STDOUT] std1
[STDERR] error2
[STDERR] error3
[STDOUT] std4

It works for me in bash and ksh (93u+).

Note that I add "sleep 0.1" between command in order to preserve line order in that case.

1

This is one way of capturing stdout and stderr to different command pipelines.

#!/bin/bash
#
exec 3>&1 4>&2

loggerForStdout() {
    # FD 3 is the original stdout
    local x
    while IFS= read -r x; do printf "STDOUT\t%s\n" "$x"; done >&3
}
loggerForStderr() {
    # FD 4 is the original stderr
    local x
    while IFS= read -r x; do printf "STDERR\t%s\n" "$x"; done >&4
}


( (
    # This is where your command would be put
    # e.g. stdbuf -oL -eL rsync -a /from /to
    #
    echo this is stdout; echo this is stderr >&2

) | loggerForStdout ) 2>&1 | loggerForStderr

I'm not entirely sure whether it's possible to guarantee interleaved line ordering even with stdbuf -oL -eL.

You can omit the first three lines if you have alternative loggers. They exist only so that the code is a complete and self-contained example.

  • Doesn't seem to work at all in my case. logger-for-stout doesn't get executed. And logger-for-stderr is passed NULL as STDIN inspite of me resolving that issue elsewhere. I updated the gist to show how I implemented your suggestion (currently commented out). Perhaps you can explain where I went wrong? – Cliff Armstrong Jan 21 '18 at 23:46
  • @CliffArmstrong my mistake. I changed the code I'd used for my initial test, thinking that it was a cleaner solution. Cleaner it might have been, but broken it was, too. I've removed the redirection of stdout after 2>&3. Please try that. – roaima Jan 22 '18 at 10:07
  • In my tests, this is stdout was also being sent to logger-for-stderr. The fix for that is to use /dev/tty instead of just echoing to stdout without redirections. – Sergiy Kolodyazhnyy Mar 11 at 9:12
  • @SergiyKolodyazhnyy thank you for that. I've revisited the code and I believe the result is shorter and cleaner than my original. (And as accurate as yours.) – roaima Mar 11 at 12:26

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.