Creating Good Log Messages

Sometimes a bug emerges at a customer site and the support staff sends me a log session and a set of recreation steps to figure out the bug. With rich log messages, that provide indication of what and where the application failed, am able to understand the bug and ultimately fix it. This has lead me to understand how important log messages are in an application.

There are tones of article emphasising on the importance of good programming practices etc but very little about logging practices. On this post am going to describe a good log message based on my experience.

To start with, a few rules that you should follow when logging;

1. Log messages should be short and precise.
2. Avoid spelling mistakes in the logs.
3. Provide fatality levels in your messages. This will help the support analyst to rate the bug/issues severity.
4. Avoid fancy characters in the log messages .
5. Avoid logging your messages to the database, this cost space and reduce performance.
6. Always have a consistent format for your logs. this helps is keeping uniformity

Here is how a good log message should appear:

ERROR|| DATETIME: 22-Aug-2012 13:24:24 || DESCRIPTION: Could not write to output file 'C:\thisfolder\myfile\report1.txt', 'The directory name is invalid.' || SOURCE: Report.SaveReport || PROCESSID: 3456 || PCNAME: Mark-laptop||  USER: Mark || BUILD VER: 2.1.1 || OS :  Windows 7 Version 6.1 Build 7600

 

LOG MESSAGE BREAK DOWN

You will realise I have used a double slash to segment my message, this is to make it readable. Lets break down the sample message and look at it bit by bit.

SERVERITY– This is the first section of the message indicating ERROR. It is very helpful in determining the importance of the message at a glance.

DATETIME: It is the date and time when the error occurred. This is important in case you would like to know the frequency of error or even tag it to a certain external process or event.

DESCRIPTION:  This is a test message of what happened. This can be the runtime  message generated by the debugger or a custom message by the developer.

SOURCE: The code location that generated this message. This will save you a lot of time figuring out where you need to look in your code. In my case I have used the class_name.method_name format.

PROCESSID: In case you have several processes it good to know which particular one is being a nuisance.

PCNAME: This gives you the machine where the error occurred. You could also provide the server name just incase your logs come from different hosts.

USER: An identifier of the user logged in, this is important if you want to track a users actions within the session. You could use a session id instead of a username like I have done.

BUILD VER: This is the code version running. This is very important as the location in the log may be for a different version of code from what is currently running.

OS: Some bugs are tagged to Operating Systems therefore it is important o know what platform the user was on.

 

Most of the time we rely on the debugger to fix our bugs but suppose a bug occurs in site and you manage to fix it through the information provided by the logs. This is the reason why we should always improve the content to provide as much information as possible.To do this think about what information the log provided, evaluate if was it was helpful and find out if more content be appended to make it even more helpful.

Making the log rich enough may not be your priority because  as the developer you have the debugger,  but it a very important aspect for the support team and the customers too. You will be shocked at how may issues the support team can resolve at site just because they can make out what the problem is. This makes it easier for you as a developer and you can concentrate on more relevant issue.

Those are my thought about log messages. If you may have anything to add please drop me a comment.