one number is usually two numbers
three times a single reading hid the cost that actually mattered, and each time the fix was to measure again from somewhere else
- container right-sizing
- external observation
- process introspection limits
- one-time vs per-call cost
- cold instance vs warm instance
- instance-scoped memoisation
- cache lifetime vs cache logic
- native vs managed-heap allocation
- request scope vs application scope
- shared mutable state
- I spent a few months measuring a query service and kept getting numbers that were true and useless at the same time.
- A process can time its own functions all day and still not tell you, cheaply, what its peak memory was.
- The first time you construct something you are timing construction and the import that had to happen first.
- A cache can work flawlessly and still charge you full price on every single request.
- All three readings were correct. Each one was just a single number doing the work of two.
None of this is clever, and that is sort of the point. Every fix was the same move: take the measurement again from a different vantage point, or at a different moment, and watch a single figure split into two figures that want different things done about them.
the shape of the mistake
A single measurement fuses costs that have different lifetimes. You get one number, you form one opinion, and the opinion turns out to be about the wrong half.
one reading two readings
─────────── ────────────
┌───────────┐ ┌───────────┐
│ │ │ 485 ms │ once
│ 1,076 ms │ ──> ├───────────┤
│ │ │ 592 ms │ always
└───────────┘ └───────────┘
"expensive" one you can drop,
one you cannot
The left box is accurate. The trouble is that you cannot do anything with it, because it never tells you which part of that cost you could have got rid of.
reading one: a process cannot see its own peak
The question was how much memory the API container actually needed, so it could be given a sensible size on a certain platform that bills by declared CPU and memory. A platform that has not responded to my support ticket about drastically reduced caps in 28 days. ( </3 )
The documentation said a quarter of a vCPU and 512 MiB. If I had put my trust in that, it would have produced a container that got OOM-killed on its first real query. But peak memory is genuinely awkward: you cannot read it cheaply from inside the process, and you cannot observe it at all without real work to drive it.
So the measurement had to come from outside the thing being measured.
┌─────────── container ───────────┐
│ the process │
│ times its own code ..... yes │
│ sees its own peak RSS ... no │
└────────────┬────────────────────┘
│
sampler ───┘ polls from outside,
every 1-2 s, started
and stopped by a
marker file on disk
| idle | one simple query | one heavy query | |
|---|---|---|---|
| api container | 213 MiB | 1,139 MiB | 1,220 MiB |
| ui container | 146 MiB | 146 MiB | 146 MiB |
Three things fell out of that table, and only one of them was the thing I asked for.
The size, obviously. 512 MiB was never going to survive. But also: the UI container is perfectly flat under load, which is evidence that it is a pure HTTP client and can be given almost nothing. And the API container going from 213 to 1,220 MiB means its heavy components are built on demand rather than at import, which you cannot learn by reading the code and which changes what caching can possibly buy you.
The honest limit: the sampler polls every one to two seconds, so on a fourteen-second query it takes about eight samples. Anything that spikes between samples is invisible, or I do not know how to measure it well yet. That peak is a lower bound, which is fine for sizing with headroom and useless if you were tuning to the megabyte.
There is a whole genre of F1 shorts where an apparent cheating scandal turns out to be, on inspection, just extremely intelligent engineering. The one I keep thinking about: the FIA measures compression ratio with the engine cold. So, the story goes, the teams built pistons that grow when hot. Fused 3D-printed layers, hidden channels, thermal expansion tuned to a tolerance. The geometry the rules care about only exists at a temperature the inspection never sees. Undetectable, by design.
I want to be a crazy engineer like that, honestly. But it is worth noticing what is actually going on underneath, because it is the same thing I keep doing to myself: somebody took a perfectly good measurement at the wrong moment. Nothing was broken. The instrument looked once, while everything was cold, and what it saw was true and useless.
reading two: the cost you only pay once
Next question: how expensive is rebuilding the service’s components on every request?
It is the casual sys-design basic check, for a novice, I guess. Is it worth caching a component’s runtime instance? (There was also a much larger question sitting underneath, whether that instance is even safe to share once the backend is spawned a thousand times over, served across many requests and users. Thread safety, races, assignment, whether the thing is genuinely stateless. So much I never learnt in uni. For another day.)
The trick is embarrassingly small. Construct everything twice in the same process and print both passes.
for pass_no in (1, 2):
print(f"===== PASS {pass_no} =====")
timed("load_config()", load_config)
timed("build_components()", build_components)
| constructor | pass 1 | pass 2 | what it means |
|---|---|---|---|
load_config() | 66.8 ms | 65.2 ms | genuinely per-call |
build_components() | 1076.7 ms | 592.2 ms | ~485 ms was one-time import |
load_prompts() | 91.5 ms | 92.4 ms | per-call |
make_client() | 4.0 ms | 3.8 ms | negligible |
make_logger() | 72.5 ms | 71.4 ms | per-call |
Pass one on its own overstates the recurring cost by about 60%. The steady-state number is pass two, and the gap between the passes is itself a fact worth having. It tells you how much of a cold start is just Python importing modules.
There is a trap sitting next to this one. I also captured heap allocations alongside the timings,
and build_components() reported under 1 MiB. So construction is cheap in memory, which is true.
I then nearly concluded that a large resident table was being loaded during construction, and the
heap number said otherwise.
But a Python heap profiler cannot see native allocations. The ~900 MiB the external sampler saw is columnar buffers living outside the Python heap entirely, invisible to that tool by design. Put the two together and they say something neither says alone:
Construction is cheap. The memory is all in the query work, which is unsurprising, given how LLMs work anyway. So caching constructors will save time and will not reduce the container’s memory footprint at all.
Neither tool could have told me that by itself. They have different blind spots, and I only got the answer by pointing both of them at the same event.
reading three: a cache that worked and still cost me
This one started as a straightforward savings question. The service reads its tables through an S3 streaming loader, and the loader memoises each table onto the instance it belongs to. So: does caching those table reads actually buy anything, and how much?
I never got a clean answer to that, because the measurement handed me something else first.
Build a loader, load a table, time it. Then call the same function again on the same instance and time that. Cold read, then warm read. What I expected was a boring ratio. What I got was a twenty-five-row table costing more to load, cold, than a table with six hundred thousand rows in it.
theres so much that confused me here.
Fair. This one has two separate surprises in it, and they arrive at the same time.
| table | cold | warm | rows |
|---|---|---|---|
| wide fact table | 189.1 ms | 0.00 ms | 614,787 |
| metrics fact table | 4.4 ms | 0.00 ms | 9,260 |
| small lookup table | 477.5 ms | 0.00 ms | 25 |
| tiny lookup table | 201.7 ms | 0.00 ms | 21 |
| total | 872.7 ms | 0.01 ms |
The first surprise stops being strange once you notice what a read is actually made of: a round trip, a file open, a footer and schema parse, a buffer allocation. Those are roughly constant. Row count only touches the streaming part, which is sequential and cheap. So the tiny table pays almost pure overhead, and the enormous one pays that same overhead plus some inexpensive bytes.
Latency tracks round trips, not volume. What this data does not establish is why that particular small table beat the wide one. That would need a file and partition count I never measured.
The second surprise is the one that took me longest.
i sure read that 10 times and i feel like i'll forget it again after 3 days. i still dont get it, why shouldnt per-call get cheaper if im visiting the same table over and over again?
It does. warm = 0.00 ms is the memo working flawlessly. That is what a perfect cache hit looks
like.
The memo lives on the loader instance, and a fresh instance is built per request. So it is born empty, fills up, does its job, and is thrown away with everything else when the request ends. Two questions were tangled in one table: does the cache work, and does it live long enough to matter. Only the second one was ever wrong, and it turns out to be a question about lifetime. I had been answering it as though it were a question about caching.
The water was never the expensive part. It is the walk to the well. You will make that walk again tomorrow, and the day after, and you will go on thinking the problem is the water.
This one also reversed a recommendation, which is the part I would rather skip and probably shouldn’t. I had measured constructor time at 825 ms, reported the avoidable per-request work as 8.6% of a query, and said caching was not worth doing. The discarded table loads are another 873 ms. Together that is roughly 1,698 ms of a 9.6-second query, about 17.7%. Measuring the second half inverted the advice I had already given.
what the three have in common
| one reading says | the second reading says | |
|---|---|---|
| memory | “the process is fine” | 213 MiB idle, 1,220 MiB under load |
| construction | “1,076 ms, expensive” | 485 ms once, 592 ms always |
| the cache | “477 ms, cache is broken” | cache is perfect, its lifetime is wrong |
Every row there is the same mistake wearing different clothes. One number was quietly describing two costs that had different lifetimes, and the decision I actually needed only showed up once those two were pulled apart. That meant moving the observer outside the process in one case, running the same code twice in another, and in the third asking about lifetime when I had been asking about logic.
There is a sting in the last one worth naming. Hoisting that loader to application scope so it outlives a request is exactly what turns its memo into shared mutable state across threadpool workers. The caching fix creates the concurrency problem, which is why the whole next investigation had to happen at all.
And one caveat I owe you: all of the table timings came from a container that had been serving for hours, so its local disk cache was warm. A genuinely cold container pays download time on top of every one of those numbers, and I never measured it.