How to add timestamp while redirecting stdout to file in Bash?

Question

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.

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. http://stackoverflow.com/questions/3465619/how-to-make-output-of-any-shell-command-unbuffered might be what you are looking for — Graeme, Jan 13 '14 at 18:40
Pipe the output to _awk_. It provides a function called _strftime_. — devnull, Jan 13 '14 at 19:01
The `expect` distribution comes with a program called [`unbuffer`](http://linuxcommand.org/man_pages/unbuffer1.html) : `unbuffer ./server | ./predate.sh > log.txt` — glenn jackman, Jan 13 '14 at 19:02
What do you get if you try Dennis's solution in the linked question? e.g. `./server.sh > >( ./predate.sh > log.txt )` — Reinstate Monica Please, Jan 13 '14 at 20:00
@BroSlow "./server.sh > >( ./predate.sh > log.txt )" does the same - logs with same datetime on every line — wondra, Jan 13 '14 at 20:44
@wondra Any luck when using `unbuffer` as glenn jackman suggested above? (for either solution) — Reinstate Monica Please, Jan 13 '14 at 20:50
Both Graeme and denull pointed to right solution, i would select it as correct answer if it were in answers, thanks. it should be run as "stdbuf -oL ./server | ./predate.sh > log.txt" using unbuffer makes server unable to respond in console to "EXIT" for safe turning off server. (ctrl+c is "nono") — wondra, Jan 13 '14 at 20:56
Possible duplicate of [Is there a Unix utility to prepend timestamps to stdin?](http://stackoverflow.com/questions/21564/is-there-a-unix-utility-to-prepend-timestamps-to-stdin) — umläute, Jan 12 '17 at 15:01
@umläute can you *please* read the question before marking as duplicate? The problem was identified and answered by an comment years ago(changing stdout buffer settings). If you read it and still think this question need formal answer, feel free to post an answer based on said comment. — wondra, Jan 12 '17 at 15:26
What is happening is, the system detects that you are piping (and not going to terminal), and assumes that any real-time requirements can be relaxed, it then (for performance reasons) buffers the pipe. — ctrl-alt-delor, Jan 24 '17 at 09:11

score 56 · Answer 1 · edited Feb 13 '15 at 19:03

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)

edited Feb 13 '15 at 19:03

Nick

11,475
1
36
47

answered Sep 10 '14 at 11:45

oliver

9,235
4
34
39

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 '15 at 17:07
3

Awk, ever to the rescue. – macetw Dec 11 '15 at 15:09
2

This is the only output for me: `awk: line 2: function strftime never defined` – ygoe Jun 10 '17 at 20:32
@ygoe, what version of awk are you using? – mwfearnley Jun 27 '17 at 10:59
@mwfearnley GNU Awk 4.1.3, API: 1.1 (GNU MPFR 3.1.4, GNU MP 6.1.0) – ygoe Jun 27 '17 at 16:41
3

maybe install gawk first: https://stackoverflow.com/questions/3684212/using-strftime-function-in-mawk – Mladen B. Jan 15 '18 at 09:03
You can also add `tee -a`, so that tee appends to the file, if this is the behavior you would like to have. – Stanislav Jan 16 '18 at 14:33
How to add millis? – Denny Weinberg Jan 05 '21 at 09:39

Ciro Santilli OurBigBook.com · Answer 2 · 2021-03-14T11:16:37.067

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.

score 10 · Answer 3 · edited Nov 13 '16 at 15:34

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

edited Nov 13 '16 at 15:34

Ciro Santilli OurBigBook.com

347,512
102
1,199
985

answered Jan 14 '14 at 06:55

Ashish

1,856
18
30

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 '14 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). – ctrl-alt-delor Jan 24 '17 at 09:19

score 1 · Answer 4 · answered Apr 14 '19 at 02:48

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

answered Apr 14 '19 at 02:48

nyet

482
2
13

score -2 · Answer 5 · answered Jan 13 '14 at 20:40

-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

answered Jan 13 '14 at 20:40

HelpBox

55
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 '14 at 21:00
I have function for turning off server which take 25 second, believe me - I would notice... – wondra Jan 13 '14 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 '14 at 21:12

How to add timestamp while redirecting stdout to file in Bash?

5 Answers5

Linked

Related