loading...

Configuring for Log Levels & Observability

stevemushero profile image Steve Mushero ・2 min read

In the old days, we debugged with console output, logs, and god-knows what other poor tools we had back in the stone age. But having to suffer through this, we learned some good lessons and had some good ideas.

One dearest to my heart as a developer, debugger and ops guy is logging. Most programs log things somewhere, usually to a single log, usually at a single log level, i.e. the log you get is all you’re gonna get; and is probably both too much and too little.

With today’s log and observability tools like Honeycomb.io, ELK, Sumo, etc. of course you can handle, search, and tag a lot more, but this is not unlimited, especially for debugging levels and across networks — you simple cannot send all your debug logging at scale to Sumo Logic. You need more granularity, and ways to change it easily.

The first step people took to improve this was adding log levels, following the the usual hierarchy of INFO, WARNING, ERROR, DEBUG and so on. This helps, much more so if you can change it while the darn system is running (critical on larger, more mission-critical stuff). Store this in your R`edis cache and let admins change at run-time

Next was to add more complex filters and configs with tools like log4j and its clones across various languages. This helps, though often involved complex config files and requires restarts, plus really thinking in advance of what to log where, in what subsystems, what log4j configs, etc. Some of this is fixed now with logstash and external senders, but still messy to me.

I was always more interested in dynamic per-module logging via flags and log levels, because I want the logs I want, when I want them, and not more.

For example, usually I’m mostly interested in a single module or issue, so what I really want is to have ERROR debugging on most stuff, but DEBUG on my code.

This can be done a variety of ways, but we’d often re-use the existing single log level directive with a more complex config line, something like this:

DEF=1:SECURE=2:NET=2:RULES=5

Which means default is low level 1, security and networking at 2, and my rule module at level 5. Very simple; easy to parse, etc. You can even use sub-sub systems, like “Rules/Evaluator=5 to be more specific.

In your code, there’s no need for If-then/Macro logic (just like using log4j, etc.), so you just send send everything to the logger, tagged with its log level and module name (via introspection or other language-specific magic).

Then in the logger, you check the module and log level tag and emit what the configuration calls for. You can always spice this up with different configs by channel, e.g. what to send to standard out vs. syslog vs. to the DB, etc.

That’s it. Too bad I almost never see this in any of the hundreds of tools and systems I’ve run over the years, including a long list of current ones I’d love to have this included in.

Posted on by:

stevemushero profile

Steve Mushero

@stevemushero

Global Technologist based in Shanghai & Silicon Valley. Been in tech for decades, often as CTO or Chief Architect, building things in many industries from construction to manufacturing to insurance to health care to all types of Internet systems. Been CEO of ChinaNetCloud for 9 years, as AWS's only MSP Partner in China and a global operator of large-scale systems. Now launching OpsStack, a Unified Ops Platform (www.opsstack.io)

Discussion

markdown guide