Appending timestamp stamp along with log file lines
The General Way
$ cat input.log | sed -e "s/^/$(date -R) /" >> output.log
How it works:
cat
reads file calledinput.log
and just prints it to its standard output stream.Normally the standard output is connected to a terminal, but this little script contains
|
so shell redirects the standard output ofcat
to standard input ofsed
.sed
reads data (ascat
produces it), processes it (according to the script provided with-e
option) and then prints it to its standard output. The script"s/^/$(date -R) /"
means replace every start of line to a text generated bydate -R
command (the general construction for replace command is:s/pattern/replace/
).Then according to
>>
bash
redirects the output ofsed
to a file calledoutput.log
(>
means replace file contents and>>
means append to the end).
The problem is the $(date -R)
evaluated once when you run the script so it will insert current timestamp to the beginning of each line. The current timestamp may be far from a moment when a message was generated. To avoid it you have to process messages as they are written to the file, not with a cron job.
FIFO
The standard stream redirection described above called pipe. You can redirect it not just with |
between commands in the script, but through a FIFO file (aka named pipe). One program will write to the file and another will read data and receive it as the first sends.
Pick an example:
$ mkfifo foo.log.fifo
$ while true; do cat foo.log.fifo | sed -e "s/^/$(date -R) /" >> foo.log; done;
# have to open a second terminal at this point
$ echo "foo" > foo.log.fifo
$ echo "bar" > foo.log.fifo
$ echo "baz" > foo.log.fifo
$ cat foo.log
Tue, 20 Nov 2012 15:32:56 +0400 foo
Tue, 20 Nov 2012 15:33:27 +0400 bar
Tue, 20 Nov 2012 15:33:30 +0400 baz
How it works:
mkfifo
creates a named pipewhile true; do sed ... ; done
runs an infinite loop and at every iteration it runssed
with redirectingfoo.log.fifo
to its standard input;sed
blocks in waiting for input data and then processes a received message and prints it to standard output redirected tofoo.log
.At this point you have to open a new terminal window because the loop occupies the current terminal.
echo ... > foo.log.fifo
prints a message to its standard output redirected to the fifo file andsed
receives it and processes and writes to a regular file.
The important note is the fifo just as any other pipe has no sense if one of its sides is not connected to any process. If you try to write to a pipe the current process will block until someone would read data on the other side of the pipe. If you want to read from a pipe the process will block until someone will write data to the pipe. The sed
loop in the example above does nothing (sleeps) until you do echo
.
For your particular situation you just configure your application to write log messages to the fifo file. If you can't configure it - simply delete the original log file and create a fifo file. But note again that if the sed
loop will die for some reason - your program will be blocked upon attempting to write
to the file until someone will read
from the fifo.
The benefit is the current timestamp evaluated and attached to a message as the program writes it to the file.
Asynchronous Processing With tailf
To make writing to the log and processing more independent you can use two regular files with tailf
. An application will write message to a raw file and other process read new lines (follow to writes asynchronously) and process data with writing to the second file.
Let's take an example:
# will occupy current shell
$ tailf -n0 bar.raw.log | while read line; do echo "$(date -R) $line" >> bar.log; done;
$ echo "foo" >> bar.raw.log
$ echo "bar" >> bar.raw.log
$ echo "baz" >> bar.raw.log
$ cat bar.log
Wed, 21 Nov 2012 16:15:33 +0400 foo
Wed, 21 Nov 2012 16:15:36 +0400 bar
Wed, 21 Nov 2012 16:15:39 +0400 baz
How it works:
Run
tailf
process that will follow writes tobar.raw.log
and print them to standard output redirected to the infinitewhile read ... echo
loop. This loop performs two actions: read data from standard input to a buffer variable calledline
and then write generated timestamp with the following buffered data to thebar.log
.Write some messages to the
bar.raw.log
. You have to do this in a separate terminal window because the first one will be occupied bytailf
which will follow the writes and do its job. Quite simple.
The pros is your application would not block if you kill tailf
. The cons is less accurate timestamps and duplicating log files.
You could use the ts
perl script from moreutils
:
$ echo test | ts %F-%H:%M:%.S
2012-11-20-13:34:10.731562 test
Modified from Dmitry Vasilyanov's answer.
In a bash script, you can redirect and wrap output with timestamps line by line on the fly.
When to use:
- For bash script jobs, insert the line before main script
- For non-script jobs, create a script to call the program.
- For services control by system, it's better to use
tailf
for the log file as Dmitry Vasilyanov said.
Here's an example named foo.sh
:
#!/bin/bash
exec &> >(while read line; do echo "$(date +'%h %d %H:%M:%S') $line" >> foo.log; done;)
echo "foo"
sleep 1
echo "bar" >&2
sleep 1
echo "foobar"
And the result:
$ bash foo.sh
$ cat foo.log
May 12 20:04:11 foo
May 12 20:04:12 bar
May 12 20:04:13 foobar
How it works
exec &>
Redirect stdout and stderr to same place>( ... )
pipe outputs to an asynchronous inner command- The rest works as Dmitry Vasilyanov explained.
For example:
pipe timestamp and log to file
#!/bin/bash exec &> >(while read line; do echo "$(date +'%h %d %H:%M:%S') $line" >> foo.log; done;) echo "some script commands" /path-to/some-thrid-party-programs
Or print timestamp and log to stdout
#!/bin/bash exec &> >(while read line; do echo "$(date +'%h %d %H:%M:%S') $line"; done;) echo "some script commands" /path-to/some-thrid-party-programs
then save them in
/etc/crontab
setting* * * * * root /path-to-script/foo.sh >> /path-to-log-file/foo.log