fix(metrics): make Prometheus metrics correct with multiple workers, and wire the trackers up - #1523
Conversation
|
Please pass ruff at least. ty is fixed here: #1519 |
00a4a41 to
a83cd21
Compare
|
Thanks — ruff passes now. Three things were wrong: Fixed with Confirmed those 17 are all the Both commits pass |
| # answered the scrape - about 1/N of the traffic, a different 1/N each time. | ||
| # Consecutive scrapes then look like counter resets and every rate or | ||
| # histogram derived from them is wrong. | ||
| multiproc_dir = os.environ.get("PROMETHEUS_MULTIPROC_DIR") |
There was a problem hiding this comment.
Who should take care of the directory setup?
There was a problem hiding this comment.
Good catch — the answer was "nobody", which is a real gap. Fixed in 725e1de.
The /metrics handler is also the wrong place to look for it: prometheus_client mmaps a file per worker when the first metric is registered, long before any scrape arrives. Creating the directory here would already be too late.
So main() now calls _prepare_multiproc_dir() before any metric exists. It creates the directory and clears stale *.db files — without that, a previous run's dead workers get summed into the live counters on every scrape. It's best-effort: a read-only or pre-seeded mount logs a warning rather than refusing to start, since failing to boot over metrics would be the wrong trade.
Verified it creates missing nested directories, clears stale files, and warns without raising on an unwritable path.
| _R = TypeVar("_R") | ||
|
|
||
|
|
||
| class _HasTracker(Protocol): |
There was a problem hiding this comment.
The same code duplicates. We can make it common
There was a problem hiding this comment.
Agreed, and it was worse than the diff showed — fixed in 00a7e81.
A later push to satisfy ruff's ANN401 replaced the Any annotations with a Protocol-bound TypeVar, and I copied that into both files too. So by the time you looked it was the decorator plus a Protocol and three TypeVars duplicated — about 30 identical lines in two places.
Now extracted to common/metrics_factory/timed.py, next to OperationTracker, and exported as timed. Both stores import the one copy; the only thing that differed between them was the docstring.
With MEMMACHINE_WORKERS > 1 uvicorn forks a worker per process and each keeps its own registry, so /metrics returned whichever worker happened to answer the scrape - about 1/N of the traffic, a different 1/N each time. Consecutive scrapes then look like counter resets, and every rate, histogram quantile and calls-per-request figure derived from them is wrong in an unbounded direction. Build a fresh registry per scrape and attach MultiProcessCollector when PROMETHEUS_MULTIPROC_DIR is set, leaving the single-worker path on the default registry so nothing changes for the default deployment. Measured on an 8-tenant capacity run: counter resets over one ladder went from 70 (4 workers) and 87 (8 workers) to 0, and five consecutive scrapes of a loaded server returned identical values where they previously diverged. Requires PROMETHEUS_MULTIPROC_DIR to be set and a writable directory mounted at it; the chart change that does so is separate.
OperationTracker accepts metrics_factory=None and then silently discards every timing it takes - no error, no warning, no series. A component that is fully instrumented but never given a factory is therefore indistinguishable from one that was never instrumented at all, and the only way to notice is to go looking for a metric that should exist. The Neo4j store, the episode store and the session store each shipped instrumented and unwired, which is why database latency appeared to be unmeasurable: every call was timed and thrown away. Wire the factory through the resource manager, the database manager and the event backend's params so those trackers emit. The tests assert at the call sites rather than on the components. An earlier version tested that each store honours a factory it is given, which passes whether or not anything passes one - it still passed with the fix reverted. These fail when the wiring is removed.
a83cd21 to
00a7e81
Compare
There was a problem hiding this comment.
It is better to check the worker number. If the worker number is bigger than 1, setup multiproc dir automatically.
There was a problem hiding this comment.
Agreed — done in b89ee3e.
The worker count is the thing that decides whether aggregation is needed, so it now drives the setup: above 1 with nothing configured, the directory defaults to <tempdir>/memmachine-prometheus-multiproc. An explicit PROMETHEUS_MULTIPROC_DIR still wins, which is how two servers on one host keep their metrics apart.
Two details worth flagging:
- If the chosen directory can't be created, the variable is removed again.
prometheus_clientraises in every worker if it can't open the directory it's pointed at, so leaving behind a path only this code picked would turn an unwritable temp dir into a server that refuses to start — the opposite of the best-effort behaviour the rest of the function promises. An operator's own unwritable path still just warns. - Worker-count parsing moved into
_worker_count(), shared withstart_http(), so the two can't disagree about the number.
Setting the env var in main() reaches the workers because uvicorn spawns them via multiprocessing.get_context("spawn") (uvicorn/_subprocess.py) — each child is a fresh interpreter that inherits os.environ and imports prometheus_client after we've set it.
13 tests added in test_multiproc_dir.py: the default, the explicit override at both 1 and 4 workers, nested creation, stale *.db clearing, and both failure paths.
PROMETHEUS_MULTIPROC_DIR had to be set by whoever deployed the server. Set
MEMMACHINE_WORKERS=4 without it and nothing complains: each worker keeps its
own registry, a scrape is answered by whichever worker the load balancer
picked, and the numbers that come back look plausible. There is no error to
notice, so the only way to find out is to compare a counter against a request
count and see it come up short by a factor of the worker count.
The worker count is the thing that decides whether aggregation is needed, so
read it here and default the directory when it is above 1. An explicit setting
still wins, which is how two servers on one host keep their metrics apart. If
the chosen directory cannot be created the variable is removed again -
prometheus_client raises in every worker if it cannot open the directory it is
pointed at, and taking the server down over metrics would be the wrong trade.
Worker-count parsing moves into _worker_count() so start_http() and the
directory setup cannot disagree about it.
Verified: uvicorn spawns workers via multiprocessing.get_context("spawn"), so
children re-import in a fresh interpreter and inherit the variable set here.
13 new tests cover the default, the explicit override, nested creation, stale
file clearing, and both failure paths; 1228 server/common tests pass; ruff
check, ruff format --check and ty are clean (17 ty diagnostics, all
pre-existing and none in these files).
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01Nr9kacmpFVTTfkZRw6esxP
3 participants
Two fixes to metrics that are wrong in ways nothing reports. Both were found while
trying to attribute request latency on a capacity run and discovering the numbers
could not be trusted.
1. Metrics are not aggregated across uvicorn workers
/metricscalled baregenerate_latest(). WithMEMMACHINE_WORKERS > 1uvicornforks a worker per process and each keeps its own registry, so a scrape returned
whichever worker happened to answer — about 1/N of the traffic, a different 1/N
each time. Consecutive scrapes look like counter resets, and every rate, histogram
quantile and calls-per-request figure derived from them is wrong in an unbounded
direction.
Build a fresh registry per scrape and attach
MultiProcessCollectorwhenPROMETHEUS_MULTIPROC_DIRis set. The single-worker path keeps the defaultregistry, so nothing changes for the default deployment.
Measured, on an 8-tenant capacity run over one rate ladder:
Five consecutive scrapes of a loaded server returned identical values where they
previously diverged.
This needs
PROMETHEUS_MULTIPROC_DIRset and a writable directory mounted at it.The chart change that does so is separate.
2. OperationTracker silently discards timings when given no factory
OperationTrackeracceptsmetrics_factory=Noneand then throws away everytiming it takes — no error, no warning, no series. A component that is fully
instrumented but never handed a factory is indistinguishable from one that was
never instrumented at all, and the only way to notice is to go looking for a
metric that should exist and find nothing.
That is not hypothetical: the Neo4j store, the episode store and the session
store each shipped instrumented and unwired, which is why database latency
appeared to be unmeasurable. Every call was being timed and discarded. This wires
the factory through the resource manager, the database manager and the event
backend's params.
On the tests
test_metrics_factory_wiring.pyasserts at the call sites, not on thecomponents. An earlier version tested that each store honours a factory it is
given — which passes whether or not anything passes one, and still passed with
the fix reverted. The tests here fail when the wiring is removed.
Verification
running server.
memmachine/memmachine:instrumented-mpandexercised with 1, 4 and 8 workers under load.
The two changes are kept as separate commits so either can be reverted alone.
🤖 Generated with Claude Code
https://claude.ai/code/session_01Nr9kacmpFVTTfkZRw6esxP