How do I add a timestamp to every line of a stream?
Adding timestamps to a stream is a challenge, because there aren't any standard tools to do it. You either have to install something specifically for it (e.g. ts from moreutils, or multilog from daemontools), or write a filter in some programming language. Ideally, you do not want to fork a date(1) command for every line of input that you're logging, because it's too slow. You want to use builtins. Older versions of bash cannot do this. You need at least Bash 4.2 for the printf %(...)T option. Otherwise, you could write something in Perl, Python, Tcl, etc. to read lines and write them out with timestamps.
After selecting a program or writing a function -- let's call it stamper -- you can simply pipe your stream through it:
./myprogram 2>&1 | stamper > logfile
Here's a simple timestamper using Bash 4.2, with 1 second resolution:
# Bash 4.2 or later stamper() { while read -r; do printf '%(%Y-%m-%d %H:%M:%S)T %s\n' -1 "$REPLY" done }
You could also use %(%s)T on systems that support %s in strftime(3), for Unix epoch timestamps. Sadly, this is not portable.
Bash 5.0 adds the EPOCHSECONDS (1-second precision) and EPOCHREALTIME (microsecond precision) variables, which may be used instead of (or in addition to) printf %()T:
# Bash 5.0 or later stamper() { while read -r; do printf '%s %s\n' "$EPOCHREALTIME" "$REPLY" done }
One external tool designed specifically for this purpose is ts from the moreutils package. Its default format is poorly chosen (human readable month names, in Mmm DD YYYY format), but you can specify a format. It supports microsecond resolution.
stamper() { ts "%Y-%m-%d %H:%M:%S.%.S" }
Another choice is multilog, with nanosecond resolution:
stamper() { multilog t e 2>&1 }
The e option of multilog tells it to write each line to stderr, instead of to a file in an automatically rotated directory. multilog writes timestamps in TAI64N format, which is similar in nature to Unix epoch format. Use a conversion tool (e.g. tai64nlocal) to make them human-readable.
Here's an example using Tcl, with microsecond resolution:
#!/usr/bin/env tclsh while {[gets stdin line] >= 0} { set now [clock microseconds] set frac [expr {$now % 1000000}] set now [expr {$now / 1000000}] puts "[clock format $now -format {%Y-%m-%d %H:%M:%S}].$frac $line" }
That works best as a separate, standalone script. Embedding it in a bash function is also possible, albeit ugly:
stamper() { tclsh <(cat <<\EOF while {[gets stdin line] >= 0} { set now [clock microseconds] set frac [expr {$now % 1000000}] set now [expr {$now / 1000000}] puts "[clock format $now -format {%Y-%m-%d %H:%M:%S}].$frac $line" } EOF ) }
For perl fans, here's one with 1 second resolution:
stamper() { perl -p -e '$|=1; @l=localtime; printf "%04d-%02d-%02d %02d:%02d:%02d ", 1900+$l[5], $l[4], $l[3], $l[2], $l[1], $l[0]' }
Pick one of these, or write another one (or a better one) in your preferred language.
Now at this point, some readers are going to ask how they can see the unmodified stream while also logging the timestamped stream to a file. Let's say they're not completely insane, so they don't care about separation of stdout and stderr. They just want it all in one file, in order, with stdout and stderr mixed together.
Now, it's somewhat easy to run a script so that its output and stderr go to the screen normally, while timestamped lines go to a logfile:
./myscript 2>&1 | tee >(stamper >logfile)
Putting this same thing inside a script is slightly more involved:
#!/bin/bash exec > >(tee >(stamper >logfile)) 2>&1 while sleep 0.2s; do echo "TPS report $RANDOM" done
And of course, buffering issues may exist, if the parts of the script that write to stamper use stdout buffering. Take that into consideration.
I don't care how slow it is! I want to call date(1) a thousand times a second! My PC doubles as my space-heater!
This is inefficient and horrible.
stamper() { while read -r; do printf '%s %s\n' "$(date +'%Y-%m-%d %H:%M:%S')" "$REPLY" done }
Don't use this. It's stupid. You were warned.