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?
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
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
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]$
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
As pointed out after the original answer (see below), an awk-based solution is the most efficient, when really high throughput is needed, and it has the advantage of not being bash-specific syntax. (For instance, in zsh, the %(..)T format does not work.)
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.
Update. Just adding new benchmarks (still same OpenSuse PC, May 2023), and adding awk solution, as suggested by StéphaneGourichon in the comments.
>>> yes | while IFS= read -r line; do echo "$(date) ${line}"; done | uniq -c
561 Tue 09 May 2023 10:20:39 AM CEST y
704 Tue 09 May 2023 10:20:40 AM CEST y
695 Tue 09 May 2023 10:20:41 AM CEST y
696 Tue 09 May 2023 10:20:42 AM CEST y
>>> yes | while IFS= read -r line; do printf "%(%F %T)T: %s\n" -1 "${line}"; done | uniq -c
6935 2023-05-09 10:23:21: y
22962 2023-05-09 10:23:22: y
20426 2023-05-09 10:23:23: y
18212 2023-05-09 10:23:24: y
18406 2023-05-09 10:23:25: y
>>> yes | awk '{print strftime("%F %T"), $0}' | uniq -c
520932 2023-05-09 10:24:51 y
587067 2023-05-09 10:24:52 y
586600 2023-05-09 10:24:53 y
587226 2023-05-09 10:24:54 y
579186 2023-05-09 10:24:55 y
572274 2023-05-09 10:24:56 y
Like the while-loop based variants, one date is added per line, and within-line whitespace is preserved unmodified.
>>> yes | sed 's/y/This is a longer text/' | awk '{print strftime("%F %T"), $0}' | uniq -c
331324 2023-05-09 10:28:09 This is a longer text
504857 2023-05-09 10:28:10 This is a longer text
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
script.sh | gawk '{ print strftime("[%Y-%m-%d %H:%M:%S]"), $0 }' >> /var/log/logfile
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
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.
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 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
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....
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
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.
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.
To have have a short log suffix like | log I came up with this.
function log() {
while read
do
echo $(date +%F\ %T) $REPLY >> /tmp/log.log
done
}
echo foo | log
head -n 3 /proc/cpuinfo | log
Example output:
2023-01-29 10:46:58 foo
2023-01-29 10:46:58 processor : 0
2023-01-29 10:46:59 vendor_id : GenuineIntel
2023-01-29 10:46:59 cpu family : 6
Inspired by others and twisted...
The best way for me is to define a function echo_ts and use it in my script instead of the built-in echo command:
echo_ts() {
local timestamp=$(date +"%Y-%m-%d %T")
echo "[$timestamp] $*"
}
usage:
echo_ts "This is echo_ts"
#output:
[2024-09-03 14:19:13] This is echo_ts
The downsides are:
echo_ts instead of the echo for all the places you need. But as the Zen Of Python says: Explicit is better than implicit.
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
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.
#!/bin/sh
DATETIME=date "+%Y-%m-%d %H:%M:%S"
echo "[$DATETIME] TYPE_YOUR_MESSAGE" >> output_file.log
[2024-08-22 14:13:19] TYPE_YOUR_MESSAGE
I see a lot of references to "$(date +'%Y-%m-%d %H:%M:%S')" in this discussion.
While getting specific in the date format as '%Y-%m-$d', or the time as '%H:%M:%S' are functionally correct, I find it more efficient and at least as effective to code as '%F %T %P %Z' to receive full date in YYYY-MM-DD format, full time, AM/PM, and named time zone.
Pipe a "sed":
script.sh | sed "s|^|$('date') :: |" >> /var/log/logfile
