Adding Timestamp to Logs

How many small script or process do you have which just log to stdout/stderr? A few, dozens?
Their running as cronjobs or service?
Stashing the logs somewhere, like:

./produces-some-log.sh 2>&1 > log-of-my-script.log

Do you have time stamps on those logs?
If not, it is trivial to add. You just have to pipe the log through a time stamp tool.

Timestamp your lines

Linux: ts

On most Linux distros there the `ts` tool. If it is not installed, it is usually in the ‘moreutils’ package. So get it via `apt-get`, `yum`, `pacman` or whatever you`re distro uses.

Then, pipe the output through `ts`:

[gamlor@gamlor-manjaro log-util]$ ./produces-some-log.sh 2>&1                                          
We are making progress. We are at step 1/5         
And some other info about the system:  13:39:24 up 2:10, 2 users, load average: 1.44, 1.74, 1.76       
We are making progress. We are at step 2/5         
And some other info about the system:  13:39:25 up 2:10, 2 users, load average: 1.44, 1.74, 1.76       
We are making progress. We are at step 3/5         
....

Will become:

[gamlor@gamlor-manjaro log-util]$ ./produces-some-log.sh 2>&1 | ts                                     
Sep 25 13:39:30 We are making progress. We are at step 1/5                                             
Sep 25 13:39:30 And some other info about the system:  13:39:30 up 2:10, 2 users, load average: 1.65, 1.78, 1.77                                                                                               
Sep 25 13:39:31 We are making progress. We are at step 2/5                                             
Sep 25 13:39:31 And some other info about the system:  13:39:31 up 2:10, 2 users, load average: 1.65, 1.78, 1.77                                                                                               
Sep 25 13:39:31 We are making progress. We are at step 3/5                                             
...          

You can specify a date format string to have more clear format:

[gamlor@gamlor-manjaro log-util]$ ./produces-some-log.sh 2>&1 | ts '%Y-%m-%dT%T%z'
2017-09-25T22:47:25+0900 We are making progress. We are at step 1/5
2017-09-25T22:47:25+0900 And some other info about the system:  22:47:25 up 2:18, 2 users, load average: 1.25, 1.29, 1.53
2017-09-25T22:47:26+0900 We are making progress. We are at step 2/5
2017-09-25T22:47:26+0900 And some other info about the system:  22:47:26 up 2:18, 2 users, load average: 1.25, 1.29, 1.53
...

Last, I recommend using the UTC time zone, to avoid confusion. Expecially when your servers are all over the world. Or you need to cross reference time stamps with other logs.
If your server isn`t set to UTC, you can set the `TZ` enviroment variable:

[gamlor@gamlor-manjaro log-util]$ export TZ=UTC
[gamlor@gamlor-manjaro log-util]$ ./produces-some-log.sh 2>&1 | ts '%Y-%m-%dT%T%z'
2017-09-25T13:49:54+0000 We are making progress. We are at step 1/5
2017-09-25T13:49:54+0000 And some other info about the system:  13:49:54 up 2:21, 2 users, load average: 0.66, 1.13, 1.44
2017-09-25T13:49:55+0000 We are making progress. We are at step 2/5
...

For more details, check the man pages.

For all Unix-like systems, AWK to the rescue!

BSD, illumos or some other Unix like system? Maybe there no `ts` util around? Good old awk has got you covered. On each line, print the date, then the rest of the line.

This method is more portable. AWK is installed most systems. So, if you plan do distribute your script, this is the way to go.

[gamlor@gamlor-manjaro log-util]$ ./produces-some-log.sh 2>&1 | awk '{ print strftime("%Y-%m-%dT%T%z"), $0;  }'                                                                                                     
2017-09-25T22:57:54+0900 We are making progress. We are at step 1/5                                    
2017-09-25T22:57:54+0900 And some other info about the system:  22:57:54 up 2:29, 2 users, load average: 1.29, 1.23, 1.39                                                                                      
2017-09-25T22:57:55+0900 We are making progress. We are at step 2/5                                    
...

Again, I recommend using UTC. Your server probably already uses UTC anyway:

[gamlor@gamlor-manjaro log-util]$ export TZ=UTC    
[gamlor@gamlor-manjaro log-util]$ ./produces-some-log.sh 2>&1 | awk '{ print strftime("%Y-%m-%dT%T%z"), $0;  }'                                                                                                     
2017-09-25T13:59:23+0000 We are making progress. We are at step 1/5                                    
2017-09-25T13:59:23+0000 And some other info about the system:  13:59:23 up 2:30, 2 users, load average: 1.09, 1.15, 1.35                                                                                      
2017-09-25T13:59:24+0000 We are making progress. We are at step 2/5                                    
...                                  

That`s it =).
Thanks for the Stackoverflow answers, which include both solutions.

Tagged on: ,

Leave a Reply

Your email address will not be published. Required fields are marked *