One night with Cloudflare's on-demand Workers profiling

Engineering7 min read

Every request your coding agent sends through Context Mode passes a Cloudflare Worker and a few Durable Objects. For weeks, our busiest tenant store sometimes answered "Durable Object is overloaded", and requests waited in its queue for seconds. Logs could not tell us why. Then Cloudflare shipped on-demand profiling for deployed Workers. We profiled the live gateway and single Durable Objects, and in one night we fixed what the profiles showed: overload errors went from 29 in 30 minutes to 0.

The short version

What the feature does

You ask Cloudflare to profile one deployed Worker version for a few seconds, and you get a standard pprof file back. You can profile the whole Worker, or one Durable Object instance by its namespace id and actor id:

# CPU or heap profile of the whole Worker, 10 to 30 s.
cf workers versions profile <version-id> --worker-id <worker> --duration-ms 25000 --profile-type cpu > gw.pb

# One Durable Object instance: namespace id plus the actor id (hex of idFromName).
cf workers versions profile <version-id> --worker-id <worker> \
  --namespace-id <ns-id> --actor-id <actor-id> --duration-ms 25000 --profile-type cpu > store.pb

Two things made it useful for us:

We read the files with a 100-line Python script, with no Go toolchain. It sums samples by function and by "stack contains", and caps each sample (see the pitfalls).

The order that worked

  1. Count the errors first. Group error events by message, Worker and minute in Workers Observability. This tells you which Worker and which minutes to profile.
  2. Find the slow object. Our admin endpoint reports queue time, rows read and hold time per route for each Durable Object. The busiest tenant store stood out: p90 queue 975 to 2,235 ms, max 5,233 ms.
  3. Profile that object several times during real traffic, 20 to 25 s each, about a minute apart.
  4. Read each function's share of busy CPU, not raw time.
  5. Fix, deploy, profile again, and compare the same numbers.

What the profiles showed

The store: correct code that ran on every request

FunctionShare of busy CPUWhat it was doing
Schema setup10 to 25%About 65 CREATE and ALTER statements on every request to two routes. Each ALTER threw "duplicate column" and was caught.
Background sweep12 to 20%Listed a whole index in one call, with rows as large as 256 KB.
Garbage collector3 to 44%Mostly right after the sweep and large reads.
The real work12 to 16%The part that should be there.

None of this showed in logs. The schema setup was correct. It ran on every request instead of once.

The meter: parsing state the route never used

fetch was 69% of busy CPU. Its first line read and parsed a per-call ring of as much as 100 KB on every request, even on routes that never use it.

The console: whole tables per call

Our row counters showed console routes that read whole tables: 78,732 rows for the sessions list, 78,638 for daily ops, 41,197 for one chart.

The gateway: small strings, lots of garbage

In the stateless Worker, the garbage collector took 66 to 78% of busy CPU. The largest JavaScript items: measuring the byte length of the request JSON (15.3%) and hashing it (4.7%), both by building many small strings.

What we fixed

FixEffect
Schema statements run once per object instance, with a retry if they throw10 to 25% of store CPU to 0 to 1.5%
The sweep reads pages of 32 keys, one full pass per hour12 to 20% to 0 to 3.9%
The meter reads its ring only on the routes that use itNo ring read on other routes
Daily ops reads the per-day counters we already keep78,638 rows to one day plus at most 30 counter rows
Byte length and hash read the JSON value directlyAbout 20% of gateway CPU on that path removed; forwarded bytes identical
Non-urgent calls skip a store for 30 s after it answers "overloaded"Less pile-up on a busy store
A per-isolate cache limited only by count got a 4 MB byte limitRemoves a path to about 100 MB in a 128 MB isolate
Background object calls catch, count and log their errorsAn overload no longer shows as an unhandled exception

Each fix has a test that fails on the old code. We checked that the bytes we forward did not change, and ran a real agent session through the gateway before and after each deploy.

Queue p90, before975 to 2,235 ms
Queue p90, after261 to 908 ms
Busiest tenant store. Bars show the top of each range.
Busiest storeBeforeAfter
Schema setup, share of busy CPU10 to 25%0 to 1.5%
Sweep, share12 to 20%0 to 3.9%
Garbage collector, share3 to 44%4 to 19%
Queue p90975 to 2,235 ms261 to 908 ms
Queue max5,233 ms341 to 3,328 ms
"Durable Object is overloaded" errors29 in 30 min0 in the hours after

Pitfalls we hit

  1. "latest" is not what is running. It is the newest upload, often a preview with no traffic, and you get "No recent executions were found". Pass the deployed version id.
  2. Space captures about 60 s apart. Back-to-back captures got 429 Too Many Requests.
  3. Cap each CPU sample. A sample carries the time since the previous one, so the first sample after an I/O wait carries the whole wait. Uncapped, a 13 s idle gap looks like a hot function. We cap at 5 ms and report the removed time apart.
  4. A quiet object has no isolate. "no loaded isolate" means it was idle. Profile during real traffic.
  5. Heap captures of the stateless Worker were often empty. Two of about ten tries returned samples. CPU captures were reliable.
  6. A heap profile shows what is alive, not what one request makes. One capture blamed a CSS helper and the UI router for half the heap. Both are built once per isolate and kept. The profile was right; our reading was wrong. Count constructions before you fix what a heap profile shows.
  7. A profile can hold string data. Keep raw files out of git and share only function names and lines.
  8. A capture that is 95 to 100% garbage collector tells you there is heap pressure, not where. Pair it with a heap capture.

What we did wrong

What could be better

Our wish list for Cloudflare, from one night of use:

Takeaways

  1. Turn on source maps before you need them.
  2. Profile the one Durable Object that queues, not the whole Worker.
  3. Look for correct code that runs too often: schema setup, full scans, parsing state the route does not use.
  4. Garbage collector share is a symptom. Find the allocations.
  5. Prove load and memory fixes locally. Production profiling is for finding causes, not for stress.

More from the same request path: Durable Objects in production: 14 lessons from Slipstream. Live uptime for every component is on the status page. To put your own agent on this path, start with the quick start.