What logging is good logging for your app?

Question

So we've discussed logging in passing at my place of work and I was wondering if some of you guys here could give me some ideas of your approaches?

Typically our scenario is, no logging really at all, and mostly .NET apps, winforms/WPF clients talking through web services or direct to a db.

So, the real question is, where or what would you log? At the moment we have users reporting error messages - so I would assume log startups/shutdowns, exceptions...

Do you take it to calls to the web services or db? Page loads?

How do you get a good idea of what the user was trying to do at the time?

Is it better to go all the way and log everything across multiple attempts/days, or log only what you need to (given hdd is cheap).

I guess that's a few questions, but I wanted to get more of an idea of what the actual practice is out there in larger shops!

Answer 1

G'day,

As a quick answer I would say to come up with a series of categories and have switchable logging levels, e.g. info, warning, error, critical, etc.

Then make it easy to set the logging level to tune the level of detail that you need. Typically, set the logging level in a config file and stop and restart the app.

I would also pulicise to the dvelopers what the meaning is for each of the levels.

edit: I would also set up a system to rotate out, compress and archive log files on a regular basis, maybe nightly.

cheers,

Rob

Answer 2

For a typical desktop app, I'd store everything on the current session, and maybe store info messages for the past n sessions or up to x in size.

I'm assuming that your messages are organized. We use 4 categories; errors, warnings, info, and trace. We're still figuring out what goes at which level. As I'm getting used to parsing log files, I generally say "log more". Don't sweat readability, you're probably gonna have to process the log file a bit before you can use it.

In the end, find a good logging framework that allows you to control your spool usage on lifetime and storage space, and a proper api that minimizes the effect on your code. Ideally you just type info("waaah") or warning("waah") and the API does all the fancy tagging for you.

Answer 3

The key thing for logging is good planning. I would suggest that you look into the enterprise library exception and logging application block (http://msdn.microsoft.com/en-us/library/cc467894.aspx). There is a wee bit of a learning curve but it does work quite well. The approach I favour at the moment is to define 4 priority levels. 4=Unhandled exception (error in event log), 3=Handled exception (warning in event log), 2=Access an external resource such as a webservice, db or mainframe system (information in event log), 1=Verbose/anything else of interest (information in event log).

Using the application block it's then quite easy to tweak what level of priority you want to log. So in development you'd log everything but as you get a stable system in production, you'd probably only be interested in unhandled exceptions and possibly handled exceptions.

Update: For clarity, I would suggest you have logging in both your winform/wpf app and your webservices. In a web scenario, I've had problems in the past where it can be difficult to tie an error on the client back through to the app servers. Mainly because any error through webservices gets wrapped up as a SOAP exception. I can't remember off the top of my head, but I think if you use a custom exception handler (that is part of the enterprise library) you can add data onto exceptions such as the handlinginstance id of the exception from the app server. This makes it easier to tie up exceptions on a client back to your app box by using LogParser (http://www.microsoft.com/downloads/details.aspx?FamilyID=890cd06b-abf8-4c25-91b2-f8d975cf8c07&displaylang=en).

Second Update: I also like to give each different event a seperate event id and to track that in a text file or spreadsheet under source control. Yes, its a pain but if you're lucky enough to have an IT team looking after your systems in production, I find they tend to expect different events to have different event ids.

Answer 4

Is it better to go all the way and log everything across multiple attempts/days, or log only what you need to (given hdd is cheap).

The fact harddrives are cheap really isn't a good reason to verbosely log everything possible, for a few reasons.. For one, with a very busy application, you really don't want to slow it down and tie up disc-writes writing logs (harddrives are pretty slow). The second point, and the more important one - there's really very little to gain from terabytes worth of logs.. For development, they can are useful, but you don't need to keep more than a few minutes of them..

Some logging is of course useful, having different levels is about the only way to go about it - for example debug() info() only get logged if requested (in a config, or command line flag), then maybe warning() and error() get sent to a log file

For most of the things I've written (smallish scripts) I generally just have a debug() function, that checks if --verbose is set, and prints the message.. That way I can shove debug("some value: %s" % (avar)) when needed, and not have to worry about going back and removing debugging print() statements everwhere.

For web applications, I generally just use the web-server logs for statistics, and the error log. I use things like mod_rewrite's log when needed, but it would be idiotic to leave this enabled beyond development (as it creates many many lines on each page request)

I suppose it depends on the application itself, but generally, for big applications use multiple levels of logs that can be activated when needed. For smaller things, a --verbose flag or equivalent, for web applications, log errors and (to a point) log hits.

Basically, in "production" log only the information you can use, in development log everything you could possible need to fix problems.

Answer 5

This post on highscalability.com provides a good perspective on logging in a large scale distributed system. (And coincidentally it starts out by mentioning a post on the JoelOnSoftware).

Answer 6

Being an admin, I really appreciate apps that log to the Event Log (preferably their own, otherwise the application log) for all logging but trace logs. By logging to the event log, you make it much more likely that warnings or errors can be found and addressed by the admin staff before they become a major problem (if it is a issue they can address), or allows them to get in contact with the devs, who can use the trace logs to further troubleshoot the issue.

My biggest pain point in supporting a custom .NET app right now is that there are 8 different applications (some console apps, some winforms, and some web) from the same vendor. None of them log to the event log, they all have their own custom log files. But for all the winforms and console apps, they keep the file open while they are running, so I can't monitor it for issues. Also, the logs are all written slightly differently, so I would have to parse them a bit differently to get useful information.

This forces me to monitor the appearance of an application (is it responding on the ports it is active on, is the process working set getting too high, etc..), rather than what the state of the application really is.

Please, please consider the folks who maintain your application after it is deployed and provide logging they can use. Thanks!

Answer 7

Thanks guys, lot of good info, but Martin has given me a bit more detail on how to proceed. I'll give him the answer, as it seems like now we're off the front few pages answers will drop off.