317

I wish to prepend a timestamp to each line of output from a command. For example:

foo
bar
baz

would become

[2011-12-13 12:20:38] foo
[2011-12-13 12:21:32] bar
[2011-12-13 12:22:20] baz

...where the time being prefixed is the time at which the line was printed. How can I achieve this?

1

10 Answers 10

463
+50

moreutils includes ts which does this quite nicely:

command | ts '[%Y-%m-%d %H:%M:%S]'

It eliminates the need for a loop too, every line of output will have a timestamp put on it.

$ echo -e "foo\nbar\nbaz" | ts '[%Y-%m-%d %H:%M:%S]'
[2011-12-13 22:07:03] foo
[2011-12-13 22:07:03] bar
[2011-12-13 22:07:03] baz

You want to know when that server came back up you restarted? Just run ping | ts , problem solved :D.

Note: Use [%Y-%m-%d %H:%M:%.S] for microsecond precision.

12
  • 22
    How have I not known about this?!?!?! This complements tail -f amazingly! tail -f /tmp/script.results.txt | ts Mar 5, 2015 at 22:51
  • 5
    if I don't have ts command, what should I use?
    – ekassis
    Jan 16, 2017 at 11:48
  • 4
    If it's not working, try redirecting stderr to stdout e.g. ssh -v 127.0.0.1 2>&1 | ts
    – jchook
    Mar 20, 2017 at 19:02
  • 5
    Install by doing sudo apt install moreutils on Debian and yum install moreutils on Fedora. Jun 19, 2018 at 18:21
  • 13
    I think pointing out the parameter -s is useful. As that displays the runtime of the command. I personally like using both ts and ts -s at the same time. Looks something like this: command | ts -s '(%H:%M:%.S)]' | ts '[%Y-%m-%d %H:%M:%S'. This prepends the log lines like this: [2018-12-04 08:31:00 (00:26:28.267126)] Hai <3
    – BrainStone
    Dec 4, 2018 at 9:03
167

Firstly, if you are expecting these timestamps to actually represent an event, bear in mind that since many programs perform line buffering (some more aggressively than others), it is important to think of this as close to the time that the original line would have been printed rather than a timestamp of an action taking place.

You may also want to check that your command doesn't already have an inbuilt feature dedicated to doing this. As an example, ping -D exists in some ping versions, and prints the time since the Unix epoch before each line. If your command does not contain its own method, however, there are a few methods and tools that can be employed, amongst others:

POSIX shell

Bear in mind that since many shells store their strings internally as cstrings, if the input contains the null character (\0), it may cause the line to end prematurely.

command | while IFS= read -r line; do printf '[%s] %s\n' "$(date '+%Y-%m-%d %H:%M:%S')" "$line"; done

GNU awk

command | gawk '{ print strftime("[%Y-%m-%d %H:%M:%S]"), $0 }'

Perl

command | perl -pe 'use POSIX strftime; print strftime "[%Y-%m-%d %H:%M:%S] ", localtime'

Python

command | python -c 'import sys,time;sys.stdout.write("".join(( " ".join((time.strftime("[%Y-%m-%d %H:%M:%S]", time.localtime()), line)) for line in sys.stdin )))'

Ruby

command | ruby -pe 'print Time.now.strftime("[%Y-%m-%d %H:%M:%S] ")'
7
  • 4
    One problem here is that many programs turn on even more output buffering when their stdout is a pipe instead of the terminal.
    – cjm
    Dec 13, 2011 at 18:02
  • 5
    @cjm - True. Some output buffering can be alleviated by using stdbuf -o 0, but if the program is manually handling its output buffering, it won't help (unless there is an option to disable/reduce the size of the output buffer).
    – Chris Down
    Dec 13, 2011 at 22:46
  • 4
    For python, you can disable line buffering with python -u
    – ibizaman
    Nov 21, 2016 at 22:01
  • @Bwmat No. ... for x in sys.stdin iterates over lines without buffering them all into memory first.
    – Chris Down
    Dec 26, 2016 at 12:36
  • Do this and you get buffering... for a in 1 1 1 1 1; do sleep 1; echo; done | python -c 'import sys,time;sys.stdout.write("".join(( " ".join((time.strftime("[%Y-%m-%d %H:%M:%S]", time.gmtime()), line)) for line in sys.stdin )))' Jan 4, 2018 at 0:06
63

For a line-by-line delta measurement, try gnomon.

It is a command line utility, a bit like moreutils's ts, to prepend timestamp information to the standard output of another command. Useful for long-running processes where you'd like a historical record of what's taking so long.

Piping anything to gnomon will prepend a timestamp to each line, indicating how long that line was the last line in the buffer--that is, how long it took the next line to appear. By default, gnomon will display the seconds elapsed between each line, but that is configurable.

gnomon demo

1
  • 4
    Looks like a great alternative to ts when using live processes. While ts is better suited for non-interactive processes.
    – BrainStone
    Dec 4, 2018 at 9:05
9

I would have preferred to comment above but I can't, reputationally. Anyway, the Perl sample above can be unbuffered as follows:

command | perl -pe 'use POSIX strftime; 
                    $|=1; 
                    select((select(STDERR), $| = 1)[0]);
                    print strftime "[%Y-%m-%d %H:%M:%S] ", localtime'

The first '$|' unbuffers STDOUT. The second one sets stderr as the current default output channel and unbuffers it. Since select returns the original setting of $|, by wrapping the select inside a select, we also reset $| to its default, STDOUT.

And yes, you can cut 'n paste as is. I multi-lined it for legibility.

And if you really want to get precise (and you have Time::Hires installed):

command | perl -pe 'use POSIX strftime; use Time::HiRes gettimeofday;
                    $|=1; 
                    select((select(STDERR), $| = 1)[0]);
                    ($s,$ms)=gettimeofday();
                    $ms=substr(q(000000) . $ms,-6);
                    print strftime "[%Y-%m-%d %H:%M:%S.$ms]", localtime($s)'
1
  • 3
    Works like a charm, without having to install any non-standard packages.
    – Jay Taylor
    Oct 18, 2018 at 20:53
7

Ryan's post does provide an interesting idea, however, it fails in several regards. While testing with tail -f /var/log/syslog | xargs -L 1 echo $(date +'[%Y-%m-%d %H:%M:%S]') $1 , I noticed that timestamp stays the same even if stdout comes later with difference in seconds apart. Consider this output:

[2016-07-14 01:44:25] Jul 14 01:44:32 eagle dhclient[16091]: DHCPREQUEST of 192.168.0.78 on wlan7 to 255.255.255.255 port 67 (xid=0x411b8c21)
[2016-07-14 01:44:25] Jul 14 01:44:34 eagle avahi-daemon[740]: Joining mDNS multicast group on interface wlan7.IPv6 with address fe80::d253:49ff:fe3d:53fd.
[2016-07-14 01:44:25] Jul 14 01:44:34 eagle avahi-daemon[740]: New relevant interface wlan7.IPv6 for mDNS.

My proposed solution is similar, however provides proper time-stamping and uses somewhat more portable printf rather than echo

| xargs -L 1 bash  -c 'printf "[%s] %s\n" "$(date +%Y-%m-%d\ %H:%M:%S )" "$*" ' bash

Why bash -c '...' bash ? Because due to -c option, first argument gets assigned to $0 and won't show up in the output. Consult your shell's manual page for the proper description of -c

Testing this solution with tail -f /var/log/syslog and (as you probably could guess) disconnecting and reconnecting to my wifi, has shown the proper time-stamping provided by both date and syslog messages

Bash could be replaced by any bourne-like shell, could be done with either ksh or dash , at least those that have -c option.

Potential issues:

The solution requires having xargs ,which is available on POSIX compliant systems, so most Unix-like systems should be covered. Obviously won't work if your system is non-POSIX compliant or doesn't have GNU findutils

6

Most of answers suggest to use date, but it's slow enough. If your bash version is greater than 4.2.0 it's better to use printf instead, it's a bash builtin. If you need to support legacy bash versions you can create log function depends on bash version:

TIMESTAMP_FORMAT='%Y-%m-%dT%H:%M:%S'
# Bash version in numbers like 4003046, where 4 is major version, 003 is minor, 046 is subminor.
printf -v BV '%d%03d%03d' ${BASH_VERSINFO[0]} ${BASH_VERSINFO[1]} ${BASH_VERSINFO[2]}
if ((BV > 4002000)); then
log() {
    ## Fast (builtin) but sec is min sample for most implementations
    printf "%(${TIMESTAMP_FORMAT})T %5d %s\n" '-1' $$ "$*"  # %b convert escapes, %s print as is
}
else
log() {
    ## Slow (subshell, date) but support nanoseconds and legacy bash versions
    echo "$(date +"${TIMESTAMP_FORMAT}") $$ $*"
}
fi

See speed differences:

user@host:~$time for i in {1..10000}; do printf "%(${TIMESTAMP_FORMAT})T %s\n" '-1' "Some text" >/dev/null; done

real    0m0.410s
user    0m0.272s
sys     0m0.096s
user@host:~$time for i in {1..10000}; do echo "$(date +"${TIMESTAMP_FORMAT}") Some text" >/dev/null; done

real    0m27.377s
user    0m1.404s
sys     0m5.432s

UPD: instead of $(date +"${TIMESTAMP_FORMAT}") it's better to use $(exec date +"${TIMESTAMP_FORMAT}") or even $(exec -c date +"${TIMESTAMP_FORMAT}") too speedup execution.

UPD2: bash 5 provides EPOCHREALTIME variable for microseconds granularity, you can use it by this command (about 30% slower than seconds only): printf "%(${TIMESTAMP_FORMAT})T.%s %5d %s\n" ${EPOCHREALTIME/./ } $$ "$*"

3
  • This answer is very underrated! Particularly nice to show the relative performance impact. Oct 5, 2020 at 17:39
  • Excellent suggestion, but unfortunately date does not provide sub-second resolution, which is a requirement in my case Feb 8, 2021 at 18:11
  • 1
    With bash 5.0+ you can use this command: printf "%(${TIMESTAMP_FORMAT})T.%s %5d %s\n" ${EPOCHREALTIME/./ } $$ "$*"
    – Mikhail
    Feb 9, 2021 at 13:07
5

Shameless plug for something I just wrote to solve this exact problem: ets, written in Go.

demo

You can find a lot of usage examples on the project page.

The notable difference from existing answers and similar offerings is that ets is designed to run your command for you, in a pty (pseudo tty) — that is to say, simulating your command running natively in a tty. Compared to piping command output into e.g. ts, this makes timestamping mostly transparent, and solves a bunch of issues of piping:

  • Some programs aggressively buffer when writing to a pipe, so you see no output and then a whole bunch of output (yeah, you can stdbuf them, you can even wrap stdbuf and ts in an alias/function, but wouldn't it be better if things work out of the box);
  • Some programs disable color and/or interactivity when writing to a pipe;
  • Exit status is gone unless you turned on pipefail; etc.

Commands can be directly exec'ed, meaning you can simply prepend ets to your existing command line, or they can be shell commands (as shown in the gif above). Of course, if you want to pipe output in, ets can do that too.

ets supports the same timestamp modes as moreutils ts: absolute time mode, elapsed time mode, and incremental time mode. It uses saner defaults (e.g. monotonic clock is always used for elapsed/incremental timestamps) and has additional support for custom time zones. There's a detailed comparison here.

Again, https://github.com/zmwangx/ets. Give it a spin, report bugs, etc.

4

You can do this with date and xargs:

... | xargs -L 1 echo `date +'[%Y-%m-%d %H:%M:%S]'` $1

Explanation:

xargs -L 1 tells xargs to run the proceeding command for every 1 line of input, and it passes in the first line as it does so. echo `date +'[%Y-%m-%d %H:%M:%S]'` $1 basically echoes the date with the input argument at the end of it

2
  • 2
    The solution is close, but doesn't timestamp properly when it comes to output separated by long periods of time. Also , you're using backticks and haven't quoted $1 . That's not good style. Always quote the variables. In addition, you're using echo , which is not portable . It's alright, but may not properly work on some systems. Jul 14, 2016 at 7:56
  • After testing this, it appears you're absolutely right... do you know of any way to make date get reevaluated every line, or is it pretty much hopeless?
    – Ryan
    Jul 18, 2016 at 1:14
1

If you are working in bash, put this near the start of your script

exec &> >( ts '%Y-%m-%d.%H%M.%.S ' )  # prepend a timestamp to all output

Or, for extra credit, output to log file via:

script_name=foobar
log_file=$( printf "/tmp/${script_name}-%(%Y-%m-%d)T.%(%H%M%S)T.log" -1 )
echo "note: redirecting output to [${log_file}]"
exec &> >( ts '%Y-%m-%d %H:%M:%.S ' > ${log_file} )

to output to both console and log file:

script_name=foobar
log_file=$( printf "/tmp/${script_name}-%(%Y-%m-%d)T.%(%H%M%S)T.log" -1 )
exec &> >( ts '%Y-%m-%d %H:%M:%.S ' | tee ${log_file} )

The main advantages of doing this are to separate the logging from everything else, not cluttering the body of the script by piping to tee or similar on every command, and not having to write custom logging functions and sticking to plain old echo and printf.

The ts program is found in the moreutils package, which should be readily available under any reasonably sane administration regime. :-)

0

No need for big 3rd-party packages, or kooky new languages, and no need to fork an entire shell and interpreter for every line of stdout that comes your way. I'm an adult -- my interpreter is the CPU:

/*
 * Redirect stdin to stdout, prepending a millisecond-precision
 * Unix timestamp to each line.
 */
#include <stdio.h>
#include <sys/time.h>

int main(int argc, char *argv[]) {
   char *line = NULL;
   size_t linecap = 0;
   ssize_t linelen;
   struct timeval tv;

   while ((linelen = getline(&line, &linecap, stdin)) > 0) {
      gettimeofday(&tv, NULL);
      fprintf(stdout, "%lu ", tv.tv_sec*1000 + tv.tv_usec/1000);
      fwrite(line, linelen, 1, stdout);
   }
}

Paste the above code into a .c file. I call mine tsms.c. Then

gcc -o tsms tsms.c

and then

command | tsms

and you can be a big boy too.

Your Answer

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