Logs are not just streams

April 4, 2011

Via Hacker News, I recently read Logs Are Streams, Not Files. In it, Adam Wiggins suggests that because logs are just streams, your program should just write log messages to standard error as the most flexible, most stream-based way of operating on Unix.

I'm sorry, I'm a sysadmin. I just saw red.

Logs are not just streams. Logs are crucially different from streams in one respect; logs can and in fact must be segmented and sectioned periodically. In the sysadmin business, we call this 'log rolling' (or 'log rotation'), and we do it both because we don't have the disk space to keep all of your log messages forever and because it's much easier to work with relatively small chunks of logs that cover restricted time intervals than to have to work with everything from the start of time.

Writing log messages to standard error does not cope well with log rotation. To rotate a log, your program needs to stop writing to one file and start writing to another one, and standard error is simply a stream; even if we ask your program nicely, it cannot close standard error and then reopen it. This means that a program that logs to standard error cannot be deployed as a standalone entity; we cannot run your program as just 'program 2>/var/log/program', because that would give us no way to rotate /var/log/program. Instead, your program's output must be fed to another program that actually does the work of logging things in some manner.

This is sort of okay if you provide us with this extra program and the infrastructure to configure it and run it along with your main program. But if you simply hand us your main program and claim that its ready to go, we see red because now we have to supply the program (and the infrastructure) to actually make your logging work.

(Perhaps Unix should have a standard program for this, but it doesn't. Note that logger is not a good option for this even if we want things to go to syslog.)


Comments on this page:

From 138.246.23.74 at 2011-04-04 07:54:35:

Plenty of such tools exist:

Also, can you elaborate what the problem with piping to logger is? The implementations I saw fgets a line and syslog it, which seems fine.

By cks at 2011-04-04 17:08:14:

One part of the answer about logger is sufficiently long and involved that I wrote an entry about it, SyslogVsStderr.

The other part is that you have to trust both logger and the program feeding it a lot. For example, you have to trust that both sides are doing unbuffered IO, so that messages go through the pipe immediately and as fast as possible. This is probably true, but if you're going to build a logging solution you need to check.

(And then you need to be wary of people changing either side out from underneath you, because after all they never imagined that someone was using logger this way and that it mattered etc etc.)

From 77.23.49.79 at 2011-04-06 10:21:11:

I don't quite agree with you about:

"we cannot run your program as just 'program 2>/var/log/program', because that would give us no way to rotate /var/log/program."

At least in Linux the logrotate program offers the "copytruncate" configuration option, which can handle such cases. I'd be surprised if other OSs wouldn't offer a similar option.

From 85.12.213.105 at 2011-04-06 10:29:34:

No one mentioned stdout/stderr redirection capabilities in systemd, while it's pretty much the only place where it seemed to be useful to me.

Lots of simple apps that don't do much logging can be told to just log to stderr (and it usually coincides nicely with non-forking mode, which is preferrable when running stuff in systemd), and default logging (syslog, or terminal, if you need to debug something early) target will catch the output instead of creating lots of unwatched and unchecked log files.

By cks at 2011-04-06 10:45:02:

Copying and truncating log files suffers from two problems: you can lose records (and you will if this is an active daemon) and you have to trust that the program and the system are not going to malfunction in the face of having standard error truncated on them (cf).

From 82.145.208.209 at 2011-04-07 01:38:22:

hello, when yiu want to use copy truncate, you need to have the application appending. so using >>logfile instead of >logfile. some older tomcat had it wrong for catalina.out log (basicaly stdout logging) and it made problems.

-jhr.

From 80.254.147.84 at 2011-04-07 06:46:08:

Redirect stderr to a named pipe, read from the named pipe into your rotating/syslogging program of choice.

Written on 04 April 2011.
« Please don't alert based on percentages
Why logging to syslog is different than logging to standard error »

Page tools: View Source, View Normal, Add Comment.
Search:
Login: Password:
Atom Syndication: Recent Comments.

Last modified: Mon Apr 4 00:24:56 2011
This dinky wiki is brought to you by the Insane Hackers Guild, Python sub-branch.