41

I have a program (server) and I am looking for a way (script) that will redirect (or better duplicate) all its stdout to file and add timestamp for each entry.

I've done some research and the furthest I could get was thanks to How to add timestamp to STDERR redirection. It redirects stdout but the timestamp added is of the time when the script finishes:

#!/bin/bash
./server | ./predate.sh > log.txt

code of predate.sh:

#!/bin/bash
while read line ; do
    echo "$(date): ${line}"
done

It seems that server output is flushed after exit of the program.(without redirecting it works fine). Also if I try using predate.sh on given example in mentioned thread, it works perfectly. I am aware it would be easy adding a timestamp to the main program but I would rather avoid editing its code.

11
  • 2
    So the problem is that all the timestamps are the same and the time when the script finished? Sounds like this is a problem with server output not being properly buffered. stackoverflow.com/questions/3465619/… might be what you are looking for
    – Graeme
    Jan 13, 2014 at 18:40
  • Pipe the output to awk. It provides a function called strftime.
    – devnull
    Jan 13, 2014 at 19:01
  • 1
    The expect distribution comes with a program called unbuffer : unbuffer ./server | ./predate.sh > log.txt Jan 13, 2014 at 19:02
  • 2
    Also see man stdbuf.
    – devnull
    Jan 13, 2014 at 19:04
  • What do you get if you try Dennis's solution in the linked question? e.g. ./server.sh > >( ./predate.sh > log.txt ) Jan 13, 2014 at 20:00

5 Answers 5

56

I recently needed exactly that: receive log messages in a serial console (picocom), print them to a terminal and to a file AND prepend the date.

What I now use looks s.th. like this:

picocom -b 115200 /dev/tty.usbserial-1a122C | awk '{ print strftime("%s: "), $0; fflush(); }' | tee serial.txt
  • the output of picocom is piped to awk
  • awk prepends the date (the %s option converts the time to the Number of seconds since 1970-01-01 00:00:00 UTC - or use %c for a human-readable format)
  • fflush() flushes any buffered output in awk
  • that is piped to tee which diverts it to a file. (you can find some stuff about tee here)
8
  • 11
    Thank you very much for this. I'd like to add to anyone using this, to print a timestamp similar "2015-11-13 17:04:57:" the pattern is "%Y-%m-%d %H:%M:%S:".
    – lm2s
    Nov 13, 2015 at 17:07
  • 3
    Awk, ever to the rescue.
    – macetw
    Dec 11, 2015 at 15:09
  • 2
    This is the only output for me: awk: line 2: function strftime never defined
    – ygoe
    Jun 10, 2017 at 20:32
  • @ygoe, what version of awk are you using?
    – mwfearnley
    Jun 27, 2017 at 10:59
  • 3
    maybe install gawk first: stackoverflow.com/questions/3684212/…
    – Mladen B.
    Jan 15, 2018 at 9:03
30

moreutils ts

Absolute date and time is the default:

$ sudo apt-get install moreutils
$ (echo a;sleep 1;echo b;sleep 3;echo c;sleep 2;echo d;sleep 1) | ts | tee myfile
$ cat myfile
Apr 13 03:10:44 a
Apr 13 03:10:45 b
Apr 13 03:10:48 c
Apr 13 03:10:50 d

or counting from program start with ts -s:

$ (echo a; sleep 1; echo b; sleep 3; echo c; sleep 2; echo d; sleep 1) | ts -s
00:00:00 a
00:00:01 b
00:00:04 c
00:00:06 d    

or deltas for benchmarking with ts -i:

$ (echo a; sleep 1; echo b; sleep 3; echo c; sleep 2; echo d; sleep 1) | ts -i
00:00:00 a
00:00:01 b
00:00:03 c
00:00:02 d
$ (echo a; sleep 1; echo b; sleep 3; echo c; sleep 2; echo d; sleep 1) | ts -i '%.s'
0.000010 a
0.983308 b
3.001129 c
2.001120 d

See also: How to monitor for how much time each line of stdout was the last output line in Bash for benchmarking?

Tested on Ubuntu 18.04, moreutils 0.60.

10

For Me Your Code is working perfectly fine

Check this is what I tried

test.sh

#!/bin/bash

while true; do
  echo "hello"
done

predate.sh

#!/bin/bash

while read line; do
  echo $(date) ":" $line;    
done

then

./test.sh  | ./predate.sh

gives me

Tue Jan 14 17:49:47 IST 2014 : hello
Tue Jan 14 17:49:47 IST 2014 : hello
Tue Jan 14 17:49:47 IST 2014 : hello
Tue Jan 14 17:49:47 IST 2014 : hello
Tue Jan 14 17:49:47 IST 2014 : hello
Tue Jan 14 17:49:47 IST 2014 : hello
Tue Jan 14 17:49:47 IST 2014 : hello
Tue Jan 14 17:49:47 IST 2014 : hello
Tue Jan 14 17:49:47 IST 2014 : hello
Tue Jan 14 17:49:47 IST 2014 : hello
Tue Jan 14 17:49:47 IST 2014 : hello
Tue Jan 14 17:49:47 IST 2014 : hello
Tue Jan 14 17:49:47 IST 2014 : hello
Tue Jan 14 17:49:47 IST 2014 : hello
Tue Jan 14 17:49:47 IST 2014 : hello

This can be redirected to some file using ">" or ">>" for append

Check Snapshot

2
  • 1
    If you read my question carefully - this works. Stdout of script wroked for me but stdout of program did not(strange). I needed stdout of program. The issue is more complicated then simply redirecting output - output of program was fushed at once after it ended.
    – wondra
    Jan 15, 2014 at 15:47
  • Formatting is lost: I struggled to get formatting correct and ended up with this function predate () { tr "\n" "\0" | xargs -0 -I{} echo "$(date) : {}"; } (Note this still does not answer the question). Jan 24, 2017 at 9:19
1

Again, using ts from moreutils, you can just use exec at the top of your script.

#!/bin/bash

exec > >(ts>>file.log)

echo hello 1
echo hello 2
sleep 5
echo hello 3
-2

If I understand your problem is to have stderr output included in your log.txt file. Right ? If that's what you want the solution is:

./server 2>&1 | ./predate.sh > log.txt

Regards

3
  • Maybe your server is executed too quickly... Try to print nanoseconds as follows and check the difference: echo "$(date +%T.%N): ${line}"
    – HelpBox
    Jan 13, 2014 at 21:00
  • I have function for turning off server which take 25 second, believe me - I would notice...
    – wondra
    Jan 13, 2014 at 21:00
  • Of course but your server may print some lines very quickly and stop printing anything until it ends up... Add a begin and end message to your predate.sh script.
    – HelpBox
    Jan 13, 2014 at 21:12

Not the answer you're looking for? Browse other questions tagged or ask your own question.