@DevOpsSummit Authors: Yeshim Deniz, Zakia Bouachraoui, Liz McMillan, Elizabeth White, Pat Romanski

Related Topics: @DevOpsSummit, Containers Expo Blog, @CloudExpo

@DevOpsSummit: Blog Post

Ditch the Debugger and Use Log Analysis Instead By @MatthewPSkelton | @DevOpsSummit #DevOps

The applications we're developing and running are becoming increasingly distributed

Ditch the Debugger and Use Log Analysis Instead
By Matthew Skelton, Co-founder and Principal Consultant at Skelton Thatcher Consulting.

Summary: As a Developer, you cannot attach the debugger to your application in Production, but you can use logging in a way that helps you easily diagnose problems in both development AND Production. You also get to make friends with Operations people - win!

The applications we're developing and running are becoming increasingly distributed, with requests crossing several service or container boundaries. The traditional debugger is of limited use in these scenarios, but with a solid, easy-to-use log aggregation capability in place, we can begin to explore ways of using logging to improve our understanding of how the software behaves in Production and enhance our ability to diagnose problems rapidly. Logging becomes not just a ‘dump' of exception or error details, but a rich trace of application execution.


There are three key parts to this modern approach to logging:

  • Event type IDs
  • Configurable log severity levels
  • Transaction tracing

We'll now look at each of these facets in turn.

Event type IDs
Event type IDs are values that represent specific application states, typically based on anenum. Each application state has its own ID, unique to that application (or suite of applications). Event types include both technical and domain events, so we might define a set of Event type IDs like this:

public enum EventID
// Badly-initialised logging data
NotSet = 0,

// An unrecognised event has occurred
UnexpectedError = 10000,

ApplicationStarted = 20000,
ApplicationShutdownNoticeReceived = 20001,

PageGenerationStarted = 30000,
PageGenerationCompleted = 30001,

MessageQueued = 40000,
MessagePeeked = 40001,

ItemAddedToBasket = 60001,
ItemRemovedFromBasket = 60002,

CreditCardDetailsSubmitted = 70001,

// ...

We use an enum because we can represent application states with both human-readable memorable values (like ApplicationStartedand integer values (like 20000), and enums (generally) allow a sparse numbering scheme, with gaps between blocks of IDs. This means we can represent all application startup/shutdown states with (say) event IDs 20000-29999 - with over 4 billion integers in a typical enum space, we are unlikely to run out of IDs!

Any and every ‘interesting' application state is captured with a call to the logging subsystem, passing in the event type ID (for instance, ApplicationStarted or 20001):

logger.Message(EventID.ApplicationStarted, ... );

This means we can search easily for specific application states (using the exact event type) but also groups of application state, such as "Message*" to find MessageQueued,MessagePeeked, and so on, assuming we name the enum values consistently.

Configurable log severity levels
One thing I have always found baffling when writing application code is the need to specify the log severity level at the point where the log call is made. As a developer, why should I be forced to make a decision about log severity before the application is run? Surely log severity is dependent on context, or might need to change after deployment?

It turns out to be pretty straightforward to decouple log severity levels from log events, and it's something I have been doing for many years. We store the severity level for each event type ID in configuration, and do a severity lookup when a log call is made. Here is some example severity configuration in JSON:

"eventmappings": {
"events": {
"event": [ {
"id": "CacheServiceStarted",
"severity": { "level": "Information" }
}, {
"id": "PageCachePurged",
"severity": { "level": "Debug" },
"state": { "enabled": false }
}, {
"id": "DatabaseConnectionTimeOut",
"severity": { "level": "Error" }
} ]

When we come to log an event, we simply provide the event type ID and the message, and the underlying logging setup does the severity mapping:

DecoupledLogger.Log(EventID.PageCachePurged, "details");

In this case, our logging subsystem looks up the severity for PageCachePurged and finds it to be ‘Debug'; however, it also sees that logging for this entire event type ID has been disabled (enabled: false) so no message is logged at all. This is great for tuning log events after deployment; we do not need to recompile our code, and different environments can have different severity levels if we want (useful for things like Performance testing, where we care about specific events).

Transaction tracing
With applications becoming more distributed, we need to be able to trace the logical execution of a single request or callback across service and component boundaries. A simple and effective way to do this is with a transaction trace (or correlation) ID which we inject at the start of the request, and then log at each component. The ID needs to be ‘unique enough' for the time window we're likely to consider, so although a UUID/GUID would work, such an ID is probably too long and certainly is too tricky to type into a search dialog. When we search for the ID, we can be sure that every log entry containing that ID (within that past say 15 minutes) represents part of the original, traced request, allowing us to reconstruct the request ‘after the fact' - very useful for both developers and operations people!

Enable Learning and Collaboration Through Logging
Application Performance Management (APM) can be great when used effectively; the insights into application performance can mean the difference between fixing a performance problem and having to scale out the number of VMs to cope with increased load. However, if APM is used only in the Production/Live system and not in upstream environments (due to cost, complexity, etc.) then APM tends to become a kind of ‘magic' that is hidden from developers. This ‘singleton tool' approach effectively means we lose out on learning and reasoning about the software system, and a crucial route to improvement is lost.

Instead of ‘painting on' APM in the Production environment, we can use the techniques mentioned above - event type IDs, configurable log severity levels, and transaction tracing - to help us discover how the system really works, opening the door to ‘third-way DevOps' feedback cycles for learning and improvement. It also means that developers and operations people use the same tool - log aggregation - to diagnose problems both in development and in Production, bringing Dev and Ops closer together.

Logging done well, with a good log aggregation tool, is the ultimate DevOps technique.

More Stories By Trevor Parsons

Trevor Parsons is Chief Scientist and Co-founder of Logentries. Trevor has over 10 years experience in enterprise software and, in particular, has specialized in developing enterprise monitoring and performance tools for distributed systems. He is also a research fellow at the Performance Engineering Lab Research Group and was formerly a Scientist at the IBM Center for Advanced Studies. Trevor holds a PhD from University College Dublin, Ireland.

@DevOpsSummit Stories
Sanjeev Sharma Joins November 11-13, 2018 @DevOpsSummit at @CloudEXPO New York Faculty. Sanjeev Sharma is an internationally known DevOps and Cloud Transformation thought leader, technology executive, and author. Sanjeev's industry experience includes tenures as CTO, Technical Sales leader, and Cloud Architect leader. As an IBM Distinguished Engineer, Sanjeev is recognized at the highest levels of IBM's core of technical leaders.
Andrew Keys is Co-Founder of ConsenSys Enterprise. He comes to ConsenSys Enterprise with capital markets, technology and entrepreneurial experience. Previously, he worked for UBS investment bank in equities analysis. Later, he was responsible for the creation and distribution of life settlement products to hedge funds and investment banks. After, he co-founded a revenue cycle management company where he learned about Bitcoin and eventually Ethereal. Andrew's role at ConsenSys Enterprise is a multi-faceted approach of strategy and enterprise business development. Andrew graduated from Loyola University in Maryland and University of Auckland with degrees in economics and international finance.
DXWorldEXPO | CloudEXPO are the world's most influential, independent events where Cloud Computing was coined and where technology buyers and vendors meet to experience and discuss the big picture of Digital Transformation and all of the strategies, tactics, and tools they need to realize their goals. Sponsors of DXWorldEXPO | CloudEXPO benefit from unmatched branding, profile building and lead generation opportunities.
The best way to leverage your Cloud Expo presence as a sponsor and exhibitor is to plan your news announcements around our events. The press covering Cloud Expo and @ThingsExpo will have access to these releases and will amplify your news announcements. More than two dozen Cloud companies either set deals at our shows or have announced their mergers and acquisitions at Cloud Expo. Product announcements during our show provide your company with the most reach through our targeted audiences.
DXWorldEXPO LLC announced today that Telecom Reseller has been named "Media Sponsor" of CloudEXPO | DXWorldEXPO 2018 New York, which will take place on November 11-13, 2018 in New York City, NY. Telecom Reseller reports on Unified Communications, UCaaS, BPaaS for enterprise and SMBs. They report extensively on both customer premises based solutions such as IP-PBX as well as cloud based and hosted platforms.