From c29039274349f5ba30a8be289f845c6d445454d2 Mon Sep 17 00:00:00 2001 From: Michael Bunsen Date: Tue, 12 May 2026 11:23:43 -0700 Subject: [PATCH 1/5] perf(api): trim captures list SELECT via .only() MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Replaces the unconditional wide SELECT (every column on main_sourceimage + main_deployment + main_event) on SourceImageViewSet.list with a `.only()` list scoped to fields SourceImageListSerializer actually reads. Row width drops from 52 columns to 26. select_related("deployment__data_source") added so SourceImage.public_url()'s presigned-URL fallback (when public_base_url is blank) does not fire a per-row lazy fetch. SOURCE_IMAGE_LIST_ONLY_FIELDS is exposed as a module-level constant with a maintenance docstring covering how to keep it in sync as the serializer or model methods change. SOURCE_IMAGE_PUBLIC_URL_DEPENDENCIES is split out as a sub-constant so the 11 fields that exist only to support presigned-URL generation are visibly grouped — that whole chain goes away once images are served through the upcoming image-resizing/CDN layer instead of directly from source buckets. Only applied to the list action; retrieve keeps the wide SELECT so the detail serializer's broader field set is unaffected. Tests: - TestSourceImageListQueryCount extended with response-shape assertion guarding against `.only()` over-restriction (verifies url, size_display, deployment.name, event present without lazy loads). Refs: docs/planning/2026-05-11-list-endpoint-perf-continuation-plan.md PR-B1. Co-Authored-By: Claude --- ami/main/api/views.py | 74 +++++++++++++++++++++++++++++++++++++++++++ ami/main/tests.py | 27 ++++++++++++++++ 2 files changed, 101 insertions(+) diff --git a/ami/main/api/views.py b/ami/main/api/views.py index 57654dde8..5e0a98516 100644 --- a/ami/main/api/views.py +++ b/ami/main/api/views.py @@ -472,6 +472,76 @@ def list(self, request, *args, **kwargs): return super().list(request, *args, **kwargs) +# Fields read solely by `SourceImage.public_url()` (exposed as the `url` serializer field). +# `public_url()` falls back to building a presigned S3 URL from the deployment's data_source +# credentials when `SourceImage.public_base_url` is blank — that fallback is what forces the +# `data_source__*` chain to be preloaded. +# +# TEMPORARY. This whole group will be removed once we stop serving images directly from +# their source buckets and instead serve them through our image-resizing/CDN layer. At that +# point `url` becomes a static derivation from `id`/`path` and the data_source credentials +# no longer need to fan out into every list response. +# +# Until then, every column here is load-bearing for the list endpoint — dropping any one of +# them triggers a deferred-field SELECT per row during serialization. +SOURCE_IMAGE_PUBLIC_URL_DEPENDENCIES = ( + "path", + "public_base_url", + "deployment__data_source_id", + "deployment__data_source__id", + "deployment__data_source__bucket", + "deployment__data_source__region", + "deployment__data_source__prefix", + "deployment__data_source__access_key", + "deployment__data_source__secret_key", + "deployment__data_source__endpoint_url", + "deployment__data_source__public_base_url", +) + +# Columns preloaded for the SourceImage list response. Must include every column read by +# `SourceImageListSerializer` *and* every column touched by model methods on the serialized +# fields, so DRF serialization never triggers a deferred-field lazy load. +# +# How to keep this in sync when adding a serializer field or a model method: +# 1. Add the DB columns the new field/method reads (use `__` for FK chains). +# 2. Run TestSourceImageListQueryCount — the response-shape test fails loudly if a +# lazy load fires during serialization, and the scaling tests fail if a missing +# column causes per-row queries. +# +# Notes on what is and is NOT here: +# - `detections_count` is a cached DB column on SourceImage and IS preloaded. +# - `occurrences_count` and `taxa_count` are NOT columns on SourceImage — they exist +# only when `with_counts=true` adds them as annotations. Listing them here would +# raise FieldDoesNotExist. +# - The `deployment__data_source__*` chain is grouped into +# `SOURCE_IMAGE_PUBLIC_URL_DEPENDENCIES` above — see that constant for why it exists +# and when it goes away. +SOURCE_IMAGE_LIST_ONLY_FIELDS = ( + # Core fields read by the serializer (id, timestamps, dimensions, cached counts, FKs). + "id", + "timestamp", + "width", + "height", + "size", + "detections_count", + "project_id", + "deployment_id", + # Nested DeploymentNestedSerializer ({id, name, details}) and permission walk. + "deployment__id", + "deployment__name", + "deployment__project_id", + # Nested EventNestedSerializer ({id, name, details, date_label}) — name/date_label + # read `start` and `end`. + "event_id", + "event__id", + "event__start", + "event__end", + "event__deployment_id", + # See constant above. TEMPORARY — drops when image serving moves behind the CDN. + *SOURCE_IMAGE_PUBLIC_URL_DEPENDENCIES, +) + + class SourceImageViewSet(DefaultViewSet, ProjectMixin): """ API endpoint that allows captures from monitoring sessions to be viewed or edited. @@ -539,9 +609,13 @@ def get_queryset(self) -> QuerySet: queryset = queryset.select_related( "event", "deployment", + "deployment__data_source", ).order_by("timestamp") if self.action == "list": + # Trim row width to the fields SourceImageListSerializer + model methods read. + # See SOURCE_IMAGE_LIST_ONLY_FIELDS comment for maintenance rules. + queryset = queryset.only(*SOURCE_IMAGE_LIST_ONLY_FIELDS) # It's cumbersome to override the default list view, so customize the queryset here queryset = self.filter_by_has_detections(queryset) diff --git a/ami/main/tests.py b/ami/main/tests.py index fe28705dc..091ae7ec3 100644 --- a/ami/main/tests.py +++ b/ami/main/tests.py @@ -3206,6 +3206,33 @@ def test_list_query_with_counts_and_detections(self): ) self.assertLessEqual(large, small + 5, f"SourceImage list scaling: {small} -> {large} (likely N+1)") + def test_list_response_shape_preserved_after_only(self): + """Guards against `.only()` over-restricting fields: every row must still serialize + `url`, `size_display`, `deployment.name`, and `event.name` without lazy loads.""" + from django.core.cache import caches + from django.test.utils import CaptureQueriesContext + + url = f"/api/v2/captures/?project_id={self.project.pk}&limit=5" + self.client.get(url) + caches["default"].clear() + with CaptureQueriesContext(connection) as ctx: + res = self.client.get(url) + self.assertEqual(res.status_code, status.HTTP_200_OK) + body = res.json() + self.assertGreater(len(body["results"]), 0) + row = body["results"][0] + # Confirm fields the serializer reads (some via model methods) are non-null/present. + for key in ("id", "url", "size_display", "deployment", "event", "detections_count", "path"): + self.assertIn(key, row, f"missing field {key!r} in list response") + self.assertIsNotNone(row["deployment"]["name"]) + # No lazy-load queries should fire after the main list SELECT. + # 1 list select + 1 detection prefetch (no, not in this call) + savepoints. + self.assertLessEqual( + len(ctx.captured_queries), + 6, + f"Unexpected extra queries — likely lazy-load from deferred field: {len(ctx.captured_queries)}", + ) + @override_settings(CACHALOT_ENABLED=False) class TestTaxonListQueryCount(APITestCase): From 3f34b783f56b5918ec1fa70014cac229cfd7cfa7 Mon Sep 17 00:00:00 2001 From: Michael Bunsen Date: Tue, 12 May 2026 11:23:52 -0700 Subject: [PATCH 2/5] docs: list-endpoint perf planning trail MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Adds: - 2026-05-11-newrelic-post-upgrade-findings.md — NR prod data after the agent upgrade that surfaced the list-endpoint hot paths. - 2026-05-11-list-endpoint-perf-analysis.md — SQL-level root-cause analysis for the 3 endpoints (collection list, captures list, project charts). - 2026-05-11-list-endpoint-perf-continuation-plan.md — sequenced PR plan. PR-A (collection subquery rewrite) superseded by the denormalize-counts approach on perf/sourceimagecollection-cached-counts. PR-B1 ships in this PR. PR-C/D/E queued. Co-Authored-By: Claude --- .../2026-05-11-list-endpoint-perf-analysis.md | 219 ++++++++++++++++++ ...11-list-endpoint-perf-continuation-plan.md | 158 +++++++++++++ ...26-05-11-newrelic-post-upgrade-findings.md | 133 +++++++++++ 3 files changed, 510 insertions(+) create mode 100644 docs/planning/2026-05-11-list-endpoint-perf-analysis.md create mode 100644 docs/planning/2026-05-11-list-endpoint-perf-continuation-plan.md create mode 100644 docs/planning/2026-05-11-newrelic-post-upgrade-findings.md diff --git a/docs/planning/2026-05-11-list-endpoint-perf-analysis.md b/docs/planning/2026-05-11-list-endpoint-perf-analysis.md new file mode 100644 index 000000000..fd1d87f9e --- /dev/null +++ b/docs/planning/2026-05-11-list-endpoint-perf-analysis.md @@ -0,0 +1,219 @@ +# List endpoint perf analysis — 2026-05-11 + +**Status:** observations + fix hypotheses, no PR yet. +**Source:** New Relic prod data, 30 min window after PR #1299 (NR agent 12.1.0 + tuned `function_trace`) and PR #1274 (Occurrence N+1 fix) shipped. + +## tl;dr + +`OccurrenceViewSet.list` is fixed (p95 dropped from ~35s in a prior incident to **0.93s**, DB share dropped from ~100% to 32%). Three remaining list-endpoint hot paths surfaced: + +1. **`SourceImageCollectionViewSet.list`** — unconditional `COUNT(DISTINCT) FILTER (...)` annotations on a 4-table join. Two queries × ~5s each per page. p95 **10.58s**. Highest leverage. +2. **`SourceImageViewSet.list`** — wide SELECT pulling all `main_deployment` + `main_event` columns into every row; paginator COUNT(*) does the same JOIN. p95 **4.47s**. +3. **`ProjectViewSet.charts`** — full-table aggregates over `main_sourceimage` with `EXTRACT(HOUR|MONTH FROM timestamp)`. p95 **7.58s**. Lower frequency (~2/15 min), separate fix shape. + +None of these are N+1 in the same sense as `OccurrenceViewSet.list` was; they're each a small number of expensive single queries. + +## 1. SourceImageCollectionViewSet.list — annotation explosion + +### Observation + +NR captured the SQL via `record_sql = raw`. Each list request issues two queries: + +**Query A (annotation, 6.14s top, ~1.5s typical):** +```sql +SELECT main_sourceimagecollection.*, + COUNT(DISTINCT main_sourceimagecollection_images.sourceimage_id) AS source_images_count, + COUNT(DISTINCT main_sourceimagecollection_images.sourceimage_id) + FILTER (WHERE main_detection.bbox IS NOT NULL AND main_detection.bbox <> '...') + AS source_images_with_detections_count, + COUNT(DISTINCT main_sourceimagecollection_images.sourceimage_id) + FILTER (WHERE main_detection.id IS NOT NULL) + AS source_images_processed_count +FROM main_sourceimagecollection +LEFT JOIN main_sourceimagecollection_images + ON main_sourceimagecollection.id = main_sourceimagecollection_images.sourceimagecollection_id +LEFT JOIN main_sourceimage + ON main_sourceimagecollection_images.sourceimage_id = main_sourceimage.id +LEFT JOIN main_detection + ON main_sourceimage.id = main_detection.source_image_id +WHERE project_id = %s +GROUP BY main_sourceimagecollection.id +LIMIT ?; +``` + +**Query B (paginator COUNT, 3.97s top, ~0.7s typical):** +```sql +SELECT COUNT(*) FROM ( + SELECT main_sourceimagecollection.id + FROM main_sourceimagecollection + LEFT JOIN main_sourceimagecollection_images ... + LEFT JOIN main_sourceimage ... + LEFT JOIN main_detection ... + WHERE project_id = %s + GROUP BY ? +) subquery; +``` + +Same 4-table join done twice. The 3 `COUNT(DISTINCT) FILTER (...)` aggregates walk every detection in every image in every collection in the project. + +Sum across 9 calls in 30 min: **13.25s** of pure Query-A time. The same window had **6** `main_sourceimage.timestamp/select` calls @ avg 2.16s (those belong to `ProjectViewSet.charts` — see §3) — i.e. the collection-list endpoint, despite low call count, contributes meaningful DB load. + +### Root cause + +In `ami/main/api/views.py:715-719`: + +```python +queryset = ( + SourceImageCollection.objects.all() + .with_source_images_count() + .with_source_images_with_detections_count() + .with_source_images_processed_count() + .prefetch_related("jobs") +) +``` + +The three count annotations are applied **unconditionally on the class-level `queryset`**, before `get_queryset()` runs. List requests pay even when the caller doesn't ask for counts. + +Compare: in the same view (`SourceImageCollectionViewSet.get_queryset`, views.py:737-758), `with_occurrences_count` and `with_taxa_count` are correctly gated by `?with_counts=1`. The three image-counts predate that gating and were missed. + +Annotation definitions live in `ami/main/models.py:4074-4101` (`SourceImageCollectionQuerySet.with_source_images_*`); the property fallbacks at `models.py:4201-4213` return `None` if pre-population missed. + +### Fix candidates (ordered by reversibility) + +**A. Gate the three count annotations behind `with_counts` (smallest change).** + +Move the three `.with_*()` calls out of the class-level `queryset` and into the `if with_counts:` block in `get_queryset()`. Frontend consumers that today rely on the counts being free will need to pass `?with_counts=1`. + +Risk: silently changes API shape for any caller that reads `source_images_count` without `with_counts`. They'd start getting `None`. Audit callers first. + +**B. Replace annotation with denormalized columns on `SourceImageCollection`.** + +Add three integer columns (`source_images_count`, `source_images_with_detections_count`, `source_images_processed_count`) updated by signal on `SourceImageCollection_images.through.{add,remove}` and `Detection.{create,delete}`. Same shape as `Deployment.captures_count` and friends already present on `Deployment` (see `models.py` `Deployment` model fields). + +Risk: signal-based denormalization drifts under bulk ops. Need a periodic reconcile management command. Higher effort but cleanest read-path. + +**C. Replace LEFT JOIN aggregates with correlated `Subquery(...)` annotations.** + +```python +images_subquery = SourceImage.objects.filter( + collections=OuterRef("pk") +).order_by() +annotate( + source_images_count=Subquery(images_subquery.values("collections").annotate(c=Count("id")).values("c")), + ... +) +``` + +PostgreSQL planner can index-scan each subquery against `main_sourceimagecollection_images` independently, avoiding the cartesian blowup of 3 distinct-count aggregates. Easier than B, less invasive than A. + +**D. Fix the paginator JOIN (Query B) regardless of A/B/C.** + +Even if the annotation goes, DRF's paginator currently issues `SELECT COUNT(*) FROM ()`. Override `paginator.get_count` or use `qs.values_list("id").count()` style to bypass the annotated aggregate. This is independent of the annotation question. + +### Recommended path + +A + D for the immediate p95 drop; B as the longer-term cleanup. C is a fallback if A breaks the frontend in audit. + +## 2. SourceImageViewSet.list — wide select + paginator + +### Observation + +Top main_sourceimage SQL last 30 min (NR datastore spans): + +**Query A (list rows, 2.38s top, ~1.1s typical):** +```sql +SELECT + main_sourceimage.<18 cols>, + main_deployment.<25 cols>, + main_event.<13 cols> +FROM main_sourceimage +LEFT JOIN main_deployment ON main_sourceimage.deployment_id = main_deployment.id +LEFT JOIN main_event ON main_sourceimage.event_id = main_event.id +WHERE ... +ORDER BY timestamp; +``` + +**Query B (paginator COUNT, 1.12s):** +```sql +SELECT COUNT(*) +FROM main_sourceimage +INNER JOIN main_deployment ON main_sourceimage.deployment_id = main_deployment.id +WHERE main_deployment.project_id = %s; +``` + +### Root cause + +Three contributing factors, listed in order of suspected impact: + +1. **`select_related("event", "deployment")` is unconditional** (views.py:539). Pulls full row of both tables every time. `SourceImageListSerializer` doesn't read most of those columns. +2. **Paginator JOIN is unnecessary.** `main_sourceimage` has `project_id` directly (`models.py` `SourceImage.project = ForeignKey(Project)`). The paginator joins to `main_deployment` only because the filter uses `deployment__project=...`. Filter could go via `project=...` instead. +3. **`order_by("timestamp")` without `(project_id, timestamp)` composite index.** `timestamp` alone is indexed (`models.py` `SourceImage.timestamp = DateTimeField(db_index=True)`), but a Project-scoped `ORDER BY timestamp` cannot use it efficiently. + +### Fix candidates + +**A. Trim the SELECT:** `queryset.only("id", "path", "timestamp", "deployment_id", "deployment__name", "event_id", "event__start", ...)` matching only the fields the list serializer reads. Halve the row width. + +**B. Override `get_queryset` count path** for list — at minimum filter by `project=project` directly, not `deployment__project=project`. The DRF paginator then drops the JOIN. + +**C. Add composite index** on `main_sourceimage(project_id, timestamp DESC)` via migration. Lets `ORDER BY timestamp` use an index range-scan for a project-filtered list. + +A + B are zero-risk and recover most of the latency. C requires a migration (large table — `CONCURRENTLY` recommended). + +## 3. ProjectViewSet.charts — full-scan aggregates + +### Observation + +Time-correlated to the `charts` action, not `SourceImageViewSet.list`: + +```sql +-- 3.31s top +SELECT (timestamp)::date, EXTRACT(HOUR FROM timestamp), COUNT(*) +FROM main_sourceimage +WHERE project_id = %s AND timestamp IS NOT NULL +GROUP BY 1, 2 ORDER BY 1, 2; + +-- 2.95s top +SELECT EXTRACT(MONTH FROM timestamp), COUNT(*) +FROM main_sourceimage +WHERE project_id = %s AND timestamp IS NOT NULL +GROUP BY 1 ORDER BY 1; +``` + +Source: `ami/main/charts.py:40,89,117`. The endpoint feeds the project dashboard's capture-heatmap and monthly-distribution charts. + +### Root cause + +Full-table aggregate over `main_sourceimage` filtered only by `project_id`. No index can usefully accelerate `EXTRACT(HOUR FROM timestamp)` because the function is applied per row. + +### Fix candidates + +**A. Cache the chart payload.** Cachalot is already enabled; can pin chart endpoints with a longer TTL (chart values change on capture ingest, not on user interaction). Lowest effort, highest user-facing win. + +**B. Materialized aggregates.** Roll up per-(project, date, hour) into a denormalized table updated nightly. Reads are O(displayed range), not O(all captures). + +**C. Functional index on `(project_id, date_trunc('hour', timestamp))`.** Useful if A and B are both off the table; less effective than B for the monthly aggregate. + +A first — chart freshness on the order of minutes is fine for these views. + +## What still won't surface in NR + +- **Datastore spans aren't tagged with `transaction.name`** in the async-Django + Python agent path (`Span.trace.id` also null on Transaction events). Span→Transaction attribution is by `timestamp` correlation only. Documented blocker; see internal NR proposal. +- **Cachalot internals aren't auto-instrumented.** If chart caching (§3 A) is applied, cache hit/miss rate won't appear in NR. Would need an import-hook. + +## Proposed sequencing + +1. PR for §1.A + §1.D (gate annotations, drop paginator JOIN) — lowest risk, biggest p95 drop on the list page. +2. PR for §2.A + §2.B (trim SELECT, fix count filter) — independent. +3. Decision on §1.B (denormalized columns) before any other annotation-heavy view ships. +4. §3 in a separate ticket; not in the critical path. + +## Verification protocol + +For each PR, after merge to staging or a perf branch: + +1. Run `OccurrenceViewSet.list` regression check first (PR #1274 baseline must not break). NR query: `SELECT percentile(duration, 95) FROM Transaction WHERE name = 'WebTransaction/Function/ami.main.api.views:OccurrenceViewSet.list' SINCE 1 hour ago`. +2. Hit the target endpoint with the same query the failing trace used (project_id known from the slow trace). +3. Compare NR p95 + the per-span `Datastore/statement/...` durations against the values in this doc. +4. Re-run with `?with_counts=1` to verify the gated path still works. + +Numbers in this doc are **post-PR-#1274** prod data, 2026-05-11 ~23:50 UTC, 30-min window. Sample sizes are small for the rarer endpoints (Charts: 2 hits; SourceImageCollection.list: 9 hits) — treat the p95s as directional, not stable. diff --git a/docs/planning/2026-05-11-list-endpoint-perf-continuation-plan.md b/docs/planning/2026-05-11-list-endpoint-perf-continuation-plan.md new file mode 100644 index 000000000..da9b865dd --- /dev/null +++ b/docs/planning/2026-05-11-list-endpoint-perf-continuation-plan.md @@ -0,0 +1,158 @@ +# List-endpoint perf — continuation plan + +**Date:** 2026-05-11 +**Status (2026-05-12 update):** +- **PR-A (collection list subquery rewrite)** — superseded. The subquery shape benchmarked mixed on the row SELECT, and the paginator-COUNT win is invisible because the UI does not paginate collections. Replaced by a denormalize-counts-as-columns approach on its own branch (`perf/sourceimagecollection-cached-counts`). +- **PR-B1 (captures list `.only()` + data_source preload)** — in flight as PR #1300, scope renamed to "Speed up the captures list view". +- **PR-B2 / PR-C / PR-D / PR-E** — queued, see sections below. + +**Companions:** +- [`2026-05-11-newrelic-post-upgrade-findings.md`](2026-05-11-newrelic-post-upgrade-findings.md) — prod NR data (DB visibility, top N+1s, conn-pool incident) +- [`2026-05-11-list-endpoint-perf-analysis.md`](2026-05-11-list-endpoint-perf-analysis.md) — root-cause SQL analysis for the same three endpoints (read first; this plan refers to its §1/§2/§3) +- [PR #1274](https://github.com/RolnickLab/antenna/pull/1274) — `OccurrenceViewSet` N+1 fix; merged 2026-05-11 23:46 UTC. Use as the template for solution shape *and* validation methodology + +## What this plan is + +A sequenced action plan for the **three list-endpoint hot paths** the analysis doc identified, plus the **one detail-endpoint hot path** the NR data surfaced post-merge. Numbered in suggested PR order. Each PR is independently mergeable. + +Local-testable. Reuses PR #1274 measurement tooling. + +## State at start of this plan + +**Already in flight (this branch):** +- `SourceImageCollectionQuerySet.with_source_images_count` / `with_source_images_with_detections_count` / `with_source_images_processed_count` rewritten as correlated `Subquery(Count())` annotations (`ami/main/models.py:4074-4117`). Same fix shape as `SourceImageQuerySet.with_occurrences_count` (models.py:1865) and `with_taxa_count` (models.py:1893) — which were already using subqueries and carried `@TODO update the SourceImageCollectionQuerySet to use the same approach` (now removed). +- SQL verified via Django shell: + - Annotated list: 3 independent scalar subqueries on `main_sourceimage` + the M2M through table only. No cartesian blowup. + - Paginator count: collapsed to `SELECT COUNT(*) FROM main_sourceimagecollection WHERE project_id = ?`. No JOIN, no GROUP BY. +- `ami.main.tests -k SourceImageCollection` passes (9/9). + +This is **planning-doc §1 option C + D** delivered as one change. Option A (gate behind `with_counts`) is not pursued because `capture-set-columns.tsx:101` uses `source_images_count` as a sort field — gating would break the list page without coordinated frontend work. + +## Sequenced PRs + +### PR-A — `SourceImageCollectionViewSet.list` subquery rewrite *(in flight)* + +- Status: code written, unit tests pass, SQL verified. Needs query-count regression guard before commit. +- Effort: small. No migration. No API shape change. No frontend change. +- Risk: low — same pattern already in use on `SourceImageQuerySet`. +- Estimated payoff: planning doc measured ~13s of DB time/30min on this endpoint with 9 calls. Subquery rewrite eliminates the cartesian blowup; expected p99 drop from 10.5s → <2s based on the planner's ability to use the FK index per subquery. +- **Test before merge** (mirrors PR #1274 regression guard): + - Add `TestSourceImageCollectionListQueryCount` to `ami/main/tests.py` using `CaptureQueriesContext` + `@override_settings(CACHALOT_ENABLED=False)`. Run `/captures-set/?project=X&limit=25`; assert query count ≤ small constant regardless of page size. Three variants: cold list, list with `?with_counts=1`, list with sort by `source_images_count`. + - Local end-to-end: `docker compose run --rm django python manage.py test ami.main.tests -k Collection --keepdb` (already passing). + - Local SQL inspection: `EXPLAIN ANALYZE` against demo DB for both shapes; confirm planner uses `main_sourceimagecollection_images_sourceimagecollection_id_idx` for each subquery. + +### PR-B — `SourceImageViewSet.list` SELECT trim + paginator JOIN fix + +References: `ami/main/api/views.py:475-583`. Planning doc §2. + +- Two sub-changes, both small and zero-risk: + 1. **B1: Trim the SELECT** (§2.A). Replace the unconditional `select_related("event", "deployment")` with `.only("id", "path", "timestamp", "deployment_id", "deployment__name", "event_id", "event__start", …)`. Match exactly what `SourceImageListSerializer` reads. Halves row width. + 2. **B2: Drop the paginator JOIN** (§2.B). The endpoint currently scopes by `deployment__project` which forces the paginator's `COUNT(*)` to join `main_deployment`. `main_sourceimage` has a direct `project_id` FK — switching the project filter to `project=project` (or adding `.filter(project=project)` before the deployment-scoped filters in `get_queryset`) lets the paginator skip the JOIN. +- Effort: small. No migration. +- Risk: low. `.only()` is reversible; needs an audit of `SourceImageListSerializer` field access (model methods that touch un-loaded columns will trigger lazy loads → re-introducing N+1 silently). +- Skipped from §2: **C — composite index `(project_id, timestamp DESC)`** on `main_sourceimage`. Real win at scale but requires a `CONCURRENTLY` migration on a large table. Park for a follow-up PR with measured before/after; not urgent if B1+B2 land first. +- **Test before merge**: + - Add `TestSourceImageListQueryCount` already exists from PR #1274 — extend it with `select_related` and `paginator-count` assertions. The existing test passes at 4 queries for `with_detections=true&with_counts=true`; should not regress. + - Cold-row width check via Django shell: `print(SourceImage.objects.filter(project_id=X).only(...)[0].__dict__)` — verify only-fields are loaded, no `_deferred_fields` cascade in serializer access. + +### PR-C — `SourceImageViewSet.retrieve` audit *(NEW from NR data)* + +References: `ami/main/api/views.py:548-574`. **Not covered in the planning doc.** + +- NR observed **571 DB calls / 1.5s** on a single `/captures//` request (newrelic-post-upgrade-findings §2). Likely culprits: + 1. **`prefetch_detections(queryset, project)` on retrieve** (views.py:561) — runs the same `filtered_detections` Prefetch the list uses, but on a detail object. The nested Prefetch attaches `occurrence` + `occurrence__determination` to every detection. With ~100s of detections per high-traffic image, the inner `Max("occurrence__detections__classifications__score")` subquery can fire per row. + 2. **`add_adjacent_captures()`** (views.py:637-688) — wires four subqueries (next, previous, index, total) into the queryset. Cheap per subquery but adds 4 to the floor count. + 3. **`with_occurrences_count()` + `with_taxa_count()`** annotations (views.py:567-572) applied on `with_counts_default=True` for retrieve. +- Effort: medium. Likely needs an audit pass like PR #1274's: ([what does the serializer actually read?]→[which prefetches/annotations are required?]→[remove the rest]). +- Approach: mirror PR #1274 exactly: + - Create `ami/main/models_future/source_image.py` with `prefetch_detections_for_detail()` (only nested relations the detail serializer reads). + - Add `SourceImageQuerySet.with_detail_prefetches()`. + - Wire `get_queryset` to call it for the retrieve action; remove the bespoke `prefetch_detections` reuse-on-retrieve. + - Add `_require_prefetch()` strict gate on any model methods the detail serializer calls that depend on prefetched detections. +- **Test before merge**: + - Add `TestSourceImageRetrieveQueryCount` — single-row fetch should be a small constant of queries (target ≤10) regardless of detection count. + - Synthetic test with 1 / 50 / 500 detections per image; assert query count does **not** scale with detection count. + +### PR-D — `SourceImageCollectionViewSet.populate` / `add` and other endpoint shape + +Out of scope for this plan. Mentioning to flag: those write paths (views.py:767, 813) call `collection.images.count()` and `collection.images.add(...)` synchronously. If we move to denormalized count columns (planning doc §1.B as a longer-term direction), those write paths become the natural maintenance points. Not blocking PR-A. + +### PR-E — `ProjectViewSet.charts` (out of critical path) + +Planning doc §3. NR shows 7.6s tail with 36 queries — aggregate-bound, not N+1. Three fix candidates in the planning doc. **A (cachalot pinning)** is the right first step: chart freshness on the order of minutes is acceptable, and the existing cachalot infrastructure already covers it. Separate ticket. + +## Comparison vs PR #1274 approach + +| Concern | PR #1274 (Occurrence list) | PR-A (Collection list) | PR-B (SourceImage list) | PR-C (SourceImage retrieve) | +|---|---|---|---|---| +| **Problem shape** | True N+1 (1.6 extra queries/row) | Annotation-aggregate cartesian (1 big query × 4 tables) | Wide-row + paginator JOIN | Suspected N+1 on detail | +| **Solution shape** | Strict prefetch factories + `_require_prefetch` gate | Correlated `Subquery(Count())` | `.only()` + filter rewrite | Likely same as #1274 (prefetch factory + strict gate) | +| **New module needed?** | Yes (`models_future/occurrence.py`) | No | No | Yes (`models_future/source_image.py`) | +| **API shape change?** | List `detection_images` capped at 1 (was unbounded) | None | None | TBD | +| **Migration?** | None | None | None (C in §2 adds one, deferred) | None | +| **Tests** | `TestOccurrenceListQueryCount`, `TestOccurrenceDetailQueryCount`, `TestOccurrencePrefetchHelpersEdgeCases` | `TestSourceImageCollectionListQueryCount` (new) | Extend existing `TestSourceImageListQueryCount` | `TestSourceImageRetrieveQueryCount` (new) | +| **Local benchmark** | `scripts/benchmark_occurrences_list.sh` | Reuse with `--endpoint=/captures-set/` parametrization | Same; already has it | Same with `--endpoint=/captures//` | + +**Key takeaway**: only PR-C (and possibly a §1.B follow-up) needs PR #1274's `_require_prefetch` strict-contract machinery. PR-A and PR-B are smaller SQL-shape changes that don't need a new helper module — the QuerySet rewrite is the whole fix. + +## Local validation methodology + +For every PR in this plan: + +1. **Cold query count regression test.** Pattern (mirrors `ami/main/tests.py::TestOccurrenceListQueryCount`): + ```python + from django.test.utils import CaptureQueriesContext + from django.db import connection + from django.test import override_settings + + @override_settings(CACHALOT_ENABLED=False) + def test__list_query_count(self): + # warmup (load app, perm cache) + self.client.get(f"{URL}?limit=5") + self.client.get(f"{URL}?limit=5") + with CaptureQueriesContext(connection) as ctx: + response = self.client.get(f"{URL}?limit=25") + self.assertLess(len(ctx.captured_queries), N) + ``` + `@override_settings(CACHALOT_ENABLED=False)` is critical — cachalot otherwise hides the N+1 on warm DB. + +2. **SQL shape inspection.** Django shell: + ```python + qs = .objects.(...) + print(str(qs.query)) # annotated list SQL + from django.db import connection + qs.count() + print(connection.queries[-1]['sql']) # paginator count SQL + ``` + +3. **Local stack DB benchmark.** Against the demo project (`create_demo_project`): + ```bash + docker compose exec django python manage.py shell -c " + from django.test.utils import CaptureQueriesContext + from django.db import connection + from django.test.client import Client + c = Client() + c.force_login() + with CaptureQueriesContext(connection) as ctx: + r = c.get('/api/v2/captures-set/?project=1&limit=25') + print(f'{len(ctx.captured_queries)} queries, {r.status_code}') + " + ``` + +4. **EXPLAIN ANALYZE on a real-data DB copy** (where available — staging arbutus-2026 has the production schema and realistic row counts). Confirms the planner picks the FK index per subquery on PR-A and confirms the paginator drops the JOIN on PR-B. + +5. **A/B concurrent load** (only for PRs likely to affect saturation behavior — PR-A and PR-B). Reuse PR #1274's `scripts/benchmark_occurrences_list.sh` with `--endpoint` switched. The pattern: 10/40 concurrent × limit=25/100, p50/p95/p99/max + per-status error counts. Run against `arctia.dev` or equivalent staging. + +## Open follow-ups (won't block this plan) + +- **Tracked separately**: `SourceImageViewSet.retrieve` — file ticket and reference NR data + this plan's PR-C row. +- **Tracked separately**: `ProjectViewSet.charts` cachalot pinning — planning doc §3. +- **Maybe revisit**: composite index `main_sourceimage(project_id, timestamp DESC)` after PR-B is in prod for a week. If `SourceImageViewSet.list` p95 is still above target (~1s), the index is the next lever. +- **From PR #1274's deferred list**: expose `?detection_images_limit=N` query param on `OccurrenceViewSet` — relevant once tracking-merged occurrences are common. Cross-reference: that PR caps at 1 (list) / 100 (detail) which works today. + +## Why this plan, not a single mega-PR + +- PR-A is **already coded**; merging it alone is a clean small win. +- PR-B is **independent of PR-A** (different endpoint, different DB tables). Bundling adds review surface for no shipping speedup. +- PR-C **needs new infrastructure** (`models_future/source_image.py`) and an audit pass; lumping it with PR-A/B would push the easy wins behind the hard one. +- PR #1274's audit-then-fix sequencing is the proven pattern. Apply it three times rather than once, each scoped to a single endpoint family. diff --git a/docs/planning/2026-05-11-newrelic-post-upgrade-findings.md b/docs/planning/2026-05-11-newrelic-post-upgrade-findings.md new file mode 100644 index 000000000..8c382c655 --- /dev/null +++ b/docs/planning/2026-05-11-newrelic-post-upgrade-findings.md @@ -0,0 +1,133 @@ +# New Relic post-upgrade findings — 2026-05-11 + +**Status:** observations after PR #1299 (NR agent 9.6.0 → 12.1.0 + tuned config) shipped. Hypothesis-framed; no fixes proposed below the connection-pool incident. +**Companion doc:** [`2026-05-11-list-endpoint-perf-analysis.md`](2026-05-11-list-endpoint-perf-analysis.md) — covers the SourceImageCollection/SourceImage/Project.charts list-side detail this doc only summarizes. +**Data window:** ~1h after deploy; throughput 181 rpm, errorRate 0%, avg resp 65ms, 16 hosts reporting. + +## tl;dr + +1. **DB visibility restored.** `databaseCallCount` populated on 57% of transactions vs 2.8% one day earlier. ~20× lift, no other agent variables changed. Confirms the psycopg3 instrumentation gap was the cause, not ASGI context. +2. **Surfaced N+1 on `SourceImageViewSet.retrieve`** — 571 DB calls per single-image fetch, 1.5s p99. Hidden pre-upgrade; not on PR #1274's radar. +3. **Surfaced PG connection-slot exhaustion burst** around the deploy window (22:22–22:32 UTC). 440 `OperationalError` events, ~99% at `CsrfViewMiddleware.process_view` (request entry, before any view). Pattern suggests a pool-sizing or `CONN_MAX_AGE` issue rather than a slow-endpoint cause. +4. **`function_trace` config is mostly redundant** — DRF auto-instrumentation already captures every `*ViewSet.list/.retrieve`. Only the Pydantic-heavy serializer method and the two Celery task entries are still earning their slot. + +## 1. DB visibility — before/after + +NRQL: +``` +SELECT filter(count(*), WHERE databaseCallCount IS NOT NULL) as with_db, + count(*) as txns +FROM Transaction +WHERE appName = '' +SINCE 1 hour ago COMPARE WITH 1 day ago +``` + +| Window | Txns | With DB call count | +|---|---|---| +| Current (agent 12.1.0) | 9863 | **5669 (57.4%)** | +| 1 day ago (agent 9.6.0) | 8815 | 245 (2.8%) | + +Postgres span breakdown is now usable: `main_occurrence/select` 191ms avg with a 568ms tail; `main_taxon/select` 21ms avg but a 704ms outlier; `ml_processingservice/update` 125 spans (periodic health check chatter, max 115ms); Redis `mget` 17780 calls @ 0.7ms avg (cachalot working as expected). None of this was queryable before the upgrade. + +## 2. Top N+1 / slow-tail endpoints + +Transactions filtered to `duration > 0.5s`, faceted by name, 1h window: + +| Endpoint | n | avg | p99 | DB calls/req | DB ms | +|---|---|---|---|---|---| +| **`SourceImageViewSet.retrieve`** | 1 | 1469ms | 1469ms | **571** | 866ms | +| `OccurrenceViewSet.list` | 80 | 624ms | 1310ms | 194 | 177ms | +| `ProjectViewSet.list` | 9 | 578ms | 644ms | 242 | 305ms | +| `SourceImageViewSet.list` | 4 | 3489ms | 4974ms | 167 | 3335ms | +| `EventViewSet.list` | 1 | 4142ms | 4142ms | 118 | 3986ms | +| `SourceImageCollectionViewSet.list` | 4 | 3693ms | 10583ms | 117 | 3484ms | +| `SummaryView.get` | 4 | 965ms | 1542ms | 26 | 892ms | +| `TaxonViewSet.list` | 2 | 1441ms | 1505ms | 20 | 1363ms | +| `ProjectViewSet.charts` | 1 | 7585ms | 7585ms | 36 | 7457ms | + +### Worth calling out + +- **`SourceImageViewSet.retrieve` @ 571 DB calls** — only one sample in this window, but the call count is so far above the rest that it's almost certainly an N+1 (and not just slow individual queries). Companion doc covers the list endpoint; the **detail endpoint hasn't been audited**. Likely candidates: `detections` prefetch missing on the detail serializer, or `Occurrence.detection_images / .best_prediction / .best_identification` firing per detection inside the response. +- **`SourceImageCollectionViewSet.list` and `SourceImageViewSet.list`** are dominated by **DB time** (>95% of total). High DB-call counts but bigger fix is the SQL itself, not the count — see companion doc for the `COUNT(DISTINCT) FILTER (...)` annotation-explosion analysis. +- **`ProjectViewSet.charts` @ 7.6s with only 36 queries** — not an N+1. Aggregate-heavy SQL. Different fix shape (materialized view, or limit time range default). +- **PR #1274 target is real but not the worst offender.** OccurrenceViewSet.list at 194 calls / 1.3s p99 is in the upper tier, but Detail+Collection list outrank it on both call-count and tail. + +## 3. PG connection-pool incident — 22:22–22:32 UTC + +### Observation + +`TransactionError` table, `error.class = django.db.utils:OperationalError`, last 24h: + +``` +22:22 UTC — 4 errors +22:27 UTC — 152 errors +22:32 UTC — 284 errors +all other hours — 0 +``` + +Error messages: +- 402× `connection failed: FATAL: remaining connection slots are reserved for non-replication superuser connections` +- 22× `connection failed: FATAL: sorry, too many clients already` +- 15× combination of both + +Faceted by `transactionName`: +- **435/440 at `WebTransaction/Function/django.middleware.csrf:CsrfViewMiddleware.process_view`** +- 4 at `OtherTransaction/Celery/ami.jobs.tasks.update_async_services_seen_for_pipelines` +- 1 at `WebTransaction/Function/ami.main.api.views:SourceImageViewSet.list` + +### Interpretation (hedged) + +The CSRF middleware runs early in the Django request lifecycle, and one of its first steps is resolving `request.user` — which opens a DB connection. Errors landing on CSRF rather than a downstream view means **most of these requests never reached a queryset** — they couldn't open a connection to start with. That's a pool-sizing/connection-lifecycle problem, not a slow-endpoint problem. + +Possible contributors (none verified): +- `hostCount = 16` × `WEB_CONCURRENCY=4` (per `.envs/.production/.django-example` line 130) = **64 web workers minimum**, plus Celery (`CELERY_WORKER_CONCURRENCY=16`, line 28) on whichever host runs the worker = ~80 processes against PG. +- `psycopg[binary]==3.1.9` + Django default `CONN_MAX_AGE=0` (settings not searched for an override) = every request opens and closes a connection. Under uvicorn ASGI (async workers can handle many concurrent requests), the simultaneous-connection ceiling is much higher than `WEB_CONCURRENCY` alone suggests. +- PG default `max_connections=100` with `superuser_reserved_connections=3` = ~97 usable. Easily exhausted by the above. + +The curve shape (4 → 152 → 284 over 15 minutes, growing) is **not** a single restart blip. Restarts produce a spike-and-drop. Sustained growth implies real load contention. + +### What we still need to verify + +- Confirm `CONN_MAX_AGE` setting in `config/settings/production.py`. If 0 (default), the suspicion is correct. +- Confirm whether pgbouncer fronts Postgres in production (no entry in `docker-compose.yml` here, but production may differ). +- Get PG `max_connections` from the live server (`SHOW max_connections;`). +- Correlate the 22:22 burst with deploy logs — did the NR upgrade restart cause a brief spike in concurrent connections during worker rollout? Or was it coincident with user-triggered load (e.g. a large job submission)? +- Check whether 22:22 was UTC or local — confirm against deploy timestamp. + +### Directions to discuss + +In order of effort/risk: + +1. **`CONN_MAX_AGE=60`** in production settings — Django persistent connections. Single-line change, large effect on per-request connection churn. Risk: if a worker holds a stale connection across a PG restart, the request errors once. Acceptable trade-off. +2. **pgbouncer in transaction-pooling mode** in front of PG — caps the connection ceiling regardless of worker count. Bigger infra change but standard for Django/Celery setups. +3. **Lower `WEB_CONCURRENCY`** until pool is sized — quick bandage if neither above is fast to ship. + +## 4. function_trace coverage — operational note + +Verified that DRF auto-instrumentation in agent 12.1.0 already captures every `*ViewSet.list/.retrieve` we explicitly listed in `config/newrelic.ini` lines 194–202. The explicit entries that **are still pulling their weight**: + +- `ami.main.api.serializers:OccurrenceListSerializer.get_determination_details` (842 calls/hr, captures per-row serializer cost) +- `ami.jobs.tasks:run_job` and `ami.jobs.tasks:process_nats_pipeline_result` (Celery tasks, no auto-instrumentation for these by name) +- `ami.main.models:Occurrence.detection_images / .best_prediction / .best_identification` (model methods called inside serializers; auto-instr doesn't see these) + +The four `*ViewSet.list` / `JobViewSet.result` entries can be removed at the next config audit — they're duplicated by auto-instrumentation. Low priority (no cost penalty for keeping them, just config bloat). + +## 5. Open follow-ups + +- [ ] Audit `SourceImageViewSet.retrieve` for N+1 (571 DB calls in one sample is a clear smell). +- [ ] File / link a ticket on the 22:22 connection-pool incident with the `CONN_MAX_AGE` and pgbouncer questions answered. +- [ ] Re-check the same NRQL queries 24h after deploy to confirm steady-state DB visibility (this writeup is from the first hour after rollout). +- [ ] Trim redundant `function_trace` entries at next config audit. + +## Method (for reproduction) + +All queries run via the `newrelic` skill against `Antenna Backend (live)`. Pattern: +``` +cd ~/Projects/AMI/ami-devops && set -a && . ./.env && set +a && cat > /tmp/q.json << EOF +{"query": "{ actor { account(id: $NEW_RELIC_ACCOUNT_ID) { nrql(query: \"\") { results } } } }"} +EOF +curl -s https://api.newrelic.com/graphql \ + -H "API-Key: $NEW_RELIC_API_KEY" \ + -H "Content-Type: application/json" \ + -d @/tmp/q.json | jq '.data.actor.account.nrql.results' +``` From 8dfc3a0beb9521e4b2c12ec04b20c6580858e5e7 Mon Sep 17 00:00:00 2001 From: Michael Bunsen Date: Wed, 13 May 2026 16:03:18 -0700 Subject: [PATCH 3/5] refactor(api): move SourceImage list-only field groups into viewset class Per review on #1300: pulled `SOURCE_IMAGE_LIST_ONLY_FIELDS` / `SOURCE_IMAGE_PUBLIC_URL_DEPENDENCIES` out of module scope and into `SourceImageViewSet` as class attributes, grouped by what reads them (core, deployment-nested, event-nested, public-url). Trimmed the docstring and added a short note on why we whitelist with `.only()` instead of blacklisting with `.defer()`, with a link to the Django ref. Co-Authored-By: Claude --- ami/main/api/views.py | 132 +++++++++++++++++++----------------------- 1 file changed, 59 insertions(+), 73 deletions(-) diff --git a/ami/main/api/views.py b/ami/main/api/views.py index 5e0a98516..312c9bb46 100644 --- a/ami/main/api/views.py +++ b/ami/main/api/views.py @@ -472,76 +472,6 @@ def list(self, request, *args, **kwargs): return super().list(request, *args, **kwargs) -# Fields read solely by `SourceImage.public_url()` (exposed as the `url` serializer field). -# `public_url()` falls back to building a presigned S3 URL from the deployment's data_source -# credentials when `SourceImage.public_base_url` is blank — that fallback is what forces the -# `data_source__*` chain to be preloaded. -# -# TEMPORARY. This whole group will be removed once we stop serving images directly from -# their source buckets and instead serve them through our image-resizing/CDN layer. At that -# point `url` becomes a static derivation from `id`/`path` and the data_source credentials -# no longer need to fan out into every list response. -# -# Until then, every column here is load-bearing for the list endpoint — dropping any one of -# them triggers a deferred-field SELECT per row during serialization. -SOURCE_IMAGE_PUBLIC_URL_DEPENDENCIES = ( - "path", - "public_base_url", - "deployment__data_source_id", - "deployment__data_source__id", - "deployment__data_source__bucket", - "deployment__data_source__region", - "deployment__data_source__prefix", - "deployment__data_source__access_key", - "deployment__data_source__secret_key", - "deployment__data_source__endpoint_url", - "deployment__data_source__public_base_url", -) - -# Columns preloaded for the SourceImage list response. Must include every column read by -# `SourceImageListSerializer` *and* every column touched by model methods on the serialized -# fields, so DRF serialization never triggers a deferred-field lazy load. -# -# How to keep this in sync when adding a serializer field or a model method: -# 1. Add the DB columns the new field/method reads (use `__` for FK chains). -# 2. Run TestSourceImageListQueryCount — the response-shape test fails loudly if a -# lazy load fires during serialization, and the scaling tests fail if a missing -# column causes per-row queries. -# -# Notes on what is and is NOT here: -# - `detections_count` is a cached DB column on SourceImage and IS preloaded. -# - `occurrences_count` and `taxa_count` are NOT columns on SourceImage — they exist -# only when `with_counts=true` adds them as annotations. Listing them here would -# raise FieldDoesNotExist. -# - The `deployment__data_source__*` chain is grouped into -# `SOURCE_IMAGE_PUBLIC_URL_DEPENDENCIES` above — see that constant for why it exists -# and when it goes away. -SOURCE_IMAGE_LIST_ONLY_FIELDS = ( - # Core fields read by the serializer (id, timestamps, dimensions, cached counts, FKs). - "id", - "timestamp", - "width", - "height", - "size", - "detections_count", - "project_id", - "deployment_id", - # Nested DeploymentNestedSerializer ({id, name, details}) and permission walk. - "deployment__id", - "deployment__name", - "deployment__project_id", - # Nested EventNestedSerializer ({id, name, details, date_label}) — name/date_label - # read `start` and `end`. - "event_id", - "event__id", - "event__start", - "event__end", - "event__deployment_id", - # See constant above. TEMPORARY — drops when image serving moves behind the CDN. - *SOURCE_IMAGE_PUBLIC_URL_DEPENDENCIES, -) - - class SourceImageViewSet(DefaultViewSet, ProjectMixin): """ API endpoint that allows captures from monitoring sessions to be viewed or edited. @@ -553,6 +483,59 @@ class SourceImageViewSet(DefaultViewSet, ProjectMixin): GET /captures/1/ """ + # Columns preloaded by `.only()` for the list response. We whitelist (`only`) instead of + # blacklist (`defer`) because the serializer surface is the stable contract, while + # SourceImage gains wide/heavy columns over time that we don't want pulled into every + # list row. See https://docs.djangoproject.com/en/4.2/ref/models/querysets/#only + # + # When adding a serializer field, add the DB columns it reads to the matching group below + # (use `__` for FK chains) and run TestSourceImageListQueryCount. + + # Core columns read by SourceImageListSerializer (id, dimensions, cached counts, FKs). + _CORE_FIELDS = ( + "id", + "timestamp", + "width", + "height", + "size", + "detections_count", + "project_id", + "deployment_id", + ) + + # Columns read by the nested DeploymentNestedSerializer and the permission walk. + _DEPLOYMENT_FIELDS = ( + "deployment__id", + "deployment__name", + "deployment__project_id", + ) + + # Columns read by the nested EventNestedSerializer ({id, name, details, date_label}). + _EVENT_FIELDS = ( + "event_id", + "event__id", + "event__start", + "event__end", + "event__deployment_id", + ) + + # TEMPORARY — columns `SourceImage.public_url()` reads when `public_base_url` is blank + # and we have to build a presigned S3 URL from the deployment's data_source credentials. + # Goes away once image serving moves behind the image-resizing/CDN layer. + _PUBLIC_URL_FIELDS = ( + "path", + "public_base_url", + "deployment__data_source_id", + "deployment__data_source__id", + "deployment__data_source__bucket", + "deployment__data_source__region", + "deployment__data_source__prefix", + "deployment__data_source__access_key", + "deployment__data_source__secret_key", + "deployment__data_source__endpoint_url", + "deployment__data_source__public_base_url", + ) + require_project_for_list = True # Unfiltered list scans are too expensive on this table queryset = SourceImage.objects.all() @@ -613,9 +596,12 @@ def get_queryset(self) -> QuerySet: ).order_by("timestamp") if self.action == "list": - # Trim row width to the fields SourceImageListSerializer + model methods read. - # See SOURCE_IMAGE_LIST_ONLY_FIELDS comment for maintenance rules. - queryset = queryset.only(*SOURCE_IMAGE_LIST_ONLY_FIELDS) + queryset = queryset.only( + *self._CORE_FIELDS, + *self._DEPLOYMENT_FIELDS, + *self._EVENT_FIELDS, + *self._PUBLIC_URL_FIELDS, + ) # It's cumbersome to override the default list view, so customize the queryset here queryset = self.filter_by_has_detections(queryset) From 04999abe80fad69842b557062219ce9119e28af8 Mon Sep 17 00:00:00 2001 From: Michael Bunsen Date: Wed, 13 May 2026 16:26:32 -0700 Subject: [PATCH 4/5] =?UTF-8?q?refactor(api):=20drop=20.only()=20=E2=80=94?= =?UTF-8?q?=20select=5Frelated=20is=20the=20N+1=20fix?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Per @mihow review on #1300: the `.only()` machinery added in this PR was acting as a row-width trim on top of select_related, not as the N+1 fix. The actual N+1 prevention is `select_related("deployment__data_source")` ensuring `SourceImage.public_url()` doesn't lazy-load the data_source chain per row. With that in place, dropping `.only()` keeps the captures list query count flat (verified empirically — `TestSourceImageListQueryCount` still passes at limit=1, 5, 25). This removes the maintenance burden of keeping the field tuples in sync with the serializer surface. django-zen-queries and the existing perf tests are the safety net for regressions. Renamed `test_list_response_shape_preserved_after_only` to `test_list_response_shape_has_no_lazy_loads` so the contract it asserts is independent of any specific deferred-fields mechanism. Co-Authored-By: Claude --- ami/main/api/views.py | 59 ------------------------------------------- ami/main/tests.py | 7 ++--- 2 files changed, 4 insertions(+), 62 deletions(-) diff --git a/ami/main/api/views.py b/ami/main/api/views.py index 312c9bb46..c4ca76da8 100644 --- a/ami/main/api/views.py +++ b/ami/main/api/views.py @@ -483,59 +483,6 @@ class SourceImageViewSet(DefaultViewSet, ProjectMixin): GET /captures/1/ """ - # Columns preloaded by `.only()` for the list response. We whitelist (`only`) instead of - # blacklist (`defer`) because the serializer surface is the stable contract, while - # SourceImage gains wide/heavy columns over time that we don't want pulled into every - # list row. See https://docs.djangoproject.com/en/4.2/ref/models/querysets/#only - # - # When adding a serializer field, add the DB columns it reads to the matching group below - # (use `__` for FK chains) and run TestSourceImageListQueryCount. - - # Core columns read by SourceImageListSerializer (id, dimensions, cached counts, FKs). - _CORE_FIELDS = ( - "id", - "timestamp", - "width", - "height", - "size", - "detections_count", - "project_id", - "deployment_id", - ) - - # Columns read by the nested DeploymentNestedSerializer and the permission walk. - _DEPLOYMENT_FIELDS = ( - "deployment__id", - "deployment__name", - "deployment__project_id", - ) - - # Columns read by the nested EventNestedSerializer ({id, name, details, date_label}). - _EVENT_FIELDS = ( - "event_id", - "event__id", - "event__start", - "event__end", - "event__deployment_id", - ) - - # TEMPORARY — columns `SourceImage.public_url()` reads when `public_base_url` is blank - # and we have to build a presigned S3 URL from the deployment's data_source credentials. - # Goes away once image serving moves behind the image-resizing/CDN layer. - _PUBLIC_URL_FIELDS = ( - "path", - "public_base_url", - "deployment__data_source_id", - "deployment__data_source__id", - "deployment__data_source__bucket", - "deployment__data_source__region", - "deployment__data_source__prefix", - "deployment__data_source__access_key", - "deployment__data_source__secret_key", - "deployment__data_source__endpoint_url", - "deployment__data_source__public_base_url", - ) - require_project_for_list = True # Unfiltered list scans are too expensive on this table queryset = SourceImage.objects.all() @@ -596,12 +543,6 @@ def get_queryset(self) -> QuerySet: ).order_by("timestamp") if self.action == "list": - queryset = queryset.only( - *self._CORE_FIELDS, - *self._DEPLOYMENT_FIELDS, - *self._EVENT_FIELDS, - *self._PUBLIC_URL_FIELDS, - ) # It's cumbersome to override the default list view, so customize the queryset here queryset = self.filter_by_has_detections(queryset) diff --git a/ami/main/tests.py b/ami/main/tests.py index 091ae7ec3..c31d56faa 100644 --- a/ami/main/tests.py +++ b/ami/main/tests.py @@ -3206,9 +3206,10 @@ def test_list_query_with_counts_and_detections(self): ) self.assertLessEqual(large, small + 5, f"SourceImage list scaling: {small} -> {large} (likely N+1)") - def test_list_response_shape_preserved_after_only(self): - """Guards against `.only()` over-restricting fields: every row must still serialize - `url`, `size_display`, `deployment.name`, and `event.name` without lazy loads.""" + def test_list_response_shape_has_no_lazy_loads(self): + """Every row must serialize `url`, `size_display`, `deployment.name`, and + `event.name` without lazy loads — `select_related("deployment__data_source")` + is the contract that prevents per-row queries from `SourceImage.public_url()`.""" from django.core.cache import caches from django.test.utils import CaptureQueriesContext From 875ded2e1345493c44285c3bb902b99ec8971f88 Mon Sep 17 00:00:00 2001 From: Michael Bunsen Date: Wed, 13 May 2026 18:12:54 -0700 Subject: [PATCH 5/5] docs: drop list-endpoint perf planning docs MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Three planning notes from 3f34b783 were committed under docs/planning/ (wrong convention — should be docs/claude/planning/ per CLAUDE.md) and have since rotted: PR-A was superseded by the denormalize approach in #1301; the .only() recommendation was reverted per review; PR-B1 ships in this PR. Two genuinely useful items have been harvested: - New Relic baseline numbers for 9 list endpoints (post-NR-12.1.0) → memory entry reference_nr_baseline_2026_05_11.md - 22:22 UTC PG connection-pool burst hypothesis → issue #1302 - SourceImageViewSet.retrieve 571-call N+1 audit → issue #1303 Co-Authored-By: Claude --- .../2026-05-11-list-endpoint-perf-analysis.md | 219 ------------------ ...11-list-endpoint-perf-continuation-plan.md | 158 ------------- ...26-05-11-newrelic-post-upgrade-findings.md | 133 ----------- 3 files changed, 510 deletions(-) delete mode 100644 docs/planning/2026-05-11-list-endpoint-perf-analysis.md delete mode 100644 docs/planning/2026-05-11-list-endpoint-perf-continuation-plan.md delete mode 100644 docs/planning/2026-05-11-newrelic-post-upgrade-findings.md diff --git a/docs/planning/2026-05-11-list-endpoint-perf-analysis.md b/docs/planning/2026-05-11-list-endpoint-perf-analysis.md deleted file mode 100644 index fd1d87f9e..000000000 --- a/docs/planning/2026-05-11-list-endpoint-perf-analysis.md +++ /dev/null @@ -1,219 +0,0 @@ -# List endpoint perf analysis — 2026-05-11 - -**Status:** observations + fix hypotheses, no PR yet. -**Source:** New Relic prod data, 30 min window after PR #1299 (NR agent 12.1.0 + tuned `function_trace`) and PR #1274 (Occurrence N+1 fix) shipped. - -## tl;dr - -`OccurrenceViewSet.list` is fixed (p95 dropped from ~35s in a prior incident to **0.93s**, DB share dropped from ~100% to 32%). Three remaining list-endpoint hot paths surfaced: - -1. **`SourceImageCollectionViewSet.list`** — unconditional `COUNT(DISTINCT) FILTER (...)` annotations on a 4-table join. Two queries × ~5s each per page. p95 **10.58s**. Highest leverage. -2. **`SourceImageViewSet.list`** — wide SELECT pulling all `main_deployment` + `main_event` columns into every row; paginator COUNT(*) does the same JOIN. p95 **4.47s**. -3. **`ProjectViewSet.charts`** — full-table aggregates over `main_sourceimage` with `EXTRACT(HOUR|MONTH FROM timestamp)`. p95 **7.58s**. Lower frequency (~2/15 min), separate fix shape. - -None of these are N+1 in the same sense as `OccurrenceViewSet.list` was; they're each a small number of expensive single queries. - -## 1. SourceImageCollectionViewSet.list — annotation explosion - -### Observation - -NR captured the SQL via `record_sql = raw`. Each list request issues two queries: - -**Query A (annotation, 6.14s top, ~1.5s typical):** -```sql -SELECT main_sourceimagecollection.*, - COUNT(DISTINCT main_sourceimagecollection_images.sourceimage_id) AS source_images_count, - COUNT(DISTINCT main_sourceimagecollection_images.sourceimage_id) - FILTER (WHERE main_detection.bbox IS NOT NULL AND main_detection.bbox <> '...') - AS source_images_with_detections_count, - COUNT(DISTINCT main_sourceimagecollection_images.sourceimage_id) - FILTER (WHERE main_detection.id IS NOT NULL) - AS source_images_processed_count -FROM main_sourceimagecollection -LEFT JOIN main_sourceimagecollection_images - ON main_sourceimagecollection.id = main_sourceimagecollection_images.sourceimagecollection_id -LEFT JOIN main_sourceimage - ON main_sourceimagecollection_images.sourceimage_id = main_sourceimage.id -LEFT JOIN main_detection - ON main_sourceimage.id = main_detection.source_image_id -WHERE project_id = %s -GROUP BY main_sourceimagecollection.id -LIMIT ?; -``` - -**Query B (paginator COUNT, 3.97s top, ~0.7s typical):** -```sql -SELECT COUNT(*) FROM ( - SELECT main_sourceimagecollection.id - FROM main_sourceimagecollection - LEFT JOIN main_sourceimagecollection_images ... - LEFT JOIN main_sourceimage ... - LEFT JOIN main_detection ... - WHERE project_id = %s - GROUP BY ? -) subquery; -``` - -Same 4-table join done twice. The 3 `COUNT(DISTINCT) FILTER (...)` aggregates walk every detection in every image in every collection in the project. - -Sum across 9 calls in 30 min: **13.25s** of pure Query-A time. The same window had **6** `main_sourceimage.timestamp/select` calls @ avg 2.16s (those belong to `ProjectViewSet.charts` — see §3) — i.e. the collection-list endpoint, despite low call count, contributes meaningful DB load. - -### Root cause - -In `ami/main/api/views.py:715-719`: - -```python -queryset = ( - SourceImageCollection.objects.all() - .with_source_images_count() - .with_source_images_with_detections_count() - .with_source_images_processed_count() - .prefetch_related("jobs") -) -``` - -The three count annotations are applied **unconditionally on the class-level `queryset`**, before `get_queryset()` runs. List requests pay even when the caller doesn't ask for counts. - -Compare: in the same view (`SourceImageCollectionViewSet.get_queryset`, views.py:737-758), `with_occurrences_count` and `with_taxa_count` are correctly gated by `?with_counts=1`. The three image-counts predate that gating and were missed. - -Annotation definitions live in `ami/main/models.py:4074-4101` (`SourceImageCollectionQuerySet.with_source_images_*`); the property fallbacks at `models.py:4201-4213` return `None` if pre-population missed. - -### Fix candidates (ordered by reversibility) - -**A. Gate the three count annotations behind `with_counts` (smallest change).** - -Move the three `.with_*()` calls out of the class-level `queryset` and into the `if with_counts:` block in `get_queryset()`. Frontend consumers that today rely on the counts being free will need to pass `?with_counts=1`. - -Risk: silently changes API shape for any caller that reads `source_images_count` without `with_counts`. They'd start getting `None`. Audit callers first. - -**B. Replace annotation with denormalized columns on `SourceImageCollection`.** - -Add three integer columns (`source_images_count`, `source_images_with_detections_count`, `source_images_processed_count`) updated by signal on `SourceImageCollection_images.through.{add,remove}` and `Detection.{create,delete}`. Same shape as `Deployment.captures_count` and friends already present on `Deployment` (see `models.py` `Deployment` model fields). - -Risk: signal-based denormalization drifts under bulk ops. Need a periodic reconcile management command. Higher effort but cleanest read-path. - -**C. Replace LEFT JOIN aggregates with correlated `Subquery(...)` annotations.** - -```python -images_subquery = SourceImage.objects.filter( - collections=OuterRef("pk") -).order_by() -annotate( - source_images_count=Subquery(images_subquery.values("collections").annotate(c=Count("id")).values("c")), - ... -) -``` - -PostgreSQL planner can index-scan each subquery against `main_sourceimagecollection_images` independently, avoiding the cartesian blowup of 3 distinct-count aggregates. Easier than B, less invasive than A. - -**D. Fix the paginator JOIN (Query B) regardless of A/B/C.** - -Even if the annotation goes, DRF's paginator currently issues `SELECT COUNT(*) FROM ()`. Override `paginator.get_count` or use `qs.values_list("id").count()` style to bypass the annotated aggregate. This is independent of the annotation question. - -### Recommended path - -A + D for the immediate p95 drop; B as the longer-term cleanup. C is a fallback if A breaks the frontend in audit. - -## 2. SourceImageViewSet.list — wide select + paginator - -### Observation - -Top main_sourceimage SQL last 30 min (NR datastore spans): - -**Query A (list rows, 2.38s top, ~1.1s typical):** -```sql -SELECT - main_sourceimage.<18 cols>, - main_deployment.<25 cols>, - main_event.<13 cols> -FROM main_sourceimage -LEFT JOIN main_deployment ON main_sourceimage.deployment_id = main_deployment.id -LEFT JOIN main_event ON main_sourceimage.event_id = main_event.id -WHERE ... -ORDER BY timestamp; -``` - -**Query B (paginator COUNT, 1.12s):** -```sql -SELECT COUNT(*) -FROM main_sourceimage -INNER JOIN main_deployment ON main_sourceimage.deployment_id = main_deployment.id -WHERE main_deployment.project_id = %s; -``` - -### Root cause - -Three contributing factors, listed in order of suspected impact: - -1. **`select_related("event", "deployment")` is unconditional** (views.py:539). Pulls full row of both tables every time. `SourceImageListSerializer` doesn't read most of those columns. -2. **Paginator JOIN is unnecessary.** `main_sourceimage` has `project_id` directly (`models.py` `SourceImage.project = ForeignKey(Project)`). The paginator joins to `main_deployment` only because the filter uses `deployment__project=...`. Filter could go via `project=...` instead. -3. **`order_by("timestamp")` without `(project_id, timestamp)` composite index.** `timestamp` alone is indexed (`models.py` `SourceImage.timestamp = DateTimeField(db_index=True)`), but a Project-scoped `ORDER BY timestamp` cannot use it efficiently. - -### Fix candidates - -**A. Trim the SELECT:** `queryset.only("id", "path", "timestamp", "deployment_id", "deployment__name", "event_id", "event__start", ...)` matching only the fields the list serializer reads. Halve the row width. - -**B. Override `get_queryset` count path** for list — at minimum filter by `project=project` directly, not `deployment__project=project`. The DRF paginator then drops the JOIN. - -**C. Add composite index** on `main_sourceimage(project_id, timestamp DESC)` via migration. Lets `ORDER BY timestamp` use an index range-scan for a project-filtered list. - -A + B are zero-risk and recover most of the latency. C requires a migration (large table — `CONCURRENTLY` recommended). - -## 3. ProjectViewSet.charts — full-scan aggregates - -### Observation - -Time-correlated to the `charts` action, not `SourceImageViewSet.list`: - -```sql --- 3.31s top -SELECT (timestamp)::date, EXTRACT(HOUR FROM timestamp), COUNT(*) -FROM main_sourceimage -WHERE project_id = %s AND timestamp IS NOT NULL -GROUP BY 1, 2 ORDER BY 1, 2; - --- 2.95s top -SELECT EXTRACT(MONTH FROM timestamp), COUNT(*) -FROM main_sourceimage -WHERE project_id = %s AND timestamp IS NOT NULL -GROUP BY 1 ORDER BY 1; -``` - -Source: `ami/main/charts.py:40,89,117`. The endpoint feeds the project dashboard's capture-heatmap and monthly-distribution charts. - -### Root cause - -Full-table aggregate over `main_sourceimage` filtered only by `project_id`. No index can usefully accelerate `EXTRACT(HOUR FROM timestamp)` because the function is applied per row. - -### Fix candidates - -**A. Cache the chart payload.** Cachalot is already enabled; can pin chart endpoints with a longer TTL (chart values change on capture ingest, not on user interaction). Lowest effort, highest user-facing win. - -**B. Materialized aggregates.** Roll up per-(project, date, hour) into a denormalized table updated nightly. Reads are O(displayed range), not O(all captures). - -**C. Functional index on `(project_id, date_trunc('hour', timestamp))`.** Useful if A and B are both off the table; less effective than B for the monthly aggregate. - -A first — chart freshness on the order of minutes is fine for these views. - -## What still won't surface in NR - -- **Datastore spans aren't tagged with `transaction.name`** in the async-Django + Python agent path (`Span.trace.id` also null on Transaction events). Span→Transaction attribution is by `timestamp` correlation only. Documented blocker; see internal NR proposal. -- **Cachalot internals aren't auto-instrumented.** If chart caching (§3 A) is applied, cache hit/miss rate won't appear in NR. Would need an import-hook. - -## Proposed sequencing - -1. PR for §1.A + §1.D (gate annotations, drop paginator JOIN) — lowest risk, biggest p95 drop on the list page. -2. PR for §2.A + §2.B (trim SELECT, fix count filter) — independent. -3. Decision on §1.B (denormalized columns) before any other annotation-heavy view ships. -4. §3 in a separate ticket; not in the critical path. - -## Verification protocol - -For each PR, after merge to staging or a perf branch: - -1. Run `OccurrenceViewSet.list` regression check first (PR #1274 baseline must not break). NR query: `SELECT percentile(duration, 95) FROM Transaction WHERE name = 'WebTransaction/Function/ami.main.api.views:OccurrenceViewSet.list' SINCE 1 hour ago`. -2. Hit the target endpoint with the same query the failing trace used (project_id known from the slow trace). -3. Compare NR p95 + the per-span `Datastore/statement/...` durations against the values in this doc. -4. Re-run with `?with_counts=1` to verify the gated path still works. - -Numbers in this doc are **post-PR-#1274** prod data, 2026-05-11 ~23:50 UTC, 30-min window. Sample sizes are small for the rarer endpoints (Charts: 2 hits; SourceImageCollection.list: 9 hits) — treat the p95s as directional, not stable. diff --git a/docs/planning/2026-05-11-list-endpoint-perf-continuation-plan.md b/docs/planning/2026-05-11-list-endpoint-perf-continuation-plan.md deleted file mode 100644 index da9b865dd..000000000 --- a/docs/planning/2026-05-11-list-endpoint-perf-continuation-plan.md +++ /dev/null @@ -1,158 +0,0 @@ -# List-endpoint perf — continuation plan - -**Date:** 2026-05-11 -**Status (2026-05-12 update):** -- **PR-A (collection list subquery rewrite)** — superseded. The subquery shape benchmarked mixed on the row SELECT, and the paginator-COUNT win is invisible because the UI does not paginate collections. Replaced by a denormalize-counts-as-columns approach on its own branch (`perf/sourceimagecollection-cached-counts`). -- **PR-B1 (captures list `.only()` + data_source preload)** — in flight as PR #1300, scope renamed to "Speed up the captures list view". -- **PR-B2 / PR-C / PR-D / PR-E** — queued, see sections below. - -**Companions:** -- [`2026-05-11-newrelic-post-upgrade-findings.md`](2026-05-11-newrelic-post-upgrade-findings.md) — prod NR data (DB visibility, top N+1s, conn-pool incident) -- [`2026-05-11-list-endpoint-perf-analysis.md`](2026-05-11-list-endpoint-perf-analysis.md) — root-cause SQL analysis for the same three endpoints (read first; this plan refers to its §1/§2/§3) -- [PR #1274](https://github.com/RolnickLab/antenna/pull/1274) — `OccurrenceViewSet` N+1 fix; merged 2026-05-11 23:46 UTC. Use as the template for solution shape *and* validation methodology - -## What this plan is - -A sequenced action plan for the **three list-endpoint hot paths** the analysis doc identified, plus the **one detail-endpoint hot path** the NR data surfaced post-merge. Numbered in suggested PR order. Each PR is independently mergeable. - -Local-testable. Reuses PR #1274 measurement tooling. - -## State at start of this plan - -**Already in flight (this branch):** -- `SourceImageCollectionQuerySet.with_source_images_count` / `with_source_images_with_detections_count` / `with_source_images_processed_count` rewritten as correlated `Subquery(Count())` annotations (`ami/main/models.py:4074-4117`). Same fix shape as `SourceImageQuerySet.with_occurrences_count` (models.py:1865) and `with_taxa_count` (models.py:1893) — which were already using subqueries and carried `@TODO update the SourceImageCollectionQuerySet to use the same approach` (now removed). -- SQL verified via Django shell: - - Annotated list: 3 independent scalar subqueries on `main_sourceimage` + the M2M through table only. No cartesian blowup. - - Paginator count: collapsed to `SELECT COUNT(*) FROM main_sourceimagecollection WHERE project_id = ?`. No JOIN, no GROUP BY. -- `ami.main.tests -k SourceImageCollection` passes (9/9). - -This is **planning-doc §1 option C + D** delivered as one change. Option A (gate behind `with_counts`) is not pursued because `capture-set-columns.tsx:101` uses `source_images_count` as a sort field — gating would break the list page without coordinated frontend work. - -## Sequenced PRs - -### PR-A — `SourceImageCollectionViewSet.list` subquery rewrite *(in flight)* - -- Status: code written, unit tests pass, SQL verified. Needs query-count regression guard before commit. -- Effort: small. No migration. No API shape change. No frontend change. -- Risk: low — same pattern already in use on `SourceImageQuerySet`. -- Estimated payoff: planning doc measured ~13s of DB time/30min on this endpoint with 9 calls. Subquery rewrite eliminates the cartesian blowup; expected p99 drop from 10.5s → <2s based on the planner's ability to use the FK index per subquery. -- **Test before merge** (mirrors PR #1274 regression guard): - - Add `TestSourceImageCollectionListQueryCount` to `ami/main/tests.py` using `CaptureQueriesContext` + `@override_settings(CACHALOT_ENABLED=False)`. Run `/captures-set/?project=X&limit=25`; assert query count ≤ small constant regardless of page size. Three variants: cold list, list with `?with_counts=1`, list with sort by `source_images_count`. - - Local end-to-end: `docker compose run --rm django python manage.py test ami.main.tests -k Collection --keepdb` (already passing). - - Local SQL inspection: `EXPLAIN ANALYZE` against demo DB for both shapes; confirm planner uses `main_sourceimagecollection_images_sourceimagecollection_id_idx` for each subquery. - -### PR-B — `SourceImageViewSet.list` SELECT trim + paginator JOIN fix - -References: `ami/main/api/views.py:475-583`. Planning doc §2. - -- Two sub-changes, both small and zero-risk: - 1. **B1: Trim the SELECT** (§2.A). Replace the unconditional `select_related("event", "deployment")` with `.only("id", "path", "timestamp", "deployment_id", "deployment__name", "event_id", "event__start", …)`. Match exactly what `SourceImageListSerializer` reads. Halves row width. - 2. **B2: Drop the paginator JOIN** (§2.B). The endpoint currently scopes by `deployment__project` which forces the paginator's `COUNT(*)` to join `main_deployment`. `main_sourceimage` has a direct `project_id` FK — switching the project filter to `project=project` (or adding `.filter(project=project)` before the deployment-scoped filters in `get_queryset`) lets the paginator skip the JOIN. -- Effort: small. No migration. -- Risk: low. `.only()` is reversible; needs an audit of `SourceImageListSerializer` field access (model methods that touch un-loaded columns will trigger lazy loads → re-introducing N+1 silently). -- Skipped from §2: **C — composite index `(project_id, timestamp DESC)`** on `main_sourceimage`. Real win at scale but requires a `CONCURRENTLY` migration on a large table. Park for a follow-up PR with measured before/after; not urgent if B1+B2 land first. -- **Test before merge**: - - Add `TestSourceImageListQueryCount` already exists from PR #1274 — extend it with `select_related` and `paginator-count` assertions. The existing test passes at 4 queries for `with_detections=true&with_counts=true`; should not regress. - - Cold-row width check via Django shell: `print(SourceImage.objects.filter(project_id=X).only(...)[0].__dict__)` — verify only-fields are loaded, no `_deferred_fields` cascade in serializer access. - -### PR-C — `SourceImageViewSet.retrieve` audit *(NEW from NR data)* - -References: `ami/main/api/views.py:548-574`. **Not covered in the planning doc.** - -- NR observed **571 DB calls / 1.5s** on a single `/captures//` request (newrelic-post-upgrade-findings §2). Likely culprits: - 1. **`prefetch_detections(queryset, project)` on retrieve** (views.py:561) — runs the same `filtered_detections` Prefetch the list uses, but on a detail object. The nested Prefetch attaches `occurrence` + `occurrence__determination` to every detection. With ~100s of detections per high-traffic image, the inner `Max("occurrence__detections__classifications__score")` subquery can fire per row. - 2. **`add_adjacent_captures()`** (views.py:637-688) — wires four subqueries (next, previous, index, total) into the queryset. Cheap per subquery but adds 4 to the floor count. - 3. **`with_occurrences_count()` + `with_taxa_count()`** annotations (views.py:567-572) applied on `with_counts_default=True` for retrieve. -- Effort: medium. Likely needs an audit pass like PR #1274's: ([what does the serializer actually read?]→[which prefetches/annotations are required?]→[remove the rest]). -- Approach: mirror PR #1274 exactly: - - Create `ami/main/models_future/source_image.py` with `prefetch_detections_for_detail()` (only nested relations the detail serializer reads). - - Add `SourceImageQuerySet.with_detail_prefetches()`. - - Wire `get_queryset` to call it for the retrieve action; remove the bespoke `prefetch_detections` reuse-on-retrieve. - - Add `_require_prefetch()` strict gate on any model methods the detail serializer calls that depend on prefetched detections. -- **Test before merge**: - - Add `TestSourceImageRetrieveQueryCount` — single-row fetch should be a small constant of queries (target ≤10) regardless of detection count. - - Synthetic test with 1 / 50 / 500 detections per image; assert query count does **not** scale with detection count. - -### PR-D — `SourceImageCollectionViewSet.populate` / `add` and other endpoint shape - -Out of scope for this plan. Mentioning to flag: those write paths (views.py:767, 813) call `collection.images.count()` and `collection.images.add(...)` synchronously. If we move to denormalized count columns (planning doc §1.B as a longer-term direction), those write paths become the natural maintenance points. Not blocking PR-A. - -### PR-E — `ProjectViewSet.charts` (out of critical path) - -Planning doc §3. NR shows 7.6s tail with 36 queries — aggregate-bound, not N+1. Three fix candidates in the planning doc. **A (cachalot pinning)** is the right first step: chart freshness on the order of minutes is acceptable, and the existing cachalot infrastructure already covers it. Separate ticket. - -## Comparison vs PR #1274 approach - -| Concern | PR #1274 (Occurrence list) | PR-A (Collection list) | PR-B (SourceImage list) | PR-C (SourceImage retrieve) | -|---|---|---|---|---| -| **Problem shape** | True N+1 (1.6 extra queries/row) | Annotation-aggregate cartesian (1 big query × 4 tables) | Wide-row + paginator JOIN | Suspected N+1 on detail | -| **Solution shape** | Strict prefetch factories + `_require_prefetch` gate | Correlated `Subquery(Count())` | `.only()` + filter rewrite | Likely same as #1274 (prefetch factory + strict gate) | -| **New module needed?** | Yes (`models_future/occurrence.py`) | No | No | Yes (`models_future/source_image.py`) | -| **API shape change?** | List `detection_images` capped at 1 (was unbounded) | None | None | TBD | -| **Migration?** | None | None | None (C in §2 adds one, deferred) | None | -| **Tests** | `TestOccurrenceListQueryCount`, `TestOccurrenceDetailQueryCount`, `TestOccurrencePrefetchHelpersEdgeCases` | `TestSourceImageCollectionListQueryCount` (new) | Extend existing `TestSourceImageListQueryCount` | `TestSourceImageRetrieveQueryCount` (new) | -| **Local benchmark** | `scripts/benchmark_occurrences_list.sh` | Reuse with `--endpoint=/captures-set/` parametrization | Same; already has it | Same with `--endpoint=/captures//` | - -**Key takeaway**: only PR-C (and possibly a §1.B follow-up) needs PR #1274's `_require_prefetch` strict-contract machinery. PR-A and PR-B are smaller SQL-shape changes that don't need a new helper module — the QuerySet rewrite is the whole fix. - -## Local validation methodology - -For every PR in this plan: - -1. **Cold query count regression test.** Pattern (mirrors `ami/main/tests.py::TestOccurrenceListQueryCount`): - ```python - from django.test.utils import CaptureQueriesContext - from django.db import connection - from django.test import override_settings - - @override_settings(CACHALOT_ENABLED=False) - def test__list_query_count(self): - # warmup (load app, perm cache) - self.client.get(f"{URL}?limit=5") - self.client.get(f"{URL}?limit=5") - with CaptureQueriesContext(connection) as ctx: - response = self.client.get(f"{URL}?limit=25") - self.assertLess(len(ctx.captured_queries), N) - ``` - `@override_settings(CACHALOT_ENABLED=False)` is critical — cachalot otherwise hides the N+1 on warm DB. - -2. **SQL shape inspection.** Django shell: - ```python - qs = .objects.(...) - print(str(qs.query)) # annotated list SQL - from django.db import connection - qs.count() - print(connection.queries[-1]['sql']) # paginator count SQL - ``` - -3. **Local stack DB benchmark.** Against the demo project (`create_demo_project`): - ```bash - docker compose exec django python manage.py shell -c " - from django.test.utils import CaptureQueriesContext - from django.db import connection - from django.test.client import Client - c = Client() - c.force_login() - with CaptureQueriesContext(connection) as ctx: - r = c.get('/api/v2/captures-set/?project=1&limit=25') - print(f'{len(ctx.captured_queries)} queries, {r.status_code}') - " - ``` - -4. **EXPLAIN ANALYZE on a real-data DB copy** (where available — staging arbutus-2026 has the production schema and realistic row counts). Confirms the planner picks the FK index per subquery on PR-A and confirms the paginator drops the JOIN on PR-B. - -5. **A/B concurrent load** (only for PRs likely to affect saturation behavior — PR-A and PR-B). Reuse PR #1274's `scripts/benchmark_occurrences_list.sh` with `--endpoint` switched. The pattern: 10/40 concurrent × limit=25/100, p50/p95/p99/max + per-status error counts. Run against `arctia.dev` or equivalent staging. - -## Open follow-ups (won't block this plan) - -- **Tracked separately**: `SourceImageViewSet.retrieve` — file ticket and reference NR data + this plan's PR-C row. -- **Tracked separately**: `ProjectViewSet.charts` cachalot pinning — planning doc §3. -- **Maybe revisit**: composite index `main_sourceimage(project_id, timestamp DESC)` after PR-B is in prod for a week. If `SourceImageViewSet.list` p95 is still above target (~1s), the index is the next lever. -- **From PR #1274's deferred list**: expose `?detection_images_limit=N` query param on `OccurrenceViewSet` — relevant once tracking-merged occurrences are common. Cross-reference: that PR caps at 1 (list) / 100 (detail) which works today. - -## Why this plan, not a single mega-PR - -- PR-A is **already coded**; merging it alone is a clean small win. -- PR-B is **independent of PR-A** (different endpoint, different DB tables). Bundling adds review surface for no shipping speedup. -- PR-C **needs new infrastructure** (`models_future/source_image.py`) and an audit pass; lumping it with PR-A/B would push the easy wins behind the hard one. -- PR #1274's audit-then-fix sequencing is the proven pattern. Apply it three times rather than once, each scoped to a single endpoint family. diff --git a/docs/planning/2026-05-11-newrelic-post-upgrade-findings.md b/docs/planning/2026-05-11-newrelic-post-upgrade-findings.md deleted file mode 100644 index 8c382c655..000000000 --- a/docs/planning/2026-05-11-newrelic-post-upgrade-findings.md +++ /dev/null @@ -1,133 +0,0 @@ -# New Relic post-upgrade findings — 2026-05-11 - -**Status:** observations after PR #1299 (NR agent 9.6.0 → 12.1.0 + tuned config) shipped. Hypothesis-framed; no fixes proposed below the connection-pool incident. -**Companion doc:** [`2026-05-11-list-endpoint-perf-analysis.md`](2026-05-11-list-endpoint-perf-analysis.md) — covers the SourceImageCollection/SourceImage/Project.charts list-side detail this doc only summarizes. -**Data window:** ~1h after deploy; throughput 181 rpm, errorRate 0%, avg resp 65ms, 16 hosts reporting. - -## tl;dr - -1. **DB visibility restored.** `databaseCallCount` populated on 57% of transactions vs 2.8% one day earlier. ~20× lift, no other agent variables changed. Confirms the psycopg3 instrumentation gap was the cause, not ASGI context. -2. **Surfaced N+1 on `SourceImageViewSet.retrieve`** — 571 DB calls per single-image fetch, 1.5s p99. Hidden pre-upgrade; not on PR #1274's radar. -3. **Surfaced PG connection-slot exhaustion burst** around the deploy window (22:22–22:32 UTC). 440 `OperationalError` events, ~99% at `CsrfViewMiddleware.process_view` (request entry, before any view). Pattern suggests a pool-sizing or `CONN_MAX_AGE` issue rather than a slow-endpoint cause. -4. **`function_trace` config is mostly redundant** — DRF auto-instrumentation already captures every `*ViewSet.list/.retrieve`. Only the Pydantic-heavy serializer method and the two Celery task entries are still earning their slot. - -## 1. DB visibility — before/after - -NRQL: -``` -SELECT filter(count(*), WHERE databaseCallCount IS NOT NULL) as with_db, - count(*) as txns -FROM Transaction -WHERE appName = '' -SINCE 1 hour ago COMPARE WITH 1 day ago -``` - -| Window | Txns | With DB call count | -|---|---|---| -| Current (agent 12.1.0) | 9863 | **5669 (57.4%)** | -| 1 day ago (agent 9.6.0) | 8815 | 245 (2.8%) | - -Postgres span breakdown is now usable: `main_occurrence/select` 191ms avg with a 568ms tail; `main_taxon/select` 21ms avg but a 704ms outlier; `ml_processingservice/update` 125 spans (periodic health check chatter, max 115ms); Redis `mget` 17780 calls @ 0.7ms avg (cachalot working as expected). None of this was queryable before the upgrade. - -## 2. Top N+1 / slow-tail endpoints - -Transactions filtered to `duration > 0.5s`, faceted by name, 1h window: - -| Endpoint | n | avg | p99 | DB calls/req | DB ms | -|---|---|---|---|---|---| -| **`SourceImageViewSet.retrieve`** | 1 | 1469ms | 1469ms | **571** | 866ms | -| `OccurrenceViewSet.list` | 80 | 624ms | 1310ms | 194 | 177ms | -| `ProjectViewSet.list` | 9 | 578ms | 644ms | 242 | 305ms | -| `SourceImageViewSet.list` | 4 | 3489ms | 4974ms | 167 | 3335ms | -| `EventViewSet.list` | 1 | 4142ms | 4142ms | 118 | 3986ms | -| `SourceImageCollectionViewSet.list` | 4 | 3693ms | 10583ms | 117 | 3484ms | -| `SummaryView.get` | 4 | 965ms | 1542ms | 26 | 892ms | -| `TaxonViewSet.list` | 2 | 1441ms | 1505ms | 20 | 1363ms | -| `ProjectViewSet.charts` | 1 | 7585ms | 7585ms | 36 | 7457ms | - -### Worth calling out - -- **`SourceImageViewSet.retrieve` @ 571 DB calls** — only one sample in this window, but the call count is so far above the rest that it's almost certainly an N+1 (and not just slow individual queries). Companion doc covers the list endpoint; the **detail endpoint hasn't been audited**. Likely candidates: `detections` prefetch missing on the detail serializer, or `Occurrence.detection_images / .best_prediction / .best_identification` firing per detection inside the response. -- **`SourceImageCollectionViewSet.list` and `SourceImageViewSet.list`** are dominated by **DB time** (>95% of total). High DB-call counts but bigger fix is the SQL itself, not the count — see companion doc for the `COUNT(DISTINCT) FILTER (...)` annotation-explosion analysis. -- **`ProjectViewSet.charts` @ 7.6s with only 36 queries** — not an N+1. Aggregate-heavy SQL. Different fix shape (materialized view, or limit time range default). -- **PR #1274 target is real but not the worst offender.** OccurrenceViewSet.list at 194 calls / 1.3s p99 is in the upper tier, but Detail+Collection list outrank it on both call-count and tail. - -## 3. PG connection-pool incident — 22:22–22:32 UTC - -### Observation - -`TransactionError` table, `error.class = django.db.utils:OperationalError`, last 24h: - -``` -22:22 UTC — 4 errors -22:27 UTC — 152 errors -22:32 UTC — 284 errors -all other hours — 0 -``` - -Error messages: -- 402× `connection failed: FATAL: remaining connection slots are reserved for non-replication superuser connections` -- 22× `connection failed: FATAL: sorry, too many clients already` -- 15× combination of both - -Faceted by `transactionName`: -- **435/440 at `WebTransaction/Function/django.middleware.csrf:CsrfViewMiddleware.process_view`** -- 4 at `OtherTransaction/Celery/ami.jobs.tasks.update_async_services_seen_for_pipelines` -- 1 at `WebTransaction/Function/ami.main.api.views:SourceImageViewSet.list` - -### Interpretation (hedged) - -The CSRF middleware runs early in the Django request lifecycle, and one of its first steps is resolving `request.user` — which opens a DB connection. Errors landing on CSRF rather than a downstream view means **most of these requests never reached a queryset** — they couldn't open a connection to start with. That's a pool-sizing/connection-lifecycle problem, not a slow-endpoint problem. - -Possible contributors (none verified): -- `hostCount = 16` × `WEB_CONCURRENCY=4` (per `.envs/.production/.django-example` line 130) = **64 web workers minimum**, plus Celery (`CELERY_WORKER_CONCURRENCY=16`, line 28) on whichever host runs the worker = ~80 processes against PG. -- `psycopg[binary]==3.1.9` + Django default `CONN_MAX_AGE=0` (settings not searched for an override) = every request opens and closes a connection. Under uvicorn ASGI (async workers can handle many concurrent requests), the simultaneous-connection ceiling is much higher than `WEB_CONCURRENCY` alone suggests. -- PG default `max_connections=100` with `superuser_reserved_connections=3` = ~97 usable. Easily exhausted by the above. - -The curve shape (4 → 152 → 284 over 15 minutes, growing) is **not** a single restart blip. Restarts produce a spike-and-drop. Sustained growth implies real load contention. - -### What we still need to verify - -- Confirm `CONN_MAX_AGE` setting in `config/settings/production.py`. If 0 (default), the suspicion is correct. -- Confirm whether pgbouncer fronts Postgres in production (no entry in `docker-compose.yml` here, but production may differ). -- Get PG `max_connections` from the live server (`SHOW max_connections;`). -- Correlate the 22:22 burst with deploy logs — did the NR upgrade restart cause a brief spike in concurrent connections during worker rollout? Or was it coincident with user-triggered load (e.g. a large job submission)? -- Check whether 22:22 was UTC or local — confirm against deploy timestamp. - -### Directions to discuss - -In order of effort/risk: - -1. **`CONN_MAX_AGE=60`** in production settings — Django persistent connections. Single-line change, large effect on per-request connection churn. Risk: if a worker holds a stale connection across a PG restart, the request errors once. Acceptable trade-off. -2. **pgbouncer in transaction-pooling mode** in front of PG — caps the connection ceiling regardless of worker count. Bigger infra change but standard for Django/Celery setups. -3. **Lower `WEB_CONCURRENCY`** until pool is sized — quick bandage if neither above is fast to ship. - -## 4. function_trace coverage — operational note - -Verified that DRF auto-instrumentation in agent 12.1.0 already captures every `*ViewSet.list/.retrieve` we explicitly listed in `config/newrelic.ini` lines 194–202. The explicit entries that **are still pulling their weight**: - -- `ami.main.api.serializers:OccurrenceListSerializer.get_determination_details` (842 calls/hr, captures per-row serializer cost) -- `ami.jobs.tasks:run_job` and `ami.jobs.tasks:process_nats_pipeline_result` (Celery tasks, no auto-instrumentation for these by name) -- `ami.main.models:Occurrence.detection_images / .best_prediction / .best_identification` (model methods called inside serializers; auto-instr doesn't see these) - -The four `*ViewSet.list` / `JobViewSet.result` entries can be removed at the next config audit — they're duplicated by auto-instrumentation. Low priority (no cost penalty for keeping them, just config bloat). - -## 5. Open follow-ups - -- [ ] Audit `SourceImageViewSet.retrieve` for N+1 (571 DB calls in one sample is a clear smell). -- [ ] File / link a ticket on the 22:22 connection-pool incident with the `CONN_MAX_AGE` and pgbouncer questions answered. -- [ ] Re-check the same NRQL queries 24h after deploy to confirm steady-state DB visibility (this writeup is from the first hour after rollout). -- [ ] Trim redundant `function_trace` entries at next config audit. - -## Method (for reproduction) - -All queries run via the `newrelic` skill against `Antenna Backend (live)`. Pattern: -``` -cd ~/Projects/AMI/ami-devops && set -a && . ./.env && set +a && cat > /tmp/q.json << EOF -{"query": "{ actor { account(id: $NEW_RELIC_ACCOUNT_ID) { nrql(query: \"\") { results } } } }"} -EOF -curl -s https://api.newrelic.com/graphql \ - -H "API-Key: $NEW_RELIC_API_KEY" \ - -H "Content-Type: application/json" \ - -d @/tmp/q.json | jq '.data.actor.account.nrql.results' -```