Misconceptions re. Application Logs

Osher El-Netanany
Nov 8 · 9 min read

Logs are one of the first-ever features of software. As such they have evolved a long way, and thus, are shrouded with misconceptions rooted in the past. To take advantage of this evolution , we should acknowledge these misconceptions and the cost they harbor, so we can shake them off and adopt the modern trends, tools and practices, and the benefits they bring.

Start with some history:

In the beginning, the earth was empty and void…

…too far back? Well, around back then we employed scribes for logging into stylish scrolls. Every word was expansive and full of meaning. Please just keep that in mind as we skip a debatably short time forward…

…then, the age of information has dawned and software was writing logs to text files.

It was after all the age of information — and information was first and foremost meant for humans — so it was preliminarily kept as text. After all—in that time — it was a human that would need to make sense of them, so it was obvious to keep log messages in a format accessible for humans...
…call it the UX 101 of the day.

Since then, the age of big data has set in, and saving of information have gone a long way — i.e — people discovered that sifting through piles of log data takes people a long time, even if they are master wizards of grep/egrep, so people started saving information in formats that machines could consume better and do the searches for them, (and before you know it — the database was born, but that’s a story for another time).

Anyway, not everybody got the memo, or got it and ignored it because it did not fit well with their concept of logs, and stayed behind.

Lets disregard the artistic leniency for a minute, and acknowledge that for a disturbingly long time, logs were — and alas often still are — regarded as text messages consumed directly from files, mainly by humans.

And that misconceptions that anchor us in the past with rather implications.

Misconceptions regarding Logs

logs are files — WRONG!

Yes, they used to be, and often are. But that’s not a rule.

Logs are often not written to local files at all, but emitted to a remote service. I’ve personally seen logs sent to SQL tables already around year 2000. Even now you can commonly find in-proc log appenders that emit to a collection of noSQL DBs or ones that emit via API to a 3rd party service (datadog, logsio, logly, sumologic, cooladata, etc…).

I consider that an antipattern: it couples your application with an implementation detail of logs shipping, and probably with that a provider as well.

It requires you to include in your distribution the means to ship logs —most notably 3rd party libraries and creds, none of which is truly related to the goal or function of your app.

Even when it’s wittily and elegantly configurable — it unwittingly ships all the code that supports all these options, whether they are relevant or not.
Especially in the world of microservices and ops — all this could be managed by the infrastructure level, keeping the app generic, modular and agnostic.

On top of that —using an in-proc shipper you might still miss messages and warnings emitted to stderr/stdout, notably by 3rd level packages, and often during critical stages of startup and shutdown.

The takeout is that log-shipping is not a concern of the app. Nor is managing local log files, nor log-rotation.

Apps used to do it circumstantially, but it has never truly been their concern, but a gap they had to fill.

The modern approach — The app should just provide the log stream, and it’s up to the user (usually Ops) to handle everything from there.

It may still be a concern of the app under specific circumstances — e.g. a standalone CLI or a desktop appliance — but since applications started like this it has been taken for granted and rolled on without questioning.
However, this is an archaic practice and is especially unsuitable for cases like a micro-service or for a serverless function.

Here I must note that many Ops policies still require to pass through hoardable files — but that’s their concern, and they can do it by piping stdout/stderr to a rotatable hoardable file the good-old way (heck, docker even does that out of the box), and ship it from there on their own terms.

logs are essentially text — WRONG!

Well, kind of. Like all misconceptions here, it’s because they used to be, so we just kept doing what we did before.

The crucial thing is that even though they tell a narrative, they are no longer message-strings being print as text — but — events being described by property-bags. The confine of the past makes us think of them as text, however, what they logically are : events.

So yes, in most cases in the end of the line they are serialized to text — but that’s an implementation detail, not a purpose: not only that the text thing about it is no longer the essence of it, it’s quite often not even text. I daresay further, that even when they were text — they were still a representation of a data-structure.

Lets explore further. The data-structuring of the old-world was string format — i.e — embedding values into strings formatted for humans. The protocol of the logs became that human-readable format. A logger implementation that did not support string format was shunned as a feature-low logger.

Think of it for a minute, let it sink in: It’s like asking an MVC framework to feature for web controllers the extensive templating API expected for templates…

The result is not just bloat of logs libraries and pseudo-chivalrous practices around that bloat, but mainly that any automated tools that go over logs meet log messages in that protocol — which is tainted in human syntax, and is context-dependent, and therefore ambiguous and harder to parse. Even when machines get better in that — they do it in a lot of effort and unnecessary resource footprint.

The implication is that there’s a whole field of disciplines and tools to do that (logstash, filebeat, fluentd — just to name a few), that could be cut out to demand so much less resources from it — if only logs were emitted in a format that is generic, common, compatible — i.e. easily sorted out by machines.

So lets face the elephant in the room — JSON.

In fact — appenders do not have to use JSON. It could be bson, protobuff or any other format — but still, many of them choose JSON.
Despite it is just an implementation detail of the emission process, JSON has surfaced to become the default form because it IS a generic, common compatible standard.

It is the middle-ground: still somewhat intelligible for humans, and easily parsed by machines.

The takeout is: apps should emit logs as structured data that keeps parsing obvious and generic. Probably JSON.

Include in production code only tools to do just that.

Your instinct might tell you to object, but that’s because of the next misconception.

logs are essentially read raw — WRONG!

Here again — yes, they used to be, and because of that they too often are, and without any good reason.

CLI tools often emit text — and this text often are read raw — I’ll give you that. But already now for quite a while CLI tools format their output with color, where the more fancy CLI-tools let you specify a reporter that emits a machine-readable output. Examples? Test runners, Code-Coverage & Static-Code-Analyzers just to name a few tools a developer should meet every day. Same goes for ops: orchestrators, monitors, cloud-ops-SDKs and more. All support JSON output.

But beside output of CLI tools — nowadays, the only ones that still read logs raw are developers who run software-under-development on local-machine, which is not connected to any visualization solution (yet).

In modern places, everything — the Dev-Servers that run feature-branch builds, the QA env that runs the stable-trunk, the staging, and obviously, Prod — are all connected to some log-centralization & visualization solution.

But what about early development? Don’t kick-start developers need to read logs?

True — when your app outputs a JSON stream it makes it easier for machines to consume, but less readable for us, humans — but what is the difference between
a) shipping logs to a database and using a software to visualize them ,
— and —
b) piping the JSON log into a CLI tool that provides a readable format ?

Consider a simple tool that accepts JSON in stdin and outputs a format structured for the human eye, and decorated with colors.
Actually we start to see logger implementations that feature such CLI-tool out of the box alongside its basic toolbox of appenders and emitters (example).

The takeout here is that in the modern world log-formatting is not a concern of the app: It is reduced to data-structuring.

Formatting and Visualization are moving away from production code to external or local utilities.

Heh. Nostalgic for the sprintf days?
Well, we debate about controllers and views and presenters and models, and do everything to keep formatting of views separated from the data. But when it’s about logs — why do we allow a sub-standard?

Just one more log line is insignificant — WRONG!

Definitely wrong for a web-endpoint or a queue consumer. Maybe for CLI tools. Maybe. If they are not ran regularly as a part of a pipeline…

In short — each log line emitted is processed further down the pipe. Either because you parse it, index it and visualize it by visualization applications, or you have to learn to ignore it over and over when it’s not what you’re looking for (or filter it out in your cool visualization UI). And all these things sum up and cost time and money.

Sisyphus, put that rock down, have a rest.

I’m not telling you not to log, just to make sure every entry brings all the value it can, for it’s cost. This misconception is so elusive yet strong that it deserves it’s own future post. We will get back to that in the future.

On Top of Logs

You have to keep in mind the takeout points, they all come with perks.
Basically, they all boil down into this:

Emit data structured in a machine-readable format, preferably — solely to stdout.

But the implications come in two levels:

Level 1: Logs of the Pro

  • structured data helps you retain context
  • logging relevant information keeps you in focus
  • Colors make logs fun:
    ▶ visualization apps — make logs accessible
    stdout stream beautifiers — make fun also for local development.

The stress is on the separation between two concerns: log emissions and log visualization.
In the old world, the logs were the visualization: What you wrote to the log file was what you read later, so it got common to format data in ways that are easier for a human reader to process, and that propagated up all way to the application code.
We grow out of it by keeping this separation, and this brings us to the Level 2

Level 2: the mechanized reader as a stakeholder

Once your distribution provides machine-readable structured data — a lot is delegated to specialized tools: from the visualization, all way through aggregation and analysis, and further down to monitoring.

Treating logs like data allows very powerful logs querying,
— which in turn —
facilitates getting machines to:

  • perform for us reports and visualization efficiently
  • detect crossed thresholds and execute for us automated responses

Conclusion

The software industry — as innovative as it may be — still inherits archaic misconceptions and follows some unquestionably old habits that no longer serve us. Questioning these concepts and habits is the key to moving forward. Despite (or even because) logs were here before software — they should be questioned too.

You may want to check my previous post about logs. The next post is planned to deal with the verbosity challenge.

Everything Full Stack

The place for everything full stack.