Break/Fix: Loki Ingestion Spike

Reported symptoms

LokiIngestionSpike fires at 21:40 on Tuesday. The prod tenant is taking about 20 MB/s against a 24-hour baseline of about 1.1 MB/s, and the rate is still going up.

By the time the on-call has a terminal open, four separate things are wrong and they do not obviously belong together:

• Two innocent services are losing lines. payment-service and nginx-ingress have gaps - a minute here, ninety seconds there. Neither team has changed anything. Neither gap has a pattern they can see.
• Every tenant’s queries are slow. A 24-hour dashboard panel that renders in four seconds on a normal evening is timing out. The tenants complaining have nothing to do with the tenant that is spiking.
• Four collector hosts have alerted on disk. /var/lib/alloy is filling. None of the four ships a single line belonging to the service whose bytes dominate the spike.
• Nothing has been deployed for sixty hours. The quarter-end change freeze is in effect and the audit log confirms it has not been broken.

And the service at the centre of it looks fine. checkout-svc is producing 97 percent of the tenant’s bytes, and its own dashboards - request rate, error rate, latency, saturation - are all normal for a Tuesday evening. It is not sick. It is loud.

Evidence provided

$ logcli instant-query 'sum(rate(loki_distributor_bytes_received_total[5m]))'

21:38  6.2e+06
21:43  1.21e+07
21:49  1.74e+07
21:56  2.03e+07

$ logcli query --since=15m 'topk(5, sum by (job) (bytes_over_time({env="prod"}[15m])))'

checkout-svc      1.83e+10
nginx-ingress     2.41e+08
payment-service   1.12e+08
notifications     6.40e+07
node-journal      3.11e+07

$ logcli query --since=15m 'sum by (level) (count_over_time({job="checkout-svc"}[15m]))'

debug  17284000
info     681000
warn      24100
error      1980

$ logcli query --since=15m 'topk(10, sum by (instance) (bytes_over_time({job="checkout-svc"}[1m])))'

61 of 74 instances above 200 KB/s at 21:55
22 of 74 instances above 200 KB/s at 21:40

$ curl -s http://loki-distributor.monitoring.svc:3100/metrics | grep loki_distributor_discarded_samples_total

loki_distributor_discarded_samples_total{reason="rate_limit",tenant="prod"} 41207714
loki_distributor_discarded_samples_total{reason="stream_limit",tenant="prod"} 0
loki_distributor_discarded_samples_total{reason="older_than",tenant="prod"} 0

The tenant’s ceiling, unchanged for six months:

# /etc/loki/config.yaml (extract)
limits_config:
  ingestion_rate_mb: 20
  ingestion_burst_size_mb: 40
  per_stream_rate_limit: 5MB
  per_stream_rate_limit_burst: 10MB

And two answers from the same service, minutes apart, from two different pods:

$ kubectl exec -n prod checkout-svc-6d9f4b7c8-x2ktp -- curl -s localhost:8080/actuator/loggers/com.example.checkout.httpclient

{"configuredLevel":"INFO","effectiveLevel":"INFO"}

$ kubectl exec -n prod checkout-svc-6d9f4b7c8-r7w4m -- curl -s localhost:8080/actuator/loggers/com.example.checkout.httpclient

{"configuredLevel":"DEBUG","effectiveLevel":"DEBUG"}

Work the evidence before reading on

Five questions, in the order they can be answered.

1. The wire rate is a staircase: 6, then 12, then 17, then 20 MB/s over about fifteen minutes. What kind of change produces a staircase rather than a step, and what does that tell you about how many things had to happen?
2. checkout-svc is 97 percent of the bytes and its request rate, error rate and latency are all normal. If the service is doing the same amount of work, what else can have changed to multiply its bytes by forty?
3. Two services that changed nothing are losing lines, and the loss is bursty rather than continuous. Which limit produces a loss that hits services other than the one responsible, and why is it bursty for the first few minutes?
4. Four collector hosts are filling their disks, and none of them ships anything from checkout-svc. What connects a collector on an unrelated host to a limit breached by a different service?
5. Two pods of the same deployment, same image, same ConfigMap, report different configuredLevel. What distinguishes them?

Before continuing: the change freeze is real and has not been broken. Is the statement “nothing has changed” true, and if it is, what made this happen at 21:35 on Tuesday?

Root cause

One change on Monday, one unrelated event on Tuesday

On Monday at 18:30 an engineer raised com.example.checkout.httpclient to DEBUG at runtime, across the fleet, to chase a customer report. Ingest went from 1.1 to about 3 MB/s. The spike alert fired as a warning, was acknowledged with “known, debugging a customer issue”, and at 20:10 the level was put back. Ingest returned to baseline. By every measure available that evening, the episode was closed correctly.

At 18:40, between those two events, the same engineer also wrote the debug level into the deployment’s ConfigMap - so that the setting would survive a pod restart during the investigation. That was a sensible thing to want. It was also the only part of the evening that was never undone.

For twenty-seven hours it did nothing at all, because a pod reads its logging configuration once, at startup, and no pod restarted.

At 21:35 on Tuesday the HorizontalPodAutoscaler scaled checkout-svc from 60 to 74 replicas for the evening peak, and the node pool consolidated two nodes in the same window. Every pod created from that moment read the ConfigMap and came up at DEBUG.

That is the staircase. The fleet did not switch; it converged, one pod at a time, over about fifteen minutes, which is why the rate climbed in steps and why 22 of 74 pods were hot at 21:40 and 61 of 74 by 21:55.

The freeze was true and irrelevant

No code was deployed. The audit log is correct. The freeze covers application releases, and this was a configuration value that shipped through the same GitOps pipeline as any other config change and looked entirely routine in review - one line, one package, a commit message describing a temporary diagnostic.

The belief that nothing had changed is what cost the first fifteen minutes. The honest version of that statement is narrower: no code has changed, and nothing has changed today. A change made a day earlier that only takes effect on pod restart will always look like nothing changed, because at the moment it takes effect, nothing did.

Forty times the lines, and three symptoms that follow from one number

At INFO this service emits about two lines per request; at DEBUG the HTTP client logs each outbound request, each response, and each retry, and the figure is closer to eighty. At roughly 2,500 requests per second that is the difference between about 0.5 MB/s and about 20 MB/s.

Everything else in the incident is arithmetic on that number:

None of those four is a bug in its own right. Each is the designed behaviour of a shared platform under a tenant that has exceeded its budget. That is the uncomfortable part: the platform worked exactly as configured, and the cost was paid by everyone except the service that caused it.

Resolution

1. Lower the level on the running pods first, through the runtime logger endpoint. It takes effect in milliseconds, needs no restart, and is reversible. List the pods fresh at the moment you run it - the pod set is the thing that has been changing all evening, and a list captured five minutes ago is already wrong.
2. Watch the level distribution, not the byte rate, as you go. sum by (level) (count_over_time({job="checkout-svc"}[5m])) tells you how many pods you have actually reached; the byte rate can fall by 90 percent while several pods are still at DEBUG.
3. Revert the ConfigMap, and be precise about what that achieves. It changes nothing for the pods that are already running - which is the same property that caused the incident - and it guarantees only that the next pod to start comes up at INFO.
4. Do not roll the deployment to "make the config take effect". Restarting 74 pods of a checkout service at the evening peak is a bigger risk than the log volume, and the runtime endpoint has already done the work. Let normal pod churn carry the ConfigMap change.
5. Leave ingestion_rate_mb alone unless the volume turns out to be legitimate. If the tenant is still over budget after the level is back to INFO, that is a different and much more interesting finding.
6. If the service team cannot be reached, drop level="debug" at the collector as a second-line brake - but record it as temporary, note that it drops debug for every service on that pipeline, and be clear that it hides the armed ConfigMap rather than removing it.
7. If the investigation genuinely still needs debug output, hold deliberately: keep DEBUG on a named handful of canary pods rather than the fleet, cap the bleed with a per-stream limit, and write down who reverts it and when.
8. Capture the peak numbers before they age out - wire rate at peak, bytes attributable to the job, duration, and the two data-loss windows. The cost review will not happen this week and the evidence has a retention window.

Verification

1. A new pod comes up at INFO. Delete one pod, let it be recreated, and query its runtime logger endpoint. This is the check that would have caught the fault on Monday, and it is the only one that tests the state the incident was actually about.
2. The declared and running states agree. configuredLevel on a sample of existing pods reads INFO, and the ConfigMap reads INFO. Either one alone is satisfied by the broken state.
3. The level distribution is clean. debug is back at zero or near it for the job over a fifteen-minute window - not merely reduced, because a reduced figure means pods were missed.
4. The tenant is inside budget across a real peak. loki_distributor_discarded_samples_total stays flat for every reason label through the following evening, not through the quiet hour after the fix.
5. The collateral damage is quantified, not assumed. Reconcile line counts for payment-service and nginx-ingress across the incident window and record the gap as data loss in the incident note. Nobody else is going to go back for this.
6. The collector spools have drained. Disk usage under /var/lib/alloy is back to normal on all four hosts that alerted, which confirms the backpressure cleared rather than merely stopped growing.
7. The drift check can fail. Set the level to DEBUG on one canary pod deliberately and confirm the new declared-versus-effective probe reports it. A probe that has only ever agreed has not been tested.

Prevention

• Make runtime log-level changes expire. The runtime endpoint is the right tool precisely because it is temporary. The failure here was making it permanent. If a diagnostic level must survive restarts, scope it to a named canary pod set with a scheduled revert and an owner.
• Never persist a diagnostic level into the deployment configuration. It converts a controlled experiment into a landmine that arms itself at the next scale event, and the delay between the change and the detonation can be days - long enough that nobody connects them.
• Reconcile declared state against running state on a schedule. One HTTP request per sampled pod, comparing effective log level against declared log level, catches this whole class and its mirror image, where the config was reverted and the running pods were not.
• Write into the freeze policy that a freeze covers code, not configuration. The belief that nothing had changed cost the first fifteen minutes of this investigation and it will cost them again.
• Give acknowledged spike alerts an expiry. Monday’s alert was correctly raised and correctly acknowledged. The acknowledgement carried no end time, so it silenced the escalation path for the recurrence too.
• Drop or sample debug at the agent by default. The platform’s exposure to a debug toggle should be bounded even when the service is wrong. Make the exception explicit, scoped and temporary.
• Set a per-stream rate limit as well as a per-tenant one. A per-tenant limit alone means one stream can spend the whole budget and take innocent services down with it; a per-stream limit puts the cost back on the stream that caused it.
• Run the cost review with real numbers. Bytes, duration, and the money. A spike whose cost is never stated will happen again.