47

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.

Improve this question
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 Commented Jan 13, 2014 at 18:40
  • Pipe the output to awk. It provides a function called strftime. Commented Jan 13, 2014 at 19:01
  • 1
    The expect distribution comes with a program called unbuffer : unbuffer ./server | ./predate.sh > log.txt Commented Jan 13, 2014 at 19:02
  • 2
    Also see man stdbuf. Commented 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 ) Commented Jan 13, 2014 at 20:00

6 Answers 6

Reset to default
57

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)
Improve this answer
Sign up to request clarification or add additional context in comments.

8 Comments

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:".
Awk, ever to the rescue.
This is the only output for me: awk: line 2: function strftime never defined
@ygoe, what version of awk are you using?
maybe install gawk first: stackoverflow.com/questions/3684212/…
|
37

moreutils ts

Install on Ubuntu 24.04:

sudo apt-get install moreutils

Absolute time is the default:

(echo a;sleep 1;echo b;sleep 3;echo c;sleep 2;echo d;sleep 1) | ts | tee myfile
cat myfile

gives:

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

gives:

00:00:00 a
00:00:01 b
00:00:04 c
00:00:06 d

or deltas between two consecutive lines for benchmarking with ts -i:

(echo a; sleep 1; echo b; sleep 3; echo c; sleep 2; echo d; sleep 1) | ts -i

gives:

00:00:00 a
00:00:01 b
00:00:03 c
00:00:02 d

or with a different time format of seconds + fractions of second:

$ (echo a; sleep 1; echo b; sleep 3; echo c; sleep 2; echo d; sleep 1) | ts -i '%.s'

gives:

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.

Improve this answer

Comments

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

Improve this answer

2 Comments

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.
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).
2

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
Improve this answer

Comments

0

A Perl one-liner, if you don't have moreutils installed. This shows timestamps as seconds since the epoch, with fractional seconds:

./server | perl -MTime::HiRes=time -nE 's/\n//; say time . ": " . $_'

Formatted, without fractional seconds:

./server | perl -nE 's/\n//; say localtime . ": " . $_'
Improve this answer

Comments

-3

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

Improve this answer

3 Comments

Maybe your server is executed too quickly... Try to print nanoseconds as follows and check the difference: echo "$(date +%T.%N): ${line}"
I have function for turning off server which take 25 second, believe me - I would notice...
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.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.