Pod Startup Forensics: The Problem

Cover image credit: Photo by Kevin Ku on Unsplash

Pod Startup Forensics: The Problem

Series · Pod Startup Forensics

Post 1 of 3

  1. Pod Startup Forensics: The Problem
  2. Pod Startup Forensics: The Tooling Gap
  3. Pod Startup Forensics: The Idea
Table of Contents

A pod takes 40 seconds to start instead of 4. It doesn’t look like an incident. Nothing pages. kubectl get pods eventually shows Running. The deploy finishes. The only trace is a vague sense that something felt slow, and by the time anyone goes looking, the pod that was actually slow is usually gone.

Kubernetes has a real metric for this. kubelet exposes kubelet_pod_start_sli_duration_seconds, a live histogram, and SIG-Scalability maintains an SLO that the 99th percentile of pod startup latency, per cluster-day, stays under 5 seconds, built on exactly that signal. So the instinct is to assume the problem is already solved.

It isn’t. That metric tells you the cluster-wide p99 crept up this week. It can’t tell you which pod, which phase, or why.

Autoscaling only works if the scale-up is fast

The entire value of a Horizontal Pod Autoscaler or Cluster Autoscaler reacting to load is that new capacity shows up before the old capacity falls over. Imagine a scale-up event that takes 45 seconds to go from “decision made” to “pod serving traffic,” against a load spike that doubles request volume in under a minute. The autoscaler technically did its job. It decided to add capacity. The outcome is the same as not having an autoscaler at all: the existing pods absorb the overflow, latency degrades, and the new pod shows up in a system that’s already stopped hurting on its own, or has already tripped a different alarm.

Pod startup latency isn’t one number. It’s schedule delay, image pull, PVC attach and mount as two separate operations, init containers running in sequence, sidecars starting alongside or before the main container, and the main container itself becoming ready. Every one of those phases is a place autoscaling responsiveness can quietly evaporate, and none of them show up as a single knob to tune. Picture a cluster that scales in a few seconds on a warm node and takes a minute or more on a node that has to pull a fresh image: that cluster doesn’t have one autoscaling latency. It has a distribution, and the tail of that distribution is exactly the case autoscaling exists to handle: sudden load, no warm capacity, has to happen fast.

CI/CD pipelines spend most of their wall clock waiting on pods, not running work

Tekton, and any CI system built the same way, one pod per unit of work, pays the pod startup cost on every Task in a pipeline. A PipelineRun with five sequential Tasks doesn’t pay pod startup once. It pays it five times, because each Task runs as its own pod with its own schedule, pull, init, and ready sequence. The individual Steps inside a Task run as containers sequenced within that one pod, so they share the pod’s startup cost rather than each paying it separately.

This matters more than it looks like it should, because the actual work inside a Step is frequently fast. In this project’s own testing, a Tekton TaskRun pod’s step containers finished in under two seconds, fast enough that five separate one-shot lookups run right after the pod was deployed never once caught a step container still running; they’d already gone terminated in the time it took to issue the command. That’s one data point, not a universal one, but it illustrates a real dynamic: if the startup overhead wrapped around that Task’s pod, schedule plus image pull plus init container plus container create, itself runs several seconds, the overhead isn’t a rounding error next to the work happening inside it. A pipeline that feels slow is often a pipeline where the build and test commands run fine and the pods wrapping each Task are the bottleneck, and nothing in a typical CI dashboard separates those two costs from each other.

The on-call cost: Guessing with kubectl describe pod

When a pod is slow to start in production, not failing, not crash-looping, just slow, the standard move is kubectl describe pod followed by reading the Events section top to bottom. That gives a chronological list: Scheduled, Pulling, Pulled, Created, Started, maybe a FailedMount or a repeated Unhealthy if something is actually wrong. What it doesn’t give is any indication of why a phase took as long as it did.

So the on-call engineer does arithmetic by hand: subtracting firstTimestamp values between events to guess how long image pull took, squinting at whether the gap between Pulled and Started looks unusually large. If the answer isn’t obvious from the event list, there’s nowhere else to look. If the slow phase is an init container blocking on a connect() call to a service that’s still coming up, the Event stream shows nothing at all during that block. No event fires while a process is just waiting on a syscall to return. The engineer either already knows this failure mode from having seen it before, or starts guessing: the CNI, DNS, the CSI driver, the registry. That guessing has a real cost: time spent per incident, and because nothing captures the answer, the same ambiguity can get re-diagnosed from scratch the next time it happens.

A fair fraction of the pods worth interrogating are already gone by the time anyone looks. Kubernetes garbage-collects completed pods, CI systems delete TaskRun pods after a retention window, and a pod that failed to schedule and got evicted leaves no long-lived object to describe. kubectl describe pod only works on a pod that still exists. Kubernetes’ own Event objects carry a bounded retention window independent of the pod’s own lifecycle, so the moment a pod is deleted, its events go with it on their own separate clock. “Why was that slow” becomes permanently unanswerable through the tools most people reach for first, and for a Tekton Task pod whose steps finish in a couple of seconds, that clock starts running almost immediately.

Why kubectl get events isn’t a phase breakdown

kubectl get events, or describe pod’s embedded events section, gives the raw material a phase breakdown would be built from, not the breakdown itself. It’s a flat, chronological list of whatever the kubelet and the various controllers happened to report, in the order they happened to report it. There’s no concept of a phase in that stream. No line says “image pull took 10.4 seconds” or “this was the slowest part of startup.” Pulling shows up at one timestamp and Pulled at another, and it’s on the reader to subtract them, notice which containers were init containers versus sidecars versus the main container (which, depending on Kubernetes version, can report state in genuinely different shapes: a native sidecar with restartPolicy: Always shows up as running in the same status array where an ordinary init container shows terminated), and reconstruct the ordering by hand. There’s no root cause in that stream by construction, either. An Event is a report that something happened, not an explanation of what the process was doing while it was blocked. If a container spent eight seconds inside a connect() call, no Event says so, because Events cover what Kubernetes’ own controllers observed, and no controller is watching syscalls.

Why kubelet’s own latency metric doesn’t answer this either

kubelet_pod_start_sli_duration_seconds is a genuinely real, useful signal for a specific question, which makes it tempting to assume it solves this one too. The gap is structural, not a matter of granularity.

That histogram answers “is pod startup latency across this cluster within SLO, in aggregate, over time.” It’s a single histogram per node, rolled up again across every node in the cluster to produce the SIG-Scalability SLO number: a fast-starting sidecar-free stateless pod and a slow multi-init-container stateful pod both feed the same buckets. No per-pod breakout, no phase attribution within a single pod’s startup, no timestamp to point at and say “this second is where the time went.” A cluster-wide p99 can trend upward on a dashboard for a week straight with no way to go from that trend to a single pod name worth investigating.

kubectl get events gives raw, unstructured chronology for one pod at a time, with no phase model and no root cause. kubelet’s own metric gives an aggregate trend across the whole cluster, with no per-pod resolution at all. Between a single pod’s raw chronology and the cluster’s aggregate trend sits the actual question: which pod, which second, why. Neither tool covers that middle ground, and nothing else currently does either.

References

  1. Kubernetes Metrics Reference
  2. SIG-Scalability Pod Startup Latency SLO
  3. Tekton TaskRuns
  4. kubectl Reference
  5. Kubernetes Event v1 API Reference

Next In Series

More Articles