How Should an Application's Logs Work?

emmjayell writes "You've been there, loaded up a new application (think server-based app like Apache or Samba ...), it's working okay for a few days or a few months, then the intermittent problems start. Usually it's the CEO or someone else of relative importance that is the first victim. You can't readily duplicate the problem, so you go to find out where the application put's it's logs - maybe it's in var/log/messages - maybe in it's own directory - sometimes it's right there and available in some administrative GUI. So what makes you happiest when diagnosing the problem? Do you want tools to access it? UI or command line? Do you want it formatted to use tools like cut and sed? Do you have any examples of an app that does a great job with system logging and diag logging? Background: My team is working on an application that is gearing up for a first release. We have a logging framework in place already (we are using Apache: logging.apache.org/) -- so that covers how we are logging, but not what we should log and how it should be laid out for optimal use."

Comments

My favorite logging app...

[Zugot]

JBoss 4. Even though I can't figure it the first time most time I look at it, the answer is always in the log.

Even though it is resource intensive, I prefer the developer log everything, and let me decide how verbose or terse I want the logs to be.

When Where Who What

[NoSuchGuy]

Maybe you want to know

When from Where did What by Whom

When = ISO 8601 Timestamp (from)
Where = IP Adress / Name of computer...
Who = which Login /registered user did
What requested file foo/bar?a=213b=dfg

Re:When Where Who What

[AndroidCat]

Yes, standard timestamps! (Especially when timezones are involved.) It's extremely irritating parsing stuff into a db for processing when someone uses a non-standard format for no good reason. I've seen sites with different formats in HTTP headers for Date and Last-Modified. Huh? And almost every domain registrar uses a slightly different format.

syslog!

[Anonymous Coward]

The distressing part is that there's an answer: the syslog daemon, a quite capable application. The problem is that some prominent apps don't use it at all. This is in part due to the limitations of syslog, but the solution is not to reinvent the wheel, it's to modify the wheel so that it does as you wish. syslog doesn't have the facilities you want? Change it so it does. It doesn't deal with things like splitting logs for virtual (web) hosts? Change is so it does.

I say this as a sysadmin for a large number (several thousands) of servers. So many problems could be solved by Apache et al using, and modifying where necessary, the existing solutions. But they don't, they roll their own, and so we see problems.

I realize this is a sorta OT rant, but it's causing major problems for me at work and so I think it's justified. Stuff like rotatelog has functionality to tell Apache "dump your logs, I'm rotating the file!" (which by the way doesn't always work) which could be easily rolled into a single notification of the syslog daemon. But it isn't. For whatever perverse reason, Apache and many others decided to roll their own.

It pisses me the fuck off, having to deal with it. The greatest shortcoming by far of OSS is this insistency on reimplemtning proven, robust, existing solutions in favor of a trivial fix. This is a particularly egregious example, one the OSS world would be served well by acknowledging.

Re:syslog!

[DrSkwid]

In my experience, logging each request to a database isn't fast enough and eventually it becomes CPU overloaded.

tab separated plain text logging is just fine and dandy. Syslog is great because it has a standard format so any tools you make will just keep on trucking.

If you want a db of it do it in batch mode when you need it i.e.

zcat messages.0.gz | syslogtodb | grep httpd | mysql httpd

Why waste those CPU cycles indexing millions of lines of logging you'll never look at ?

Always rotate your log files

[EnronHaliburton2004]

Whatever your logging strategy, please remember to rotate your logfiles.

You'd be amazed how many Internet applications crash simply because the logs fill up the partition that hosts the application.

This problem was threefold, because:

1. The logfiles should never get that size
2. Logs should usually exist on a seperate partition like /var or your custom directory under /a
3. People usually ignore the messages in a Production debug log

I run 12 moderate websites. We easily generate 5GB of logfiles a week (Rotated). It used to be 10GB, but then I switched off debug logging and fixed the most common errors.

When I started my current job 1 year ago, I deleted 40GB of logs which ran back to year 2000.

User configurable levels of logging

[Goyuix]

It is nice to allow the end user to specify the verbosity of the log file - do you log each request, only failures, or every entrance/exit to a function? If the log is to assist in diagnosing the error, it is nice to be able to turn on extra information that would normally just quickly fill up disk space.

Errors should be clear

[__david__]

I agree with what others have said--I don't care about the format too much as long as it's text and has a timestamp in front.

What really matters to me is that errors get logged nicely. "Error number #57575" or even "permission denied" doesn't help at all. It needs to be specific "permission denied while opening file /blah/blah" is infintely better since it lets you actually fix the error without looking something up on google. Speaking of that, if you *do* have some kind of strange error you are reporting and you know it's not going to make sense, at least make it long and unique so I *can* look it up on google. Terseness can be a good quality in a program, but it is *not* a good quality in an error log.

Just remember, the people installing your software and using probably don't the first thing about the way it works on the inside. You have to explain to them what went wrong and give them clues on how to fix it in a short error line.

Oh, it's also nice to have a link back to the original source line that caused the problem. In C, use __FILE__, __LINE__, and __func__ (if you have it) so that if I'm really stumped I can download your source, quickly find the error and start working backwards to find the cause. However, this could get confusing if there are a number of different versions of your code floating around, and it's not as important as the other things I mentioned.

-David

The client was denied access by configuration rule

[Parsec]

To paraphrase an Apache (1.x) error I recently encountered, was: "The client was denied access by configuration rule.".

First of all: which rule did the denial? Second: does the program recall the file or line this rule was in or on? Simply having the text or location of a rule would be a huge help in debugging.

Tips for writing scriptable UNIX programs

[reed]

Related to logging, is program output. If you are writing tools that run at a Unix console, then someday you'll want to run them from scripts and use their output:

1. Use stdout and stderr appropriately: I should be able to run "foo > file" and see warnings on my console, but only get useful data in the file. Don't write messages to stdout if they aren't useful output. C++ has std::clog too. Don't make scripts use "grep -v" to remove random status messages or whatever.!

2. prefix your warnings/errors with the name of the program. So if a bunch of programs run in a script-- or in the background-- you can sort them out.

3. Indicate if something in an error or a warning.

4. Don't get too emotional, unless it's really neccesary:

Bad: WARNING! SOMETHING REALLY HORIBLE HAPPENED! AHH!!!

Good: fooprogram: Warning: Something really horrible happened!

Notice that you can use a ! at the end for emphasis, but it's not obnoxious.

Make reasonable suggestions if you think an error might be caused by user error:

fooprogram: Error: No status file found. (Use fooprogram -s to initialize.)
fooprogram: Error: No response from server at localhost:2323. Did you run it first?

(But try not to be too patronizing!)

5. Use error codes. (in exit() or return from main). Make an enum or #defines somewhere. Document them in the man page and/or --help output.