From Nick: discuss the spectrum from pure machine-readable structured data to free-form sentences and how that impacts consuming logs later.

Logs are a story your applications write for you to read. Like anything else you would read, the way you read an application's stories will vary depending on what you want to get out of it. There are three reading styles you should to consider when authoring log messages: skimming, scanning, and comprehensive reading.


Reading quickly to get a general idea of the plot. When you are skimming, you generally don't know what you're looking at to start with, and the goal is to get yourself oriented within a particular volume of text. To do this quickly, you don't read every word of every message. Perhaps you read just the names of the components or functions that are emitting log messages to help you understand which parts of the system are invoked in the handling of a specific transaction...

To promote easy skimming, your log messages should contain broad contextual information relevant to your application. This may mean logging class and method names, detail on the lifecycle of an important object, or estimated progress toward servicing a request.



Reading quickly to find a specific piece of information. When you are scanning, you already know what you are looking for, you just don't know where it is. For instance, say you are investigating an issue [XXX example].

Tools can help you with this, of course. You could always search for foo, but most of the time, the story you're interested in will take more than a single log message to tell. As much as possible, try to format your log messages such that you can quickly discern relevant and irrelevant information with your eyes as well as with your tools.

To promote easy scanning, you want log messages with consistent formatting and well-delimited contextual information.


One trick here is to consider what log messages look like when they are read in sequence, not just what they look like on their own or in the code. A typical logging pattern is to prefix a log message with several pieces of context, e.g. log level, component, class, method, etc. Let's look at two possible ways to format such information.

[XXX improve example... add noise, mostly]

2001-01-01 00:00:01 INFO TransactionProcessor ThingExtractor.thingFind() found thing 'foo' with key 'bar'
2001-01-01 00:00:02 DEBUG TransactionProcessor ThingExtractor.thingFind() find took 2.71 ms
2001-01-01 00:00:03 INFO TransactionProcessor ThingOpener.thingOpen() thing 'foo' opened successfully in 3.14 seconds
2001-01-01 00:00:04 INFO UnrelatedComponent SomeUnrelatedClass.someUnrelatedMethod() found something unrelated to the story
2001-01-01 00:00:05 ERROR RequestHandler ThingRequest.handleFind() error: timed out 
2001-01-01 00:00:01 INF [TransactionProcessor] ThingExtractor.thingFind() - found thing - id="foo" key="bar" - took 2.71 ms
2001-01-01 00:00:03 INF [TransactionProcessor] ThingOpener.thingOpen() - opened thing - id="foo"' - took 3140.00 ms
2001-01-01 00:00:04 INF [UnrelatedComponent] SomeUnrelatedClass.someUnrelatedMethod() - found something unrelated to the story -
2001-01-01 00:00:05 ERR [RequestHandler] ThingRequest.handleFind() - error: timed out -

Which of these is easier to scan when looking for the following information?

[XXX talk about why]

[XXX Probably talk about the "main log message", not sure where...]


Reading carefully with the intent to gain a complete understanding. When you are reading comprehensively, you are reading most--if not all--of the content in a particular section. You have probably scanned and skimmed through the surrounding text to find a specific part of the story you are trying to fully grasp, and you now want to internalize all the details.

[XXX Examples don't make so much sense here, I think the point is to talk about how you want to put a lot of detail in here so that when you come back to read the logs, you have all the information you might need to reconstruct not just the current state, but how you got to the current state (the bug isn't where the problem is, it's several steps that happened before that went against assumptions). The main point here to get into is how to add that much detail without compromising your ability to skim and scan...]


(restate). In the discussion above, we looked at techniques which take into account the different approaches humans take when reading to improve understanding. In the next section [structured logging], we will look at how to make our log messages easier for our tools to understand, too.