perf(health-check): retry quickly until a target first answers - #69
Merged
Conversation
Cuts the scale-to-zero cold wake from 1154ms to 278ms, measured end to end against a real Docker daemon on the same machine. #19 asked for a cold-wake number before optimising anything, and the number turned out to indict our own code rather than the container runtime. Waking a container whose app was ready almost immediately took 1154ms, of which docker start was only ~215ms. The proxy log showed where the rest went: 15:52:44.733 Healthcheck failed ... connection refused 15:52:45.742 Target health updated ... healthy 15:52:45.743 Service awake `docker start` returns when the container process is created, not when the application is accepting connections, so the immediate probe is routinely refused. The next probe then came a full check interval later. The wake was quantised to the health check interval -- roughly a second of pure waiting, for nothing. The health check now probes immediately, retries from 50ms doubling up to the configured interval until the target first answers, and settles to the configured interval after that. A running target is probed no harder than before, and a container that never comes up backs off rather than spinning. Deploys pay the same tax and get the same benefit: waiting for a new target to become healthy is the same wait. Also fixes a -race flake in TestService_CacheMissWakesASleepingService, which landed with #66. A wake persists state from its own goroutine, and Dispose does not wait for a write already in flight, so the test could race t.TempDir cleanup and fail with "directory not empty". The cleanup now takes saveLock, which returns only once any in-progress save has finished. Closes #59
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Cold wake: 1154 ms → 278 ms. Measured end to end against a real Docker daemon, same machine, same container, before and after.
#59 opened with one instruction — "Measure ours first. Before optimising, get a real number for this implementation on a real app." Now that #19 has landed, that was finally possible. The measurement changed the answer.
What the measurement found
A container whose app is ready almost instantly took 1154 ms to wake. That decomposes badly:
docker startThe proxy log says exactly where it went:
docker startreturns when the container process is created, not when the application is accepting connections. So the immediate probe is routinely refused — and the next one came a full check interval later. The wake was quantised to the health-check interval: roughly a second of pure waiting, for nothing.The fix
HealthCheck.runprobes immediately, then retries from 50 ms doubling up to the configured interval until the target first answers, and settles to the configured interval afterwards.No new flag, no new state machine, no new config to explain.
Why not the tiered pause/stop this issue proposed
The issue's own design was
docker pausefor short idles anddocker stopfor long ones. The measurement says that is now the wrong first move:docker start. I measureddocker unpauseat 75 ms median vsdocker startat 215 ms — so the pause tier buys ~140 ms plus the app's own boot.So: the cheap, universal win is in, and the tier is now a data-informed choice rather than a guess. If Rails cold starts still annoy in practice, reopen it as its own issue — the
ContainerLifecycleseam makes it additive.Test plan
RetriesQuicklyUntilTheFirstSuccess— a target ready 120 ms in is noticed without waiting out a 1 s interval. Fails on the old code at 881 ms, which is the production symptom in miniature.SettlesToTheConfiguredIntervalAfterSuccess— a healthy target is not probed at the wake cadence foreverBackoffIsBoundedByTheConfiguredInterval— a container that never comes up is not hammeredgofmt,go vetclean;go test -race— 1504 passDeviations & judgment calls
--health-check-path /(python has no/up) and then measured requests to/, so the gate was correctly answering a health check for a sleeping service without waking it. Worth recording, because the false alarm was more convincing than the real bug.--health-check-intervalmean "how often to check a healthy target" rather than also "how long a new one might sit ready but unnoticed" — arguably what operators assumed it meant already.-raceflake fix from feat(router): install the container runtime and complete scale-to-zero #66.TestService_CacheMissWakesASleepingServicecould racet.TempDircleanup against a persist still in flight. Cleanup now takessaveLock. It is unrelated to the perf work, but it is a test I wrote, it is flaky ondashtoday, and it surfaced in this branch's-racerun.Closes #59