Repository navigation
perf(jobs): defer aggregate count refresh in process_nats_pipeline_result (5-10x speedup expected) #1288
Description
Activity
- addedPSv2Async & distributed ML backend (PSv2): job state, NATS dispatch, result handling. Umbrella #515.Async & distributed ML backend (PSv2): job state, NATS dispatch, result handling. Umbrella #515.
on Jun 16, 2026 Claude says: Findings from the #928 measurement pass that sharpen this one.
The lever is real and it's the parent refresh. The aggregate count refresh on the result-ingest path is ~83% of the task's wall time, and the Deployment
COUNT(DISTINCT ...)alone is roughly half of it. The production Sentry trace backs this up (n≈11,662; p50 ≈ 12.6 s, p99 ≈ 80.7 s). Deferring the Event/Deployment refresh offprocess_nats_pipeline_result— e.g. to the existingJobState.SUCCESSfinalize step — is the right move and should get the bulk of the win.One framing correction. In an earlier review note I floated the per-image
SourceImage.save()loop as a second N+1 to worry about. Reading it more carefully, that's not the case on the path this issue targets: the async/NATS pull-mode queues one image per task (orchestration/jobs.py), solen(source_images) == 1per result message — the loop runs once, and it's the cheap, indexed, single-row part. So we can drop the "second N+1" concern; the Event/Deployment refresh is the thing to defer, full stop.Coordinate with #1301. These two touch the same code and pull in opposite directions: #1301 adds a per-write cached-count refresh into
save_results, while this issue wants to strip synchronous refresh out of the same area. They should be designed as a single invalidation contract rather than landed independently — otherwise we'll have one refresh path fighting another. The cleanest shape is probably the one #1301 review also lands on: route refreshes through an asyncupdate_cached_counts(run_async=...)so there's one deferred path for both the collection counts and the Event/Deployment counts.One correctness question to settle before implementing: do the in-progress UI views (while a job is still running) read the cached
*_countcolumns or a live query-time annotation? If they read the cached columns, deferring the refresh introduces a staleness window where in-progress counts appear frozen until the deferred refresh runs. That's probably fine, but it's worth deciding deliberately rather than discovering it.Bench numbers above are single-run
EXPLAIN/trace, not averaged under production QPS — whether deferring the parent refresh actually lands the stated p50 < 2 s should be confirmed on staging before any production claim.Claude says: Correcting my earlier version of this comment, which tied this issue to a production incident on 2026-07-29. That link does not hold and I have cut it.
I wrote that deferring the aggregate refresh "would have made the convoy shallower" and that "anything that shortens the time a task spends holding or contending for that row reduces the amplitude of that convoy directly." Both are wrong, for the same reason.
update_calculated_fields_for_eventsanddeployment.update_calculated_fieldssit at the end ofsave_results(ami/ml/models/pipeline.py:1106and:1109-1110), reached fromprocess_nats_pipeline_resultattasks.py:329. In that incident the queued messages all belonged to an already-terminal job whose Redis state had been cleaned up, so the task returned attasks.py:288and never reachedsave_resultsat all.Beyond that,
save_resultsruns outside anytransaction.atomic()in the task, so it holds nojobs_jobrow lock at any point — not on the discard path and not on the happy path either. So the "holding" half of my sentence was false regardless of which path ran.This issue stands on its own measured evidence — roughly 20 to 33 seconds per task with the large majority of it in three aggregate count queries — and does not need the incident tie-in I gave it. Apologies for the noise.
One thing from that incident that is relevant here, and is the reason I looked at this issue in the first place: 35 tasks ran past a 360-second hard time limit with no limit event at all. This issue is useful as the counter-reference, because it treats the 300-second soft limit as a known, observed production event with a Sentry issue behind it. That establishes the limits do fire under normal conditions, which rules out misconfiguration and points instead at the enforcement mechanism having been disabled by the failure. That reasoning does not depend on any claim about locks.
Summary
process_nats_pipeline_resultaverages 20-33s per task in production (p99 78s, occasional 300s SoftTimeLimit hits). About 98% of that time is in DB, and Sentry trace data shows ~83% of all task wall time is consumed by three denormalized DISTINCT COUNT queries triggered byEvent.update_calculated_fields()andDeployment.update_calculated_fields()running on every result message.Each result message → save Detection / Classification / Occurrence rows → cascading saves trigger
update_calculated_fields_for_events→ that runs aggregate counts over the entire deployment / event. With thousands of result messages per job, the same expensive aggregate is recomputed thousands of times.The actual writes (
UPDATE main_sourceimage~11ms,INSERT jobs_joblog~7ms) are cheap. The latency is entirely the count refresh cascade.Observed (last 1h prod sample, n=11,662 task transactions)
SELECT COUNT(*) FROM (SELECT DISTINCT main_detection ... INNER JOIN sourceimage/occurrence/taxon WHERE deployment_id = ... + project filters)WHERE event_id = ...SELECT COUNT(*) FROM (SELECT DISTINCT main_sourceimage ... WHERE event_id = ...)p50 task latency 12.6s, p95 50.9s, p99 80.7s. The 300s tail =
SoftTimeLimitExceededon these queries → NATS redeliveries → cascade.Root cause (verified locally)
ami/main/models.py:1217Event.get_detections_countand:1233Event.get_occurrences_count— both applybuild_occurrence_default_filters_qand run.distinct().count()over Detection joined to SourceImage / Occurrence / Taxon with the project's include/exclude-taxa M2Msami/main/models.py:3080-3081— Deployment equivalentEvent.update_calculated_fields()(models.py:1307-1309) and the matching Deploymentupdate_calculated_fields(), which are called fromupdate_calculated_fields_for_eventsinvoked per result message insideami/ml/models/pipeline.py:save_resultsProposed fixes (ordered by leverage)
1. Defer the aggregate refresh
Stop running
Event.update_calculated_fields+Deployment.update_calculated_fieldsper result message. Options:(a) is the smallest change and would eliminate the bottleneck for active jobs. (b) generalizes to other write-heavy paths.
2. Rewrite the DISTINCT COUNT queries
Independent of (1), the queries themselves are doing more than necessary:
DISTINCT over all Detection columns is wasteful when only IDs matter. Equivalent:
Likely 5-10x speedup on the queries themselves, even before deferring.
3. Verify pg indexes
Check planner picks the right indexes on:
main_sourceimage(deployment_id),(event_id)main_detection(source_image_id)main_occurrence(deployment_id),(event_id)main_taxon.parents_json @> %s(jsonb-contains) needs a GIN index to be cheap — verify.Acceptance criteria
process_nats_pipeline_resultp50 < 2s, p99 < 10s under load (currently p50 12.6s, p99 80.7s)SoftTimeLimitExceededexceptions for this task during normal job executionml_resultsqueueEvent.detections_count/occurrences_countandDeploymentequivalents stay accurate (verify via comparison test before/after)What we still need to verify
save_results(per-imagesource_image.save()loop atpipeline.py:987-988) is also material. NR has no Postgres span instrumentation today (see #separate-ticket on fixing that), so the relative weight of writes-vs-aggregates can only be confirmed via Sentry, which it has been. But other paths insidesave_resultsmay surface once the aggregate cost is removed.Related
AMI-PLATFORM-API-V46(26k events, 9d) — the dominant slow queryAMI-PLATFORM-API-V4A— the by-event variantAMI-PLATFORM-API-TYH(124 events) —SoftTimeLimitExceeded(the 300s tail)cd503d3d7ec74e9fbcbf8730b9670564(300s outlier),cd58dfe64bd44fd2afc4fa27ebc81625,c068b56703cc46dcadec08b0ebbfb55dSample trace IDs (Sentry)
cd503d3d7ec74e9fbcbf8730b9670564— 300s SoftTimeLimit outliercd58dfe64bd44fd2afc4fa27ebc81625— heavy mass examplec068b56703cc46dcadec08b0ebbfb55d— 54s with the N+1 placeholder lookupEffort + risk
pipeline.py:save_resultsto remove the per-message call, plus a job-end hook to runupdate_calculated_fields_for_eventsonce. Risk: counts stay stale until the end of a job — likely fine for most consumers, since the UI mostly cares about final counts. Worth confirming with frontend.