What guidelines do you adhere to for writing good

Question

I recently found a log statement in my projects codebase that says "here i am with search parameter==>===========11/30/2008===1====00:00 AM"

what guidelines do you adhere to for writing good log messages in an application?

Answer 1

That `log' statement looks more like a trace statement.

Logging: show the normal events and errors

Tracing: show the execution path as well as the all of the logging events

Personally, I want logging to find out what work has been done by my program, and I want trace statements to verify the execution path and for figuring out what went wrong. I'll route tracing statements to a separate file which includes both types of log messages for context.

So you should have 2 log levels at least, and be able to turn off tracing for performance. You should be able to route these event streams to different locations. This allows you to easily keep logs for historical records, while not having them cluttered with debug info that you only want for tracing problems.

A lot of the answers here focus on the fields that you would include in a log message, but I would argue that the placement and logging level of the log calls are more important. If you use log4net you would be able to include/exclude the date stamp at will via config files, but you won't be able to place or remove log statements without recompiling, so it makes sense to think pretty hard about where they go. Beyond the standard fields, such as timestamp and thread ID, etc, you want to know the class and method name that the call was made from. Log4net et al takes care of the class name already if you go by their best practice of naming your logger after the type you are concerned with. Beyond this, I typically include the method name. This is particularly necessary for tracing, but I include it on all my log messages.

Logging:

You want to know enough information about what action is about to be performed to go back and poke around if something goes wrong. Good candidates are message IDs, email addresses, something that uniquely identifies the work item. This sort of message should come as soon as this sort of data is available, so that when you are reading down through a log file, you will see something like 'attempting to do x with y' and then later if we see an exception, we know which work item we need to look at to see why we failed.

Logging exceptions should be paired with an 'attempt' log message, so that the exception message makes sense in context when reading the log. This means thinking about the structure of exception handling. If you are using .net and you only want to log an exception, not handle it, you want to rethrow the same exception, not a new one, so just do 'throw' not 'throw e' where 'e' is your exception instance. Look this one up if it doesn't make sense.

Tracing:

This is actually simpler, usually I'll have a message at the beginning and end of a method of interest, like bookends. In the entry you can print critical method arguments that affect the program flow. Logging a message at the end of a method is kind of optional, usually you will be interested in looking at the trace sort of like a stack trace. You can figure out the execution path without them.

Performance:

For string performance, use the '*Format' methods if you are using log4net or something similar. This internally will use a StringBuilder so that you aren't paying the immutable string penalty all the time. Generally though the key is to be able to turn tracing off for performance, and have logging be terse enough to leave on, even if a log message is expensive. When correctly done, there shouldn't be enough of them to be a problem.