We Cut Lambda Cold Starts 56% — Three Wrong Turns Before the Real SnapStart Fix

CloudWise's /dashboard took up to 2.3 seconds to load cold. That's the API Lambda's own cliff — not network, not the frontend. AWS Lambda SnapStart was already turned on. It was already restoring a frozen snapshot in about 600ms, which is the number SnapStart is supposed to deliver. And for two deploys, turning it on made no measurable difference to the thing that actually made the dashboard feel slow. This is the debugging path that got from there to a measured 56% cut — including the two attempts that didn't work, because the wrong-turn part is the part worth reading.

What was actually slow

We measured every layer before touching anything (full numbers in docs/redesign/clo114-dashboard-speed-analysis.md). Four dashboard API calls, already firing in parallel — parallelizing them further was a non-issue, wall-clock already tracked the slowest call. Server compute, warm, was fine: ~200–380ms. SnapStart's own restore was fine: ~550–620ms.

The problem was one specific number from CloudWatch REPORT lines: on a cold (post-restore) invocation, the first request's own Duration — not the restore, the handler work after the restore — was 1,124ms at p50, up to 2,805ms at the tail. SnapStart had already paid for the expensive part (a frozen Python interpreter + imports) and handed back a restored environment in 600ms. Something in the first real request was still doing ~1,100ms of work the snapshot didn't cover.

The diagnosis: init phase vs. handler phase

SnapStart snapshots whatever ran at module import / init. Anything deferred to the request handler is still paid, lazily, on the first real invocation — that's the whole cliff. get_settings() already runs at import in app/main.py, and constructing Settings performs the full AWS Parameter Store load — so config reads were already inside the snapshot, free. What wasn't: the boto3 session and DynamoDB client (built lazily in a factory, inside the request path) and FastAPI's startup_event — Mangum runs lifespan="auto" on the first request, not at import.

The fix looked obvious: move both into the init phase, so they're captured in the snapshot. We rejected the alternative — Lambda provisioned concurrency — outright: it bills a kept-warm 2GB instance 24/7 regardless of traffic, and it's redundant with SnapStart, which already restores in ~600ms. Paying a standing bill to paper over a problem SnapStart half-solves is exactly the kind of waste we built this product to catch in other people's accounts. So: init-phase priming, ~$0 incremental cost.

Wrong turn #1: it shipped clean and did nothing

PR #641 landed the priming code. Deploy went green, gates passed, prod promoted. Re-measured: cold Duration p50 1,142ms — statistically the same as the 1,124ms baseline. Priming had shipped and, as far as the numbers were concerned, changed nothing.

Worse: we couldn't even tell why. Every diagnostic line we'd added — "hooks registered," "SnapStart prime," even FastAPI's own unconditional startup log — was completely absent from CloudWatch across 90 minutes of cold starts. The working theory for a while was that SnapStart's init-phase logs simply don't reliably surface in CloudWatch, which would have made this nearly undebuggable from logs alone.

Wrong turn #2 (well, half a turn): it was a log level

It wasn't a SnapStart logging quirk. It was logging.info(). The Lambda's effective log level was dropping INFO — CloudWatch showed our [WARNING] lines and nothing below them, meaning every one of our priming diagnostics had been silently filtered the whole time. We moved the key diagnostic and priming log lines to WARNING (PR #648) and immediately got a real signal for the first time in this investigation. Lesson, underlined: when a fix "does nothing and also produces no logs," check the log level before you start reasoning about distributed systems semantics. We spent longer on the second hypothesis than the first.

The actual bug: after_restore cleared, but never rebuilt

With real diagnostics finally visible, we split the cold REPORT lines into two groups: requests that hit a fresh init (rare — a brand-new execution environment) versus requests that hit a restored snapshot (the common case SnapStart exists for). The restored-and-then-requested group was still averaging ~1,064ms — basically the original cliff, just hiding in a bucket we hadn't isolated before.

The cause was in our own restore hook. A boto3 session captured in a snapshot carries frozen credentials and, once a client exists, frozen TLS connection pools. After a real restore, the execution environment is new: credentials need refreshing, any frozen socket is dead. So reset_for_restore() correctly cleared the cached session and clients on after_restore — that part was right, and necessary for correctness. What it didn't do was rebuild them. So the next request found an empty session, built one lazily, and paid almost exactly the cost priming was supposed to eliminate — just relocated from "first request ever" to "first request after every restore," which for a Lambda that scales to zero between sparse dashboard loads is most of them.

The fix (PR #649): reset_for_restore() clears and eagerly rebuilds — with the freshly-restored credentials — so the next request finds the session already built, not merely uncorrupted.

The result

Post-restore first-request Duration, n=7 samples per version, staging:

Version	mean	p50
Baseline (no priming)	1,183ms	1,124ms
Clear-only (the bug)	1,064ms	1,060ms
Eager re-prime (the fix)	652ms	490ms

p50 1,124 → 490ms, a 56% reduction. Diagnostics on every restored environment now confirm the full chain worked as intended: hooks_registered=True, session_already_built=True, restore_reprimed=True, zero errors.

It's a real win, and it's not a complete one. About 3 of 7 restores in that sample still land at ≥500ms, even with the session confirmed pre-built — most likely the first actual DynamoDB operation opening its own TLS connection, since boto3 connects lazily on first call rather than at client construction. Chasing that down would mean priming a real DynamoDB round-trip inside the restore hook itself, for what's probably diminishing returns against a ~490ms floor that's already good enough. We banked the 56% rather than shipping a seventh iteration.

Alongside this, a frontend session-storage stale-while-revalidate cache (shipped separately, PR #639) hides both the network round-trip and any residual cold cliff on repeat visits — the dashboard's daily-batched data makes brief staleness safe — and a keep-warm EventBridge ping keeps instances hot enough that cold restores stay rare in the first place.

The actual lesson

None of the three wrong turns here were exotic. "The fix looks right but does nothing" was a log level. "The clear-only version regressed" was a hook that did half its job and returned success anyway, because clearing genuinely is correct and necessary — it just isn't sufficient. The instrumentation that finally cracked it wasn't clever; it was making the diagnostic state (hooks_registered, session_already_built, restore_reprimed) observable on the request path instead of trusting init-phase logs that, it turned out, we weren't even looking at correctly.

If you're chasing a Lambda cold start and the fix you shipped isn't moving the number: check what log level is actually filtering your diagnostics before you start doubting your architecture.

This is the same instinct behind the product: measure what's actually happening in your AWS account before acting on it. If you want to see what that looks like pointed at your own bill, a free, read-only scan takes about five minutes and changes nothing without you approving it first.