Logging — our most effective debugging tool?

When to log: Requests, Decisions & Outcomes

Logging is about recording activity in the application. For the log to be useful, though, it should record only key information – important & distinctive activity within the application. So, what activity is important?

To answer this, we need to consider what an application or software module does. At the highest conceptual level, we can break it down like thus:

  1. Requests – software serves requests from external users or systems.
  2. Decisions – significant business decisions or logic, affecting the outcome.
  3. Outcome – major outputs, actions or results.
  4. External Integrations – some software talks to external systems, in the course of it’s processing.

Requestsare what comes into the application. This is the difference between GET CUSTOMER, GET ORDER, and DELETE ORDER. Obviously if a ‘SQLException’ occurs, the first information we need is what the request was. Requests & their parameters should be logged first thing – before any of the code involved can break.

Decisions are ‘forks in the road’. Business or logical rules, typically as ‘if’ statements, determine which code path executes. If SAVE ORDER is calculating incorrect shipping amounts, we need to know whether the “overseas shipping” rule executed & the values decided that. Decisions should be logged after being made, including their effects (if immediately known).

Outcomes are important results, outputs or things the application does. When back-ordered product becomes available, each “SHIP PACKAGE” action our application triggers needs to be clearly recorded. Actions/ Outcomes and their parameters should be logged first thing – again, before any of the code involved can break.

External Integrations are interactions with other systems, performed within our processing. Making our software dependent on another system adds potential points of failure – in API or data incompatibility, uptime/ reliability & in network connectivity. For all these reasons, we need to log external integrations and be able to identify which layer (connectivity or data) any problem occurs at. Interactions & parameters (eg, server/URL to connect) should be logged, before anything prone to breakage.

Logging before activities and after decisions, means that any failures will occur shortly after a log-line saying what the program is about to do! You can’t get easier to debug than that.

Following these guidelines, our logging should focus on our software’s interaction with the external world. Logging should primarily be at a business level – of requests, decisions & outcomes.

We include external integrations as a business-level component to be logged, even if of an otherwise technical nature, due to their significant impact on our own software’s reliability & business success.

What to log: Key facts only

Our goal is to illustrate & identify the high-level processing and decisions made by our code. But now we understand when to log, the question is what to log?

Logging must fundamentally inform us of what processes are being performed, what decisions/outcomes have been arrived at; identify what data is being processed; and show key variables involved.

The principles here are brevity & relevance, and our guidelines are:

  1. include only the facts that are immediately pertinent,
  2. identify entities or records being processed, don’t log their full detail.
  3. log the key fields, variables, or factors being processed;
  4. log the key results;
  5. exclude other detail fields/ or children; these should be logged only where they are actually of major significance to processing, and there isn’t a loop or Visitor pattern actually doing the processing which provides a better place to do so.

As an example, we’ll consider logging when placing a customer order. Should we log the customer ID & name? Absolutely. Could we log the ID of the order we’re creating? Yes. Do we need to log the customer’s address & phone? The answer is no, not right now.

Logging other details at this point would just be clutter, rather than crucial information. After all, we can bring it up in the UI or query it from the database in 20 seconds, right?

However, if the next step makes a decision on shipping or tax rates based on the state the customer’s in, we should write a nice clear line in the log that prints the decision made – and the key factors involved. This is the line where it’s correct to log State & Country – but to keep it tidy, we would still not log any other lines of the address.

What about phone number? If we’re calling out to it, or triggering a human task/ or external integration that relies on it – log it at that place in the code. Otherwise, keep it clean.

One thought on “Logging — our most effective debugging tool?”

Leave a Reply

Your email address will not be published. Required fields are marked *

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <strike> <strong>