How to add a timestamp to bash script log?

Question

I have a constantly running script that I output to a log file:

script.sh >> /var/log/logfile

I'd like to add a timestamp before each line that is appended to the log. Like:

Sat Sep 10 21:33:06 UTC 2011 The server has booted up.  Hmmph.

Is there any jujitsu I can use?

See this questin. http://serverfault.com/questions/80749/ping-replacement-that-shows-real-time. A couple answer would apply here. — Zoredache, Sep 11 '11 at 00:43
For an awk/gawk solution see: http://stackoverflow.com/questions/21564/is-there-a-unix-utility-to-prepend-timestamps-to-lines-of-text — User, Nov 02 '12 at 17:31
Here is a comprehensive implementation of logging for bash: https://github.com/codeforester/base/blob/master/lib/stdlib.sh — codeforester, Mar 22 '19 at 01:03
Best local answer is @ChuckCottrill's https://serverfault.com/a/835534/137665 . `script.sh | gawk '{ print strftime("[%Y-%m-%d %H:%M:%S]"), $0 }' >> /var/log/logfile` — Stéphane Gourichon, Nov 22 '19 at 15:24

Gordon Davisson · Accepted Answer · 2019-06-19T21:15:59.363

120

You can pipe the script's output through a loop that prefixes the current date and time:

./script.sh | while IFS= read -r line; do printf '%s %s\n' "$(date)" "$line"; done >>/var/log/logfile

If you'll be using this a lot, it's easy to make a bash function to handle the loop:

adddate() {
    while IFS= read -r line; do
        printf '%s %s\n' "$(date)" "$line";
    done
}

./thisscript.sh | adddate >>/var/log/logfile
./thatscript.sh | adddate >>/var/log/logfile
./theotherscript.sh | adddate >>/var/log/logfile

edited Jun 19 '19 at 21:15

answered Sep 10 '11 at 21:58

Gordon Davisson

11,036
3
27
33

What is "IFS= " for? – Nils Sep 15 '11 at 21:15
3

@Nils it's a trick to prevent `read` from trimming whitespace at the beginning and and of the line. It sets IFS (bash's Internal Field Separator, basically a list of whitespace characters) to empty for the `read` command. – Gordon Davisson Sep 15 '11 at 21:43
2

...and -r ignores the escape-character "\". This should really work in all cases - great pice of scripting. – Nils Sep 16 '11 at 20:47
8

@Nils it's not completely bulletproof, since some implementations of `echo` interpret escape sequences. If you *really* want it not to mess with the content (other than adding dates), replace the `echo` command with `printf "%s %s\n" "$(date)" "$line"` – Gordon Davisson Sep 17 '11 at 02:31
This is so cool! – Aeon Jan 25 '17 at 00:37
6

You might be interested on a [ISO-8601 compliant](https://stackoverflow.com/a/7216394/4970442) date/timestamp: `date -u +"%Y-%m-%dT%H:%M:%SZ"` or maybe more pretty `date +"%Y-%m-%d %T"`. – Pablo A Jul 29 '17 at 01:40
2

while this script works as expected, it spawns a new process (execute `date`) for _each_ log line, which can be a massive drawback depending on your machine and the amount of logs. I would rather suggest to use `ts` if available, see the answer from @willem – Michael Schaefers May 09 '18 at 13:20
@PabloBianchi `date [-u] -Iseconds` or `date [-u] --iso-8601=seconds` will accomplish the same thing without manually recreating the format. Per [this question/answer](https://unix.stackexchange.com/questions/164826/date-command-iso-8601-option), this has been a documented option since v8.15 of coreutils. It doesn't appear to use a 'Z' for UTC, however, which is mildly annoying IMO. – ND Geek Jun 19 '19 at 20:49
How to preserve color? – Sohail Si Mar 15 '22 at 16:53
@SohailSi This shouldn't remove color (i.e. any color-setting terminal control escape sequences), but many commands only output color-setting escape sequences when their output is going directly to a terminal. You may need to tell the command producing the initial output to include color sequences even though its output is going to a pipe (e.g. `grep --color=always`). – Gordon Davisson Mar 15 '22 at 17:34

score 89 · Answer 2 · edited Feb 06 '19 at 13:23

89

See ts from the Ubuntu moreutils package:

command | ts

Or, if $command does automatic buffering (requires expect-dev package):

unbuffer command | ts

edited Feb 06 '19 at 13:23

das Keks

134
6

answered Oct 29 '13 at 15:20

Willem

2,712
3
27
34

1

FYI, `unbuffer` is in the "expect" package on Arch Linux. – l0b0 Jan 20 '21 at 00:30
This is great, but it is not available on AL2. – thule Jul 07 '22 at 12:41

score 43 · Answer 3 · answered Sep 10 '11 at 21:40

43

The date command will provide that information

date -u
Sat Sep 10 22:39:24 UTC 2011

so you can

echo $(date -u) "Some message or other"

is that what you wanted ?

answered Sep 10 '11 at 21:40

user9517

114,104
20
206
289

Using the date command was kind of what I had in mind, but I can't really add that to the script itself, so what I'm looking for is a way to change this line: "script.sh >> /var/log/logfile" to append the date. – Antonius Bloch Sep 10 '11 at 21:53
In that case redirect the output of your script to a named pipe and have a daemon listening for output which takes the script output and adds a date before writing it to a log file. You can probably modify the [**script I wrote**](http://serverfault.com/questions/189477/rotate-logs-of-a-dumb-non-interactive-application/189880#189880) here to do this. I would do it because it interests me but it's late in the UK and I have an early start tomorrow. – user9517 Sep 10 '11 at 22:12

score 13 · Answer 4 · answered Feb 03 '13 at 17:23

13

Make a config.sh file

#!/usr/bin/env bash
LOGFILE="/path/to/log.log"
TIMESTAMP=`date "+%Y-%m-%d %H:%M:%S"`

When you need to send to log file use

#!/usr/bin/env bash
source /path/to/config.sh

echo "$TIMESTAMP Say what you are doing" >> $LOGFILE

do_what_you_want >> $LOGFILE

Log file will looks like

2013-02-03 18:22:30 Say what you are doing

So it will be easy to sort by date

answered Feb 03 '13 at 17:23

scls

247
2
3

13

Your ''config.sh'' will run ''date'' exactly once, on ''source .../config.sh''. – clacke Mar 09 '15 at 15:03

SparX · Answer 5 · 2011-09-12T20:20:31.240

11

You can simply echo the command outputs to the logfile. ie,

echo "`date -u` `./script.sh`" >> /var/log/logfile

It really works :)

Example:

[sparx@E1]$ ./script.sh 
Hello Worldy
[sparx@E1]$ echo "`date -u` `./script.sh`" >> logfile.txt
[sparx@E1]$ cat logfile.txt 
Mon Sep 12 20:18:28 UTC 2011 Hello Worldy
[sparx@E1]$

edited Sep 12 '11 at 20:20

answered Sep 10 '11 at 22:03

SparX

1,924
12
10

What are you getting when you execute the command ? – SparX Sep 12 '11 at 20:15
17

That puts a timestamp before the entire output of ''./script.sh'', not before each line. – clacke Mar 09 '15 at 15:01

kdb · Answer 6 · 2021-07-05T14:32:51.903

8

The accepted answer https://serverfault.com/a/310104 can be a bit slow, if a lot of lines have to be processed, with the overhead of starting the date process allowing about 50 lines per second in Ubuntu, and only about 10-20 in Cygwin.

When bash can be assumed a faster alternative would be the printf builtin with its %(...)T format specifier. Compare

>> while true; do date; done | uniq -c
     47 Wed Nov  9 23:17:18 STD 2016
     56 Wed Nov  9 23:17:19 STD 2016
     55 Wed Nov  9 23:17:20 STD 2016
     51 Wed Nov  9 23:17:21 STD 2016
     50 Wed Nov  9 23:17:22 STD 2016

>> while true; do printf '%(%F %T)T\n'; done | uniq -c
  20300 2016-11-09 23:17:56
  31767 2016-11-09 23:17:57
  32109 2016-11-09 23:17:58
  31036 2016-11-09 23:17:59
  30714 2016-11-09 23:18:00

Remark. On my current OpenSuse work PC (July 2021) performance is significantly up, doing 1200 lines per second with date and 265,000 lines per second with printf. Not entirely clear, how this particular performance jumped by almost two orders of magnitude compared to my laptop from 5 years ago.

edited Jul 05 '21 at 14:32

answered Nov 09 '16 at 22:24

kdb

180
1
4

1

This answer deserves more attention. Even though using external program `date` might now be such a performance problem on nowadays machines, when a tool has everything inside, better not complicate with more tools. Plus this answers provide a simple and locally reproducible performance measurement (on my machine I get 700-1000 per second and 150k-170k per second). More answers should be of such quality. – Stéphane Gourichon Nov 22 '19 at 15:21
@StéphaneGourichon There are actually cases where it can make a huge performance difference still. E.g. I use this construct for adding timing information to stdout with `someprogram | while true; do date; done | uniq -c` . If a program produces hundreds of lines per second, calling `date` for each slows the performance down, while using the builtin does not. Though curiously, right now even the builtin produces only about 4000 lines per `uniq -c` for me... Could be that I tested on Linux back then. – kdb Nov 23 '19 at 21:59
yes we agree, no repeated external program will be faster. When performance is really important, no repeated bash construct will be even faster. GNU `awk` based solution may provide the best, see @ChuckCottrill's answer https://serverfault.com/a/835534/137665 On my machine I get 3.5x speed gain by replacing `yes |head -5000000 | while true; do printf '%(%F %T)T\n'; done | uniq -c` with `yes |head -5000000 | gawk '{ print strftime("[%Y-%m-%d %H:%M:%S]"), $0 }' >> /var/log/logfile` . – Stéphane Gourichon Nov 25 '19 at 19:17

score 7 · Answer 7 · edited May 28 '15 at 09:38

7

Try this

timestamp()
{
 date +"%Y-%m-%d %T"
}

Call this timestamp function in every echo command:

echo "$(timestamp): write your log here" >> /var/log/<logfile>.log

edited May 28 '15 at 09:38

shazbot

103
2

answered Apr 27 '15 at 16:45

Sanjay Yadav

71
1
2

@ shazbot:Thanks for editing, that was a typo error, i didnt notice. – Sanjay Yadav Jun 15 '15 at 07:08

score 5 · Answer 8 · answered Sep 12 '11 at 20:34

5

You mean like:

(date && script.sh) >> /var/log/logfile

answered Sep 12 '11 at 20:34

cjc

24,533
2
49
69

My god, people, everyone is doing back tick replacement, named pipes, etc. Just enclose both the date command and the script in parens! The guy who has the function has a legit case if there's multi-line output and the log needs to look pretty with the date on every line, but most of these solutions are overkill that doesn't use shell semantics. – cjc Sep 12 '11 at 21:11
10

That will only add the timestamp once per execution of `script.sh`. The OP needs a timestamp per line. – Dave Forgac Oct 10 '12 at 14:10
2

although this doesn't answer the OP question I still found it useful info. – User Nov 02 '12 at 20:14

score 5 · Answer 9 · edited Nov 25 '19 at 03:07

Short answer formatted to fit the question

script.sh | gawk '{ print strftime("[%Y-%m-%d %H:%M:%S]"), $0 }' >> /var/log/logfile

Explanation

awk runs fast and is able to work as Unix pipe filter and print date by itself.

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

Let's benchmark it:

yes |head -5000000 |gawk '{ print strftime("[%Y-%m-%d %H:%M:%S]"), $0 }' |uniq -c
 461592 [2017-02-28 19:46:44] y
 488555 [2017-02-28 19:46:45] y
 491205 [2017-02-28 19:46:46] y
 498568 [2017-02-28 19:46:47] y
 502605 [2017-02-28 19:46:48] y
 494048 [2017-02-28 19:46:49] y
 493299 [2017-02-28 19:46:50] y
 498005 [2017-02-28 19:46:51] y
 502916 [2017-02-28 19:46:52] y
 495550 [2017-02-28 19:46:53] y
  73657 [2017-02-28 19:46:54] y

Additional information

Sed appears to runs much faster,

sed -e "s/^/$(date -R) /"

yes |head -5000000 |sed -e "s/^/$(date -R) /" |uniq -c
5000000 Tue, 28 Feb 2017 19:57:00 -0500 y

However, on closer inspection, set does not seem to change time,

vmstat 1 | sed -e "s/^/$(date -R) /"

Because date (which is slower by the way) gets called only once.

this is because it is bash evaluating `"s/^/$(date -R) /"` and running date once before sed. Sed is passed a static string. — Evan Benn, Nov 08 '18 at 22:34
Plain bash: `yes | head -5000000 | while read line; do echo $((SECONDS)); done | uniq -c` which is much slower than gawk. `ts` utility has similar performance as bash loop. — akhan, Sep 27 '19 at 23:43
Perl: `yes |head -5000000 |perl -ne 'print localtime."\t".$_' |uniq -c` which is slightly slower than awk. — akhan, Sep 28 '19 at 00:06

Josh Williams · Answer 10 · 2022-03-16T09:39:48.487

3

Another option is to setup a function to call each time you want to output data in your code:

PrintLog(){
  information=$1
  logFile=$2
  #echo "$(date +'%Y-%m-%d %H:%M:%S)'" ${information} >> $logFile
  #Improve performance by using printf instead of date
  echo "$(printf '%(%F %T)T')" ${1} >> ${logFile}
}

Then every time in your code you want to send it to the log file call

PrintLog "Stuff you want to add..." ${LogFileVariable}

Easy peasy....

edited Mar 16 '22 at 09:39

answered Mar 30 '18 at 13:48

Josh Williams

31
4

You're missing a close paren – OneCricketeer May 06 '20 at 17:18
Thanks @OneCricketeer missed that – Josh Williams Mar 16 '22 at 09:41

score 2 · Answer 11 · answered Dec 11 '20 at 15:40

At the beggining of your script add the following:

#!/bin/bash
set -x
PS4='[\D{%d.%m.%y} \t]'

This will add date and time to every command and also it will write it out- eg: echo "GIT_BRANCH: $GIT_BRANCH" [11.12.20 12:50:46]echo 'GIT_BRANCH: master'

references and descriptions: Bash options: https://tldp.org/LDP/abs/html/options.html

Bash PS variables: https://linoxide.com/how-tos/change-bash-prompt-variable-ps1/#:~:text=PS1%3A%20environment%20variable%20which%20contains,long%20command%20in%20many%20lines.

This gives a weird result on subcommands with the time ```bash-3.2$ PS4='\t ' bash-3.2$ echo $(echo hi) hi bash-3.2$ set -x bash-3.2$ echo $(echo hi) 113:18:04 echo hi 13:18:04 echo hi hi ``` — Christian, Sep 30 '21 at 12:18

score 2 · Answer 12 · answered Oct 29 '17 at 14:25

This script print the output in terminal and also saves in log file.

#!/bin/bash

MY_LOG=/var/log/output.log

echolog(){
    if [ $# -eq 0 ]
    then cat - | while read -r message
        do
                echo "$(date +"[%F %T %Z] -") $message" | tee -a $MY_LOG
            done
    else
        echo -n "$(date +'[%F %T %Z]') - " | tee -a $MY_LOG
        echo $* | tee -a $MY_LOG
    fi
}

echolog "My script is starting"
whoami | echolog

Sample output:

[2017-10-29 19:46:36 UTC] - My script is starting
[2017-10-29 19:46:36 UTC] - root

your first date command should use single quotes, not double quotes. — Jason Harrison, Mar 29 '19 at 21:00

score 1 · Answer 13 · answered Aug 31 '20 at 08:43

1

I simply do this (buddy variable is just an example, you can put anything there):

#!/bin/bash
now=$( date +%Y%m%d-%H%M-%S )
buddy=`cat /proc/buddyinfo | grep Normal`
echo "$now, $buddy" >> /home/myuser/buddyinfo-logger.log

This works perfectly.

answered Aug 31 '20 at 08:43

bzero

369
2
9

bas080 · Answer 14 · 2020-10-05T20:18:54.590

1

I have noticed that using xargs with printf works well and is fast.

timestamp="$(date -Iseconds)"
ls | xargs -d '\n' -l printf '%s: %s' "$timestamp" 1>&2

I write to stderr just not to pollute the stdout.

I have made a logging utility written in bash that I use in my bash scripts:

https://github.com/bas080/logger

It has more features than the example above.

edited Oct 05 '20 at 20:18

answered Oct 05 '20 at 19:50

bas080

11
3

score 1 · Answer 15 · answered Jul 03 '21 at 23:08

Use the system logger, which is available on every linux instance, docker container, mac os, etc etc.

$ uname -a
Darwin xxx xxxx Darwin Kernel Version xxx: Thu Jan 21 00:07:06 PST 2021; root:xxx/RELEASE_X86_64 x86_64 i386 xxx Darwin
$ printf "%s\n" one two | logger -sp DEBUG 
Jul  4 00:51:42  christian[19358] <Debug>: one
Jul  4 00:51:42  christian[19358] <Debug>: two
$ docker run -it --rm debian sh -c 'printf "%s\n" one two | logger --socket-errors=off -sp WARN'
<12>Jul  3 23:08:21 root: one
<12>Jul  3 23:08:21 root: two

It's old and as fundamentally a part of linux as grep, sed, awk, etc and is written in c, which makes it a faster and better option than anything above, though ts is a better fit to your question. Do not use someone's self-roll; logging is too important and complex to leave to amateurish solution or something ad hoc.

https://man7.org/linux/man-pages/man1/logger.1.html https://github.com/karelzak/util-linux/blob/master/misc-utils/logger.c

score 1 · Answer 16 · edited Aug 26 '17 at 03:14

The below is my log file contents

xiongyu@ubuntu:~/search_start_sh$ tail restart_scrape.log 

2017-08-25 21:10:09 scrape_yy_news_main.py got down, now I will restart it

2017-08-25 21:10:09 check_yy_news_warn.py got down, now I will restart it

2017-08-25 21:14:53 scrape_yy_news_main.py got down, now I will restart it

some of my shell contents is as below

log_file="restart_scrape.log"
TIMESTAMP=`date "+%Y-%m-%d %H:%M:%S"`
echo "$TIMESTAMP $search_py_file got down, now I will restart it" | tee -a $log_file

score 0 · Answer 17 · answered Sep 06 '22 at 22:28

Some of my servers do not support ts, so I came up with a sed | xargs date | tee combination to timestamp all my script's output.

In addition I prefer the way to set common settings and the log mechanism in a separate script:

#!/bin/bash

# disable history expansion
set +H

# log all output
exec &> >(stdbuf -o0 sed 's/%/%%/g' | xargs -d '\n' -I {} date '+%F %T {}' | tee -a "/var/log/${0//\//_}.log" )

# log execution start
echo "Script execution started..."

Now I include this in all scripts and they will log stdout and stderr with a timestamp to /var/log/_usr_local_bin_scriptname.log:

#!/bin/bash

source /usr/local/lib/bash/common.sh

# print working dir to log file and console
pwd

# errors are logged as well
ls /does/not/exist

Of course you could suppress the additional output to the console by redirecting stdout of tee to /dev/null. And you should use logrotate to automatically compress the logs.

score 0 · Answer 18 · edited Mar 25 '15 at 12:15

0

Pipe a "sed":

script.sh | sed "s|^|$('date') :: |" >> /var/log/logfile

edited Mar 25 '15 at 12:15

Andrew Schulman

8,561
21
31
47

answered Mar 25 '15 at 11:15

eubide

1

1

as for the other answer, this is just bash running date once. sed is not updating the time per line. – Evan Benn Nov 08 '18 at 22:35

How to add a timestamp to bash script log?

18 Answers18

Short answer formatted to fit the question

Explanation

Additional information