9

I am trying to apply timestamps to stdout of a process. For the proper timestamps to be applied, I attempt to unbuffer stdout of the process. This works with unbuffer but not with stdbuf as I would expect. Consider the following slow printing script 'slowprint':

#!/bin/bash

if [ $# -ne 2 ]; then
   echo "usage: ${0%%/*} <file> <delay in microseconds>"
   exit 1
fi

DELAY=$2 perl -pe 'BEGIN{use Time::HiRes qw(usleep)} { usleep($ENV{DELAY}) }' $

now compare the following attempts to apply timestamps:

stdbuf -oL ./slowprint <(ls) 100000 | 
awk '{ print strftime("%H:%M:%S"), $0; fflush(); }'

vs

unbuffer ./slowprint <(ls) 100000 | 
awk '{ print strftime("%H:%M:%S"), $0; fflush(); }'

The second one works for me while the first one doesn't, though I expect them to do the same thing. Currently unbuffer is unsuitable because it swallows error codes in certain circumstances, (I posted a separate question about that behavior).

agc
  • 636
  • 5
  • 16
frankc
  • 311

2 Answers2

2

Try annotate-output. It provides timestamps for STDIN, STDOUT, and STDERR.

An example, use wc to do a line count of a bash process substitution, (one line), and a nonexistent file:

annotate-output wc -l <(echo foo) nosuchfile

Output:

10:17:45 I: Started wc -l /dev/fd/63 nosuchfile
10:17:45 O:       1 /dev/fd/63
10:17:45 E: wc: nosuchfile: No such file or directory
10:17:45 O:       1 total
10:17:45 I: Finished with exitcode 1
agc
  • 636
  • 5
  • 16
1

I believe the difference lies in the underlying machinery:

  • stdbuf uses LD_PRELOAD to load a shared library that uses the __attribute__((constructor)) annotation for a function inside it, causing it to run this function's code before main. That function in turn, uses the setvbuf functionality of libc to configure the buffers used for stdin, stdout and stderr at startup. Nothing stops the application to then undo this because it does its own setvbuf-ing. I believe perl does this, which is why your use of stdbuf is ignored.

  • unbuffer works in a different way - it uses the kernel to create a pseudo-tty, thus making the application think that its stdout isatty; and therefore libc's behavior defaults to line-buffered output.

ttsiodras
  • 648