The logging work nobody demos at a conference

At a conference a while back we sat through an OpenShift demo: install the whole platform with Ansible, one command, and it comes up clean. Then you read the playbook and the validation flag is off, so nothing gets validated. Of course it installs. Turning validation back on, with SELinux configured, took us months to get working. Conference demos are greenfield and the presentation almost always works. Nobody books a two hour slot called “getting the logs out of your cluster”, even though for a lot of teams that is close to a full time job.

Meanwhile observability is sold as three pillars: logs, metrics and traces. Three pillars is a shopping list. If you can only fund one, you need to decide which question matters most. Underneath the list is a sequence of decisions. What does the application write down. Who picks it up off the node. Where does it land. What do you open when the pager goes off. And which of the three gets the budget. Get that order wrong and you spend a year building a log pipeline that still can’t tell you why one request took nine seconds.

Our answer to the last question, up front: tracing. It’s also the one most teams schedule last, after the ELK cluster is already running.

Decide what the log is for before you write the line

Start with the cheapest decision, the one that happens in the application before any pipeline exists.

What should you log?

The events you would act on: an error someone has to debug, or a transaction that moved money.

Most logging gets written the other way round. The framework prints what it prints, the team adds a line whenever something feels interesting, and the volume question arrives later as a bill. Go through a day of production output and ask what each line would change if you read it. Call it 99% useless and three lines you actually want: that’s the shape of what you find, not a measurement anyone took.

Health checks are the clearest case. The load balancer asks, the application answers, and then the application writes it down: got a request from the load balancer, got another one, and one more, health check still passing. Seven or eight lines a minute per target, all reporting the state you already assumed, filling the index, the bill and the screen you’re trying to read during an incident. You end up filtering them out before the log is usable at all.

Structure beats whatever your framework prints

Once you know which lines are worth keeping, the next argument is about their shape.

Why does structure matter more than the format you pick?

Because structure is what lets everything downstream read a line the same way, while a free text stream needs a new parser per source.

JSON on stdout is the common pick: the grammar is simple, every language has a library, and it’s easy rather than fast to parse. It isn’t the only option, and the requirement is weaker than the usual argument suggests. Have a format, not a stream. JSON also archives well, since a file of JSON lines gzips down to very little, and that’s exactly where it gets awkward to query. Cheap to archive or quick to query is the trade-off to settle before you choose a store.

The alternative to structure is regular expressions, which is where log pipelines go to die. If you have a problem and you solve it with a regex, now you have two problems. Six months later nobody on the team can read the pattern that pulls the status code out, and nobody wants to touch it.

Field names are the part that gets skipped. One service writes ip_address, the next writes ip, a third writes remote_ip, and every incident query becomes three queries and a union. Agree the names across the company the way you agreed the format.

Collect on the node, not inside the pod

The line exists and it has a shape. Now get it off the machine before the machine takes it away.

Where should log collection live in a Kubernetes cluster?

In one agent per node, shipping to storage that has a lifecycle of its own.

The container runtime writes container output to files on the node, and that’s all you get by default. When a pod is evicted its containers are evicted with it, and their logs go too. The Kubernetes logging documentation is direct about why cluster level logging exists: log storage needs a lifecycle independent of nodes, pods and containers. Stitching logs back together from individual nodes by hand is not a place you want to be.

Legacy applications that insist on writing to a file need a volume in the pod and a second container that reads it. From there, two patterns. The sidecar routes what it reads straight to the backend that stores the logs, or it prints what it reads to stdout so the node agent collects those lines like every other container’s. The second keeps one collection path to debug instead of two.

For the agent itself, the numbers are in Fluent Bit’s own comparison: Fluent Bit is C with around 650KB of memory, Fluentd is C and Ruby, packaged as a gem with gem dependencies, at around 40MB (Fluentd and Fluent Bit, Fluent Bit 1.7 docs). One shape that works: Fluent Bit as a DaemonSet that only reads and forwards into a queue, then Fluentd behind the queue doing the parsing. The DaemonSet is one pod per node and can’t be scaled out. The tier behind the queue can.

The option worth taking seriously is to run none of it. A managed platform runs the log pipeline for you, and on the provider’s side there are people paid to work on log infrastructure full time, which is a thankless job to own yourself. As far as we’ve seen, Google Cloud wires cluster logging up with a checkbox. On EKS, the setup we’ve run is a Fluent Bit DaemonSet you deploy yourself, with a queue and a parsing tier behind it if the parsing warrants one. That’s a choice, not a platform requirement: for EKS on Fargate, AWS shipped a built-in Fluent Bit log router in December 2020, configured through a ConfigMap in the aws-observability namespace with no sidecar to maintain.

Every service you split multiplies what you log

Collection has known parts and known costs. Volume is the part that gets away from people.

Why does logging get worse as you add services?

Because splitting one service into two turns one event into several: you log that you sent the message, log that you received it, log that you replied.

Keep splitting and the networking and storage cost climbs with the service count, far enough that you run out of money before you even have a problem. The objection arrives immediately: why log the receive at all, when that’s exactly what tracing records? Which is the point. Logs are the wrong instrument for the question “what happened to this request across six services”, and reaching for them anyway is what makes logging in microservices expensive.

That context is more than one shared id. W3C’s trace context recommendation, a Recommendation since February 2020, carries two identifiers in the traceparent header, a trace-id and a parent-id, alongside a version and trace flags. The trace-id groups the records together, the parent-id says which call came out of which. You need both to rebuild the path a request took, rather than a pile of lines with a tag on them.

Two things cut the volume. Filter as close to the source as you can, because the earlier a line is dropped, the fewer hops you pay to carry it. And treat the rest as a data engineering problem rather than a logging one: forget that it’s logs, call it user data, and ask how you’d process that. If what you want is a record to query later, writing it to a database from the application removes the print, the parse and the filter in between.

Aggregate the answer, don’t keep the lines

Volume gets easier to cut once you notice how many lines are kept for questions that never needed lines.

Do you need raw log lines to know which browsers hit your API?

No. You need the count per browser over the month, which is a metric, and metrics are what’s left when the individual event stops mattering.

The definitions are worth being strict about, because they decide where data belongs. A log is an immutable event: this happened at this time and can’t be changed. Metrics are statistics over time about those events. Tracing is causality, one thing happening because another did, which is why you read it through time rather than as a list.

So the browser question doesn’t need the IP of each request, and keeping every line to answer it means paying log prices for a metric answer. A lot of that data also exists already in infrastructure you run. Your load balancer writes access logs, and they record more than the status code: in an Application Load Balancer entry, user_agent is field 14, right after the request line, though access logging is disabled until you turn it on. VPC flow logs cover the network level. API Gateway can write an access log per request once you configure access logging, in CLF, JSON, XML or CSV, carrying whichever context variables you name. Decide what your infrastructure already records before you add a logging statement that records it again.

Pick the store your team will actually query

With each signal attached to the questions it answers, storage turns into a cost decision rather than a brand decision.

Elasticsearch, Loki, or a time series database?

Whichever one the people who’ll use it can query without a two day course, because you collect this for developers, not for the dashboard.

Elasticsearch earns its place on text search, and for genuinely unstructured logs it’s hard to beat. If your logs are structured, a database does the job, and for metrics a time series database is the right shape. Loki went the other way deliberately: log chunks into object storage with a small index beside them, so it stays cheap to run and what you get back is grep across the streams you selected (Grafana Labs, December 2018). Prometheus and Grafana will take you a long way on their own, they’re well supported, and we like that both are open source.

At the far end of the scale, teams write their own. Uber built M3 for metrics and open sourced it in 2018, by which point it held over 6.6 billion time series. When every byte per request shows up on the invoice, the storage format becomes an engineering project. You’re almost certainly not there, and that’s the useful part of the example.

Which tool do you open when the pager goes off

The storage question has a twin, and this one splits us.

Which of the three do you reach for first?

It depends what you’re looking for, and we don’t reach for the same one.

Andrey opens the error tracker, Sentry or Rollbar, because an exception documents the problem and carries the data around it, and everything else is there to support the investigation that follows. Mattias goes to Grafana first and then into the logs, because an exception on its own doesn’t tell him whether three other services threw something similar in the same minute, and the cross reference is what he needs. One option sits between the two: pipe the tracker into a Slack channel, which turns the errors into a record across applications that you can read in order.

What doesn’t change is which metrics are worth having when you get there. The four golden signals from chapter 6 of Google’s SRE book, latency, traffic, errors and saturation, cover the health of a user facing system, and the chapter is a good guide to what deserves attention. If you’ve signed an SLA and run an error budget, the error count is a metric you keep on purpose. For the rest, be mindful. Metrics tell you about change over time, and a lot of the time you don’t need that.

If you can only fund one, fund tracing

None of that settles the budget question. If there’s money to do one of the three properly, which one gets it?

Why does tracing pay off more than logs or metrics?

Because it maps what your system is actually made of, along the request paths you’ve instrumented.

Most teams don’t know. Ask whether this service calls that one and the common answer is that nobody is sure. At five or six services things are already messy, and somebody has forgotten a call that exists. Traces give you a bird’s eye view of the system, if they’re configured correctly, and that view is what makes every other decision an informed one. Coverage is the catch: a path nobody instrumented is a path the map doesn’t have.

It’s surprisingly hard to sell. Customers have heard of tracing, it sounds good, and then comes the sentence: we’ll do logs first, we’ll do ELK. Part of that is that very few people have implemented it, so nobody on the team knows where to start, and the project stalls before it begins.

The real cost is instrumentation. Without a service mesh, in most cases you have to change code to inject instrumentation into requests. How much code depends on the language, the framework and how far the ready-made instrumentation reaches. A mesh covers part of that. It won’t get you to full coverage, because the proxies see traffic, not intent. With Istio the sidecars emit the spans, but the proxy can’t tell which outgoing call belongs to which incoming one. So your application still has to copy x-request-id and the x-b3-* headers from the inbound request onto its outbound calls. If you’re starting now, start against OpenTelemetry, where the tracing specification reached v1.0.0 in February 2021. That milestone is the cross-language contract, not the libraries: the language APIs and SDKs release their own 1.0 versions separately, which the announcement said would follow over the coming weeks. Check where the one for your language has got to. That is what decides how much code you touch. On the JVM, the OpenTelemetry Java agent reached v1.0.0 in March 2021, with javaagent instrumentation for a long list of common libraries. A good part of the work there is attaching the agent rather than editing call sites.

What this means for teams

Where we landed: the three pillars aren’t equally valuable and shouldn’t be funded as though they were. Logs are the default because they’re free to start and bill you later. Metrics are worth keeping where they’re attached to a commitment you made to someone. Tracing is the one that changes what you’re able to know, and it’s the one that gets deferred, mostly because nobody on the team has done it before. Logs end up carrying the debugging work by default, and that’s the job they’re worst at.

Four things you can do this week:

• Take one day of production logs and count what share is successful health checks and other lines confirming the state you expected. Drop those at the collector and look at the storage number next week.
• Write down the field names every service has to share, request_id, ip_address, user_id, and make the next service you deploy use them. Fix the others as you touch them.
• Check what your infrastructure already records. If your load balancer can write access logs with the request line and the user agent, turn them on and delete the application code that logs the same request.
• Instrument one request path across two services and see whether you can tell the story of a single slow request without opening Kibana. Two services is enough to find out what instrumentation will cost you.

Common questions, answered

How do I stop load balancer health checks from flooding my logs?

Drop the routine successful checks at the collector, matching the health check path and a 2xx status, before those lines reach storage. Keep the failures and anything unexpected, because those are the lines that tell you something changed. Filtering closest to the source is what makes the remaining logs good, and a successful check only confirms the state you already assumed. If the application can be configured not to write those lines in the first place, that’s better still, because you stop paying to carry them between hops.

How do I keep container logs when a Kubernetes pod is evicted?

Ship them off the node before it happens, with one log agent per node running as a DaemonSet and forwarding to storage that lives outside the cluster. A pod eviction takes the container log files on the node with it, which is why the Kubernetes documentation gives cluster level logging a lifecycle of its own. If an application writes to a file inside the container rather than to stdout, give the pod a volume and a second container that reads that file and prints it, so the node agent sees those lines too.

How do we start tracing without rewriting every service?

Start with one request path across two services instead of the whole estate, and treat that as the pilot. A service mesh gives you partial coverage without touching application code, though not full coverage: with Istio the sidecars emit spans, but the application still has to copy the trace headers from the inbound request onto its outbound calls. Instrument against OpenTelemetry, whose tracing specification reached 1.0 in February 2021, so the work survives a change of backend, and check how far the instrumentation for your language has got before you commit to a date.

Related episodes

• Episode 20, Monitoring Done Wrong or Dreaming for a Better Monitoring is where we first argued that logs are a costly way to debug a microservices architecture, and where the sane defaults question came up.
• Episode 23, How Do We Run Kubernetes In The Cloud? covers the cluster plumbing a log pipeline sits on, and what the managed offerings hand you instead.
• Episode 21, Surviving AWS Outage is the reminder that your tooling shares a failure domain with what you’re debugging: when Kinesis went dark in us-east-1, CloudWatch degraded with it.

Resources

• Logging Architecture, Kubernetes documentation settles what happens to container logs on eviction, and lays out the node agent, sidecar and push-from-the-app patterns.
• Fluentd and Fluent Bit, Fluent Bit 1.7 documentation settles the comparison in the projects’ own words: C versus C and Ruby, around 650KB against around 40MB, zero dependencies against a gem with gems behind it.
• Monitoring Distributed Systems, chapter 6 of the Google SRE book settles what to measure when you don’t know what to measure: latency, traffic, errors and saturation.
• Trace Context, W3C Recommendation 6 February 2020 settles what a request has to carry for spans to join up: a trace-id for the trace and a parent-id for the caller’s request, in a traceparent header that also carries a version and trace flags.
• OpenTelemetry specification v1.0.0, February 2021, settles which parts of OpenTelemetry are stable: the tracing specification, Context and Baggage, with the language SDKs released separately and metrics and logs still in progress.
• OpenTelemetry Java instrumentation v1.0.0, March 2021, settles how far one language has got: a stable opentelemetry-javaagent artifact with javaagent instrumentation for common JVM libraries.
• Istio distributed tracing overview, version 1.10 settles how far a service mesh gets you: it names the headers your application has to propagate for the spans to join up.
• Access logs for your Application Load Balancer settles what your load balancer can record for you, field by field, and that it records nothing until you enable it.

Since we recorded

Tracing was the only stable observability signal in OpenTelemetry when we recorded, marked stable alongside Context and Baggage in the same v1.0.0 specification release. The metrics and logs specifications are stable now too, so one project standardizes all three signals, though each still needs its own instrumentation or integration work. We took up the service mesh route to tracing directly in episode 33, Do I need a service mesh?, and by episode 100 our assessment was that Istio as the default never arrived and simpler ingress patterns won.