Log identifiers, not detail

One of the most effective ways to make logging more concise, and better focus on what’s important, is to summarize & exclude irrelevant detail. But what if that minor detail (some field, perhaps) turns out to be relevant?

The answer is that logging an identifier (or ID) with our summary, enables us to uniquely identify the record. We can easily retrieve the record & examine it.

Identifying the record, for most purposes, enables us to have a complete picture of it’s current state. Assuming that any activity which changes or updates that state is also logged, we have reasonably reliable information as to the state of the record at any given time.

Primary keys are the most common kind of identifier, used by databases or computer systems. Primary keys provide a guaranteed unique ID, often in the form of a sequential integer, to identify & retrieve an entity. Sequential integers are technically very effective, but are difficult for humans to read or remember.

In the human world, we use names. Names or titles are easily recognized & understood by humans, making it a great deal easier to follow & understand the activity being logging by your application. Names are mostly (but not fully) unique so you should always log the primary key as well.

The most effective approach in logging is to summarize entities, by both their system & human identifiers.. ie, their primary key and name. (We should also include entity type, where not otherwise obvious).

This produces a compact, yet supremely clear & understandable log output; and if we do need to reach for more information, we have the primary keys right at our fingertips.

One of the basic features of the Java language is the toString() method. We can design our toString() methods to return a suitable compact identifier or summary, enabling us to build log messages very easily.

Assuming we implement our toString() methods in a suitable format, we can build log messages very easily by just appending the object.

An example of logging output:

new basket: [id=5157 James Brown], basket=51
add to basket: basket=51, [HardwareProduct id=3194 Dell Xeon quad-core server]
add to basket: basket=51, [SoftwareProduct id=721 RedHat Enterprise Linux]

Logging types in this example, enables us to distinguish products with minimal shipping costs (software) from products with significant physical weight & space requirements. This is a simplistic example and real-world requirements may obviously differ.

Conclusion

Logging provides a means to record and “gain visibility”, into the internal operation of our program code. Logging code can be implemented once, but gives a productivity payback on each subsequent development task.

Focusing our logging to show key activities & facts, helps us maximize the high-level information we can see easily.

Log analysis, prior to a stacktrace, should be able to identify most of our problems;  or else get us very close to the vicinity of the remainder.

(You might still have to use your debugger occasionally.. but having logging tell you clearly which item/ or iteration you’re at, makes it easy to see when you’re in the right place to debug!)

What we’re trying to show here, is a simple set of principles that will give you (and your fellow developers) a better insight into how to write useful logging.

To summarize:

1. Log “information”, not “data”
2. When to log: Requests, Decisions, Outcomes plus any External Integrations
3. Log before activities, and after decisions.
4. What to log: Key facts only
5. Log identifiers, not detail

I hope these guidelines give you some food for thought, on writing logging in your own applications.

How have you managed clutter & kept logging informative in your project? Add your thoughts now.