Logging to a file, prepending a timestamp to each line (Debian)

Question

I am trying to log output from some shell scripts of mine to a file, and I want the timestamp prepended to each line. From what I understood, that's what logger(1) is for, but I don't want the output to go to /var/log/messages, and I can't see that this is possible using logger. I'm using Debian by the way.

What is the best way to do this?

—Oliver

Solution 1

logger's function is actually to shunt messages to syslog; default configs will prepend a timestamp and write the logs out to /var/log/messages, but that doesn't mean that logger's purpose is to prepend a timestamp.

One way to handle this would be to modify your syslog configs such that your messages routed via logger go to a special file - use the "-p" flag to logger to stipulate a facility.priority pair (perhaps one of the user[1..7] facilities), and configure your syslogd to log that facility to a special file.

Alternatively, you could whip up a quick shell function to simply prepend the timestamp:

Bodacious:~ james$ timestamp () {
> f=`date`
> echo $f $*
> }
You have new mail in /var/mail/james
Bodacious:~ james$ timestamp a line of logs
Tue 18 Jan 2011 22:40:24 EST a line of logs
Bodacious:~ james$ 

On my system, this is going to result in the shell forking /bin/date once per line of output. This is inefficient, but probably acceptable at small scales.

Solution 2

I needed something like that, and google got me here. Using something like syslog is definitely an overkill for just trying out to time something, and the printout-every-second is too inconvenient.

Here's a one-liner that seems to work fine:

cmd | { while read R; do echo "$(date +%s) $R"; done }

and a variant that prints the time it took to produce each line:

cmd | { T=$(date +%s); while read R; do T2=$(date +%s); echo "$((T2-T)) $R"; T=$T2; done }

(This is using seconds, probably not too hard to throw in %N in there, but at that level a shell solution is probably not the right tool anyway.)

Comments

[filiprem]

meta note: it's a duplicate of unix.stackexchange.com/questions/26728/…

[Dennis Williamson]

That's not what -f does. It uses the contents of the file as the message portion of the log entry.

[Niall Donegan]

My apologies! Misread the man page. However, the second part of the answer stands, so I've editted it to include just that.

[Kaushik Chakraborty]

Thanks for a good answer :) This was my original idea, but I thought "there has to be a program out there that does this already"… but clearly not! Or not one that's commonly used anyhow. Out of curiosity, what are the "user[1..7] facilities" you refer to?

[rain]

In attempting to provide an authoritative reference for my answer, I found out that I was a bit wrong. "Facilities" are one of the ways syslog segments the messages it processes. There are 23 facilities defined - mostly for types of log messages that were common when syslog was created (lpr, ftp, cron), a couple to be generic buckets (messages, system) - but there are 8 facilities called local0 through local7 (not user1 through user7 as I originally stated) intentionally designed for local uses. See RFC5424 for the full list of facilities

[Eli Barzilay]

No, this is broken: it appends the same date to all lines.

[Steve Bennett]

Well, it's broken if you want to run an entire log-generating process through it. I'm using it as I generate each line.

[Eli Barzilay]

If you're using it for a single line you don't need any pipe -- it's almost exactly the same as date +...; cmd. The only difference is that you get a newline from date which you can remove in the usual ways.

[Steve Bennett]

The usual ways being sed?:-)

[Eli Barzilay]

That would be one way ... but you're not using it. Your line uses backticks in a way that already swallows the newline. Here's a complete line that shows what I mean: echo -n "$(date +%s) "; cmd -- note that there are no pipes and no external subprocess other than date.

[Steve Bennett]

Cool, I just learnt something.

[Eli Barzilay]

Well, you were using it -- maybe the $(...) is confusing -- it's the same as `...` except more convenient (including for these comments, which is why I used it).