chore(profiling): confirm Stage 2 loop-resolution reduces query count and wall time at scale

Guardian permission subplans now actually execute (previously
'never executed' due to unowned seed documents short-circuiting the
owner_id IS NULL branch). best_seconds rose from 0.0251s to 31.4648s,
confirming the varchar-cast nested-loop-semi-join pathology is real
and now measured under realistic conditions.

profiling/harness.py

@@ -0,0 +1,123 @@
+# profiling/harness.py
+from __future__ import annotations
+
+import json
+import subprocess
+import time
+from dataclasses import dataclass
+from datetime import UTC
+from datetime import datetime
+from pathlib import Path
+from typing import TYPE_CHECKING
+from typing import Any
+from typing import Generic
+from typing import TypeVar
+
+import pytest
+from django.db import connection
+from django.test.utils import CaptureQueriesContext
+
+if TYPE_CHECKING:
+    from collections.abc import Callable
+
+    from django.db.models import QuerySet
+
+    from profiling.seed import ScaleProfile
+
+T = TypeVar("T")
+
+
+def require_postgres() -> None:
+    if connection.vendor != "postgresql":
+        pytest.skip(
+            "Profiling requires PostgreSQL to reflect production query "
+            "planning; SQLite does not reproduce the varchar-cast planner "
+            "pathology this work fixes.",
+        )
+
+
+@dataclass(frozen=True, slots=True)
+class ProfileResult(Generic[T]):
+    best_seconds: float
+    all_seconds: tuple[float, ...]
+    query_count: int
+    result: T
+
+
+def run_profile(fn: Callable[[], T], *, repeat: int = 5) -> ProfileResult[T]:
+    require_postgres()
+    all_seconds: list[float] = []
+    result: T | None = None
+    query_count = 0
+    for i in range(repeat):
+        with CaptureQueriesContext(connection) as ctx:
+            start = time.perf_counter()
+            result = fn()
+            all_seconds.append(time.perf_counter() - start)
+        if i == repeat - 1:
+            query_count = len(ctx.captured_queries)
+    assert result is not None  # repeat >= 1 guarantees at least one assignment
+    return ProfileResult(
+        best_seconds=min(all_seconds),
+        all_seconds=tuple(all_seconds),
+        query_count=query_count,
+        result=result,
+    )
+
+
+def capture_explain_analyze(queryset: QuerySet[Any]) -> str:
+    if connection.vendor != "postgresql":
+        raise RuntimeError("EXPLAIN ANALYZE capture is Postgres-only")
+    sql, params = queryset.query.sql_with_params()
+    with connection.cursor() as cur:
+        cur.execute(f"EXPLAIN ANALYZE {sql}", params)
+        return "\n".join(row[0] for row in cur.fetchall())
+
+
+def _current_git_ref() -> str:
+    result = subprocess.run(
+        ["git", "rev-parse", "--short", "HEAD"],
+        capture_output=True,
+        text=True,
+        check=False,
+    )
+    return result.stdout.strip() or "unknown"
+
+
+def append_profiling_history(
+    *,
+    stage: str,
+    scenario: str,
+    best_seconds: float,
+    query_count: int,
+    scale: ScaleProfile,
+    code_ref: str | None = None,
+) -> None:
+    """
+    Append one line to profiling/results/history.jsonl -- an append-only,
+    cross-session record of every profiling run. Unlike the per-stage
+    before/after snapshot JSON files (which the next run of the same stage
+    overwrites), this never gets clobbered, so a profiling effort picked
+    back up days later has a full timeline to resume from instead of only
+    the single most recent comparison.
+
+    ``code_ref`` should identify the *production* code under test (a short
+    SHA on the feature branch, not this `profiling` branch) -- pass it
+    explicitly when known. Left as ``None``, it falls back to this repo's
+    current ``git rev-parse --short HEAD``, which is only meaningful if
+    you're actually running from a checkout where that reflects the code
+    being measured.
+    """
+    results_dir = Path(__file__).parent / "results"
+    results_dir.mkdir(exist_ok=True)
+    entry = {
+        "timestamp": datetime.now(UTC).isoformat(),
+        "code_ref": code_ref or _current_git_ref(),
+        "stage": stage,
+        "scenario": scenario,
+        "scale": scale,
+        "best_seconds": best_seconds,
+        "query_count": query_count,
+    }
+    with (results_dir / "history.jsonl").open("a") as f:
+        f.write(json.dumps(entry) + "\n")

profiling/pyproject.toml

@@ -0,0 +1,18 @@
+[tool.pytest]
+ini_options.pythonpath = [ "../src", "..", "." ]
+ini_options.markers = [
+  """\
+  profiling: Profiling scripts comparing old vs new query patterns; require a throwaway PostgreSQL container, not run \
+  as part of the normal test suite\
+  """,
+]
+ini_options.DJANGO_SETTINGS_MODULE = "paperless.settings"
+
+[tool.pytest_env]
+# Standalone config: this directory must be independently runnable without
+# the rest of the dev stack (Redis, etc) present -- only Postgres is required,
+# via run_with_postgres.sh.
+PAPERLESS_SECRET_KEY = "profiling-only-insecure-key"
+PAPERLESS_DISABLE_DBHANDLER = "true"
+PAPERLESS_CACHE_BACKEND = "django.core.cache.backends.locmem.LocMemCache"
+PAPERLESS_CHANNELS_BACKEND = "channels.layers.InMemoryChannelLayer"

profiling/results/history.jsonl

@@ -0,0 +1,8 @@
+{"timestamp": "2026-07-27T22:47:46.677504+00:00", "code_ref": "test-run", "stage": "self-check", "scenario": "test_append_profiling_history_writes_a_valid_json_line", "scale": "medium", "best_seconds": 0.001, "query_count": 0}
+{"timestamp": "2026-07-27T22:49:03.762638+00:00", "code_ref": "test-run", "stage": "self-check", "scenario": "test_append_profiling_history_writes_a_valid_json_line", "scale": "medium", "best_seconds": 0.001, "query_count": 0}
+{"timestamp": "2026-07-27T23:01:49.777269+00:00", "code_ref": "0506dcad0", "stage": "stage1", "scenario": "get_objects_for_user_owner_aware_document_baseline", "scale": "medium", "best_seconds": 0.025123266968876123, "query_count": 1}
+{"timestamp": "2026-07-28T01:38:32.706519+00:00", "code_ref": "e80ede4cb", "stage": "stage1", "scenario": "get_objects_for_user_owner_aware_document_baseline", "scale": "medium", "best_seconds": 31.46481539506931, "query_count": 1}
+{"timestamp": "2026-07-28T03:53:46.770669+00:00", "code_ref": "d4fa85237", "stage": "stage1", "scenario": "get_objects_for_user_owner_aware_document_baseline", "scale": "medium", "best_seconds": 31.671881378046237, "query_count": 1}
+{"timestamp": "2026-07-28T04:02:41.942168+00:00", "code_ref": "d4fa85237", "stage": "stage1", "scenario": "permitted_document_ids_after_stage1", "scale": "medium", "best_seconds": 0.07956207206007093, "query_count": 1}
+{"timestamp": "2026-07-28T23:30:28.602501+00:00", "code_ref": "86846255f", "stage": "stage2", "scenario": "per_row_checker_vs_resolved_set_old", "scale": "medium", "best_seconds": 3.4628250940004364, "query_count": 692}
+{"timestamp": "2026-07-28T23:30:28.606987+00:00", "code_ref": "86846255f", "stage": "stage2", "scenario": "per_row_checker_vs_resolved_set_new", "scale": "medium", "best_seconds": 0.10436739504802972, "query_count": 1}

profiling/results/stage1_after.json

@@ -0,0 +1,9 @@
+{
+  "permitted_document_ids": {
+    "best_seconds": 0.07956207206007093,
+    "query_count": 1
+  },
+  "baseline_best_seconds": 31.671881378046237,
+  "baseline_query_count": 1,
+  "speedup_x": 398.07763370131113
+}

profiling/results/stage1_after_explain.txt

@@ -0,0 +1,58 @@
+Index Scan Backward using documents_document_created_bedd0818 on documents_document v0  (cost=91.31..99.33 rows=1 width=2900) (actual time=68.340..77.517 rows=12024.00 loops=1)
+  Filter: ((deleted_at IS NULL) AND ((owner_id = 12) OR (owner_id IS NULL) OR (ANY (id = (hashed SubPlan 1).col1))))
+  Rows Removed by Filter: 7976
+  Index Searches: 1
+  Buffers: shared hit=74978
+  SubPlan 1
+    ->  Unique  (cost=91.04..91.05 rows=2 width=4) (actual time=64.698..66.622 rows=9136.00 loops=1)
+          Buffers: shared hit=73487
+          ->  Sort  (cost=91.04..91.05 rows=2 width=4) (actual time=64.697..65.202 rows=9262.00 loops=1)
+                Sort Key: ((u0.object_pk)::integer)
+                Sort Method: quicksort  Memory: 385kB
+                Buffers: shared hit=73487
+                ->  Append  (cost=0.27..91.03 rows=2 width=4) (actual time=0.026..63.201 rows=9262.00 loops=1)
+                      Buffers: shared hit=73487
+                      ->  Nested Loop  (cost=0.27..12.79 rows=1 width=4) (actual time=0.026..1.834 rows=237.00 loops=1)
+                            Join Filter: (u0.permission_id = u1.id)
+                            Buffers: shared hit=696
+                            ->  Index Only Scan using guardian_userobjectpermi_user_id_permission_id_ob_b0b3d2fc_uniq on guardian_userobjectpermission u0  (cost=0.27..8.29 rows=1 width=520) (actual time=0.012..0.131 rows=237.00 loops=1)
+                                  Index Cond: (user_id = 12)
+                                  Heap Fetches: 237
+                                  Index Searches: 1
+                                  Buffers: shared hit=222
+                            ->  Seq Scan on auth_permission u1  (cost=0.00..4.49 rows=1 width=4) (actual time=0.006..0.006 rows=1.00 loops=237)
+                                  Filter: (((codename)::text = 'view_document'::text) AND (content_type_id = 17))
+                                  Rows Removed by Filter: 67
+                                  Buffers: shared hit=474
+                      ->  Nested Loop  (cost=4.73..78.23 rows=1 width=4) (actual time=1.119..60.528 rows=9025.00 loops=1)
+                            Buffers: shared hit=72791
+                            ->  Nested Loop  (cost=4.59..78.05 rows=1 width=524) (actual time=1.115..50.521 rows=9025.00 loops=1)
+                                  Buffers: shared hit=54741
+                                  ->  Nested Loop  (cost=4.44..73.62 rows=24 width=520) (actual time=1.109..13.226 rows=45387.00 loops=1)
+                                        Buffers: shared hit=329
+                                        ->  Seq Scan on auth_permission u4  (cost=0.00..4.49 rows=1 width=4) (actual time=0.008..0.017 rows=1.00 loops=1)
+                                              Filter: (((codename)::text = 'view_document'::text) AND (content_type_id = 17))
+                                              Rows Removed by Filter: 165
+                                              Buffers: shared hit=2
+                                        ->  Bitmap Heap Scan on guardian_groupobjectpermission u0_1  (cost=4.44..68.93 rows=20 width=524) (actual time=1.100..8.095 rows=45387.00 loops=1)
+                                              Recheck Cond: (permission_id = u4.id)
+                                              Heap Blocks: exact=290
+                                              Buffers: shared hit=327
+                                              ->  Bitmap Index Scan on guardian_groupobjectpermission_permission_id_36572738  (cost=0.00..4.43 rows=20 width=0) (actual time=1.052..1.053 rows=45387.00 loops=1)
+                                                    Index Cond: (permission_id = u4.id)
+                                                    Index Searches: 1
+                                                    Buffers: shared hit=37
+                                  ->  Index Only Scan using auth_user_groups_user_id_group_id_94350c0c_uniq on auth_user_groups u2  (cost=0.15..0.18 rows=1 width=4) (actual time=0.001..0.001 rows=0.20 loops=45387)
+                                        Index Cond: ((user_id = 12) AND (group_id = u0_1.group_id))
+                                        Heap Fetches: 9025
+                                        Index Searches: 45387
+                                        Buffers: shared hit=54412
+                            ->  Index Only Scan using auth_group_pkey on auth_group u1_1  (cost=0.14..0.17 rows=1 width=4) (actual time=0.001..0.001 rows=1.00 loops=9025)
+                                  Index Cond: (id = u0_1.group_id)
+                                  Heap Fetches: 9025
+                                  Index Searches: 9025
+                                  Buffers: shared hit=18050
+Planning:
+  Buffers: shared hit=2
+Planning Time: 1.089 ms
+Execution Time: 78.020 ms

profiling/results/stage1_baseline.json

@@ -0,0 +1,6 @@
+{
+  "get_objects_for_user_owner_aware_document": {
+    "best_seconds": 31.671881378046237,
+    "query_count": 1
+  }
+}

profiling/results/stage1_baseline_explain.txt

@@ -0,0 +1,68 @@
+Sort  (cost=3790.80..3790.82 rows=9 width=2900) (actual time=39120.166..39120.831 rows=12024.00 loops=1)
+  Sort Key: documents_document.created DESC
+  Sort Method: quicksort  Memory: 3230kB
+  Buffers: shared hit=8598270
+  ->  Seq Scan on documents_document  (cost=2550.72..3790.65 rows=9 width=2900) (actual time=0.009..39114.720 rows=12024.00 loops=1)
+        Filter: ((deleted_at IS NULL) AND ((owner_id = 2) OR (owner_id IS NULL) OR (ANY (id = (hashed SubPlan 1).col1)) OR (ANY (id = (hashed SubPlan 2).col1))))
+        Rows Removed by Filter: 7976
+        Buffers: shared hit=8598270
+        SubPlan 1
+          ->  Nested Loop Semi Join  (cost=0.00..1245.63 rows=1 width=8) (actual time=4.254..969.033 rows=237.00 loops=1)
+                Join Filter: ((((v0.object_pk)::bigint)::character varying)::text = (((u0.id)::bigint)::character varying)::text)
+                Rows Removed by Join Filter: 2539276
+                Buffers: shared hit=214835
+                ->  Nested Loop  (cost=0.00..23.30 rows=1 width=516) (actual time=0.031..2.425 rows=237.00 loops=1)
+                      Join Filter: (v0.permission_id = v2.id)
+                      Buffers: shared hit=490
+                      ->  Seq Scan on guardian_userobjectpermission v0  (cost=0.00..18.80 rows=1 width=520) (actual time=0.021..0.424 rows=237.00 loops=1)
+                            Filter: (user_id = 2)
+                            Rows Removed by Filter: 2120
+                            Buffers: shared hit=16
+                      ->  Seq Scan on auth_permission v2  (cost=0.00..4.49 rows=1 width=4) (actual time=0.006..0.006 rows=1.00 loops=237)
+                            Filter: ((content_type_id = 17) AND ((codename)::text = 'view_document'::text))
+                            Rows Removed by Filter: 67
+                            Buffers: shared hit=474
+                ->  Seq Scan on documents_document u0  (cost=0.00..1221.96 rows=12 width=4) (actual time=0.002..1.917 rows=10715.24 loops=237)
+                      Filter: (deleted_at IS NULL)
+                      Buffers: shared hit=214345
+        SubPlan 2
+          ->  Nested Loop Semi Join  (cost=4.73..1305.09 rows=1 width=8) (actual time=6.729..38127.912 rows=9025.00 loops=1)
+                Join Filter: ((((v0_1.object_pk)::bigint)::character varying)::text = (((u0_2.id)::bigint)::character varying)::text)
+                Rows Removed by Join Filter: 98955406
+                Buffers: shared hit=8382237
+                ->  Nested Loop Semi Join  (cost=4.73..82.77 rows=1 width=516) (actual time=1.109..137.661 rows=9025.00 loops=1)
+                      Buffers: shared hit=145515
+                      ->  Nested Loop  (cost=4.44..73.62 rows=24 width=520) (actual time=1.090..18.002 rows=45387.00 loops=1)
+                            Buffers: shared hit=329
+                            ->  Seq Scan on auth_permission v2_1  (cost=0.00..4.49 rows=1 width=4) (actual time=0.011..0.023 rows=1.00 loops=1)
+                                  Filter: (((codename)::text = 'view_document'::text) AND (content_type_id = 17))
+                                  Rows Removed by Filter: 165
+                                  Buffers: shared hit=2
+                            ->  Bitmap Heap Scan on guardian_groupobjectpermission v0_1  (cost=4.44..68.93 rows=20 width=524) (actual time=1.077..10.777 rows=45387.00 loops=1)
+                                  Recheck Cond: (permission_id = v2_1.id)
+                                  Heap Blocks: exact=290
+                                  Buffers: shared hit=327
+                                  ->  Bitmap Index Scan on guardian_groupobjectpermission_permission_id_36572738  (cost=0.00..4.43 rows=20 width=0) (actual time=1.026..1.026 rows=45387.00 loops=1)
+                                        Index Cond: (permission_id = v2_1.id)
+                                        Index Searches: 1
+                                        Buffers: shared hit=37
+                      ->  Nested Loop  (cost=0.30..0.37 rows=1 width=8) (actual time=0.002..0.002 rows=0.20 loops=45387)
+                            Join Filter: (u0_1.id = u1.group_id)
+                            Buffers: shared hit=145186
+                            ->  Index Only Scan using auth_group_pkey on auth_group u0_1  (cost=0.14..0.17 rows=1 width=4) (actual time=0.001..0.001 rows=1.00 loops=45387)
+                                  Index Cond: (id = v0_1.group_id)
+                                  Heap Fetches: 45387
+                                  Index Searches: 45387
+                                  Buffers: shared hit=90774
+                            ->  Index Only Scan using auth_user_groups_user_id_group_id_94350c0c_uniq on auth_user_groups u1  (cost=0.15..0.18 rows=1 width=4) (actual time=0.001..0.001 rows=0.20 loops=45387)
+                                  Index Cond: ((user_id = 2) AND (group_id = v0_1.group_id))
+                                  Heap Fetches: 9025
+                                  Index Searches: 45387
+                                  Buffers: shared hit=54412
+                ->  Seq Scan on documents_document u0_2  (cost=0.00..1221.96 rows=12 width=4) (actual time=0.002..1.956 rows=10965.59 loops=9025)
+                      Filter: (deleted_at IS NULL)
+                      Buffers: shared hit=8236722
+Planning:
+  Buffers: shared hit=3
+Planning Time: 1.119 ms
+Execution Time: 39121.312 ms

profiling/run_with_postgres.sh

@@ -0,0 +1,48 @@
+#!/usr/bin/env bash
+# profiling/run_with_postgres.sh
+#
+# Starts a PostgreSQL 18 container (matching
+# docker/compose/docker-compose.postgres.yml's image) if one isn't already
+# running, waits for it to accept connections, force-terminates any
+# leftover connections from a previous run that crashed or was killed, then
+# runs the given command against it with the right PAPERLESS_DB* env vars
+# set. The container is intentionally left running afterward -- see
+# stop_postgres.sh to tear it down explicitly once you're done profiling
+# for the session.
+set -euo pipefail
+
+CONTAINER_NAME="pngx-profiling-pg"
+HOST_PORT="55432"
+
+if ! docker inspect "$CONTAINER_NAME" >/dev/null 2>&1; then
+	docker run --rm -d \
+		--name "$CONTAINER_NAME" \
+		-e POSTGRES_DB=paperless \
+		-e POSTGRES_USER=paperless \
+		-e POSTGRES_PASSWORD=paperless \
+		-p "${HOST_PORT}:5432" \
+		docker.io/library/postgres:18 >/dev/null
+	echo "Started profiling Postgres container '$CONTAINER_NAME' on port $HOST_PORT (left running -- see profiling/stop_postgres.sh)." >&2
+fi
+
+until docker exec "$CONTAINER_NAME" pg_isready -U paperless >/dev/null 2>&1; do
+	sleep 1
+done
+
+# Reap any connections left over from a previous run that crashed, was
+# killed, or timed out mid-query -- without this, a persistent container
+# can accumulate stuck backends that block later test-database
+# create/drop operations indefinitely.
+docker exec "$CONTAINER_NAME" psql -U paperless -d paperless -v ON_ERROR_STOP=0 -c "
+  SELECT pg_terminate_backend(pid)
+  FROM pg_stat_activity
+  WHERE datname IN ('paperless', 'test_paperless')
+    AND pid <> pg_backend_pid();
+" >/dev/null 2>&1 || true
+
+PAPERLESS_DBHOST=localhost \
+	PAPERLESS_DBNAME=paperless \
+	PAPERLESS_DBUSER=paperless \
+	PAPERLESS_DBPASS=paperless \
+	PAPERLESS_DBPORT="${HOST_PORT}" \
+	"$@"

profiling/seed.py

@@ -0,0 +1,199 @@
+# profiling/seed.py
+from __future__ import annotations
+
+import random
+from dataclasses import dataclass
+from typing import TYPE_CHECKING
+from typing import Literal
+
+from django.contrib.auth.models import Group
+from django.contrib.auth.models import User
+from guardian.shortcuts import assign_perm
+
+from documents.models import Document
+from documents.tests.factories import CorrespondentFactory
+from documents.tests.factories import DocumentFactory
+from documents.tests.factories import DocumentTypeFactory
+from documents.tests.factories import StoragePathFactory
+from documents.tests.factories import TagFactory
+
+if TYPE_CHECKING:
+    from documents.models import Correspondent
+    from documents.models import DocumentType
+    from documents.models import StoragePath
+    from documents.models import Tag
+
+ScaleProfile = Literal["medium", "large"]
+
+# Fraction of seeded documents given a real owner; the remainder stays
+# owner=None, mirroring a real install's mix of owned and legacy/imported
+# unowned documents.
+_OWNED_FRACTION = 0.9
+
+
+class _ScaleCounts:
+    __slots__ = (
+        "correspondents",
+        "document_types",
+        "documents",
+        "groups",
+        "storage_paths",
+        "tags",
+        "users",
+    )
+
+    def __init__(
+        self,
+        *,
+        documents: int,
+        tags: int,
+        correspondents: int,
+        document_types: int,
+        storage_paths: int,
+        users: int,
+        groups: int,
+    ) -> None:
+        self.documents = documents
+        self.tags = tags
+        self.correspondents = correspondents
+        self.document_types = document_types
+        self.storage_paths = storage_paths
+        self.users = users
+        self.groups = groups
+
+
+_SCALE_PROFILES: dict[ScaleProfile, _ScaleCounts] = {
+    "medium": _ScaleCounts(
+        documents=20_000,
+        tags=100,
+        correspondents=300,
+        document_types=50,
+        storage_paths=20,
+        users=10,
+        groups=5,
+    ),
+    "large": _ScaleCounts(
+        documents=360_000,
+        tags=1_000,
+        correspondents=5_000,
+        document_types=300,
+        storage_paths=50,
+        users=25,
+        groups=10,
+    ),
+}
+# Ratios measured from a real install (discussion #13276): 1,414 user-perm
+# rows / 27,232 group-perm rows over 12,000 documents.
+_USER_PERM_ROWS_PER_DOC = 1_414 / 12_000
+_GROUP_PERM_ROWS_PER_DOC = 27_232 / 12_000
+
+
+def _sample_distinct_pairs(
+    rng: random.Random,
+    n_subjects: int,
+    n_objects: int,
+    count: int,
+) -> set[tuple[int, int]]:
+    """
+    Rejection-sample `count` distinct (subject_index, object_index) pairs.
+    `count` is always well under `n_subjects * n_objects` for every scale
+    profile, so this terminates quickly.
+    """
+    if count > n_subjects * n_objects:
+        msg = (
+            f"cannot sample {count} distinct pairs from only "
+            f"{n_subjects * n_objects} possible (subject, object) slots"
+        )
+        raise ValueError(msg)
+    pairs: set[tuple[int, int]] = set()
+    while len(pairs) < count:
+        pairs.add((rng.randrange(n_subjects), rng.randrange(n_objects)))
+    return pairs
+
+
+@dataclass(frozen=True, slots=True)
+class SeededData:
+    users: tuple[User, ...]
+    groups: tuple[Group, ...]
+    documents: tuple[Document, ...]
+    tags: tuple[Tag, ...]
+    correspondents: tuple[Correspondent, ...]
+    document_types: tuple[DocumentType, ...]
+    storage_paths: tuple[StoragePath, ...]
+
+
+def seed_permission_dataset(
+    scale: ScaleProfile = "medium",
+    *,
+    seed: int = 1337,
+) -> SeededData:
+    """
+    Build a dataset whose document count and guardian-permission-row ratios
+    mirror real bug reports, so profiling results are representative of
+    actual large installs rather than an arbitrary small fixture.
+    """
+    counts = _SCALE_PROFILES[scale]
+    rng = random.Random(seed)
+
+    users = tuple(
+        User.objects.create_user(username=f"profile_user_{i}")
+        for i in range(counts.users)
+    )
+    groups = tuple(
+        Group.objects.create(name=f"profile_group_{i}") for i in range(counts.groups)
+    )
+    for user in users:
+        user.groups.add(rng.choice(groups))
+
+    documents = list(DocumentFactory.create_batch(counts.documents))
+
+    # Assign realistic ownership -- without this, every document stays
+    # owner=None and the "owned or unowned" visibility clause is trivially
+    # true for every row, so no guardian permission check ever needs to run
+    # (see the amendment note above this code block).
+    owned_documents = []
+    for document in documents:
+        if rng.random() < _OWNED_FRACTION:
+            document.owner = rng.choice(users)
+            owned_documents.append(document)
+    Document.objects.bulk_update(owned_documents, ["owner"], batch_size=2_000)
+    documents = tuple(documents)
+
+    tags = tuple(TagFactory.create_batch(counts.tags))
+    correspondents = tuple(CorrespondentFactory.create_batch(counts.correspondents))
+    document_types = tuple(DocumentTypeFactory.create_batch(counts.document_types))
+    storage_paths = tuple(StoragePathFactory.create_batch(counts.storage_paths))
+
+    n_user_perms = round(counts.documents * _USER_PERM_ROWS_PER_DOC)
+    n_group_perms = round(counts.documents * _GROUP_PERM_ROWS_PER_DOC)
+
+    # Grant permissions only on OWNED documents -- a grant on an already-
+    # unowned document is a no-op for visibility (unowned documents are
+    # visible to everyone regardless), so restricting the pool here is what
+    # makes each assign_perm() call actually matter for someone, and is
+    # what exercises the guardian-permission-join code path this profiling
+    # effort exists to measure.
+    for user_idx, owned_idx in _sample_distinct_pairs(
+        rng,
+        len(users),
+        len(owned_documents),
+        n_user_perms,
+    ):
+        assign_perm("view_document", users[user_idx], owned_documents[owned_idx])
+    for group_idx, owned_idx in _sample_distinct_pairs(
+        rng,
+        len(groups),
+        len(owned_documents),
+        n_group_perms,
+    ):
+        assign_perm("view_document", groups[group_idx], owned_documents[owned_idx])
+
+    return SeededData(
+        users=users,
+        groups=groups,
+        documents=documents,
+        tags=tags,
+        correspondents=correspondents,
+        document_types=document_types,
+        storage_paths=storage_paths,
+    )

profiling/stop_postgres.sh

@@ -0,0 +1,24 @@
+#!/usr/bin/env bash
+# profiling/stop_postgres.sh
+#
+# Explicit, manual teardown of the profiling Postgres container. Not called
+# automatically by run_with_postgres.sh -- run this yourself once you're
+# done with a profiling session, so a seeded `large`-scale dataset can be
+# reused across several script runs first. Terminates any active backends
+# before stopping, so a stuck query can't stall `docker stop` waiting for
+# a graceful Postgres shutdown that never comes.
+set -euo pipefail
+
+CONTAINER_NAME="pngx-profiling-pg"
+
+if docker inspect "$CONTAINER_NAME" >/dev/null 2>&1; then
+	docker exec "$CONTAINER_NAME" psql -U paperless -d paperless -v ON_ERROR_STOP=0 -c "
+    SELECT pg_terminate_backend(pid)
+    FROM pg_stat_activity
+    WHERE pid <> pg_backend_pid();
+  " >/dev/null 2>&1 || true
+	docker stop "$CONTAINER_NAME" >/dev/null
+	echo "Stopped and removed profiling Postgres container."
+else
+	echo "No profiling Postgres container was running."
+fi

profiling/test_harness_self_check.py

@@ -0,0 +1,74 @@
+# profiling/test_harness_self_check.py
+from __future__ import annotations
+
+import json
+from pathlib import Path
+
+import pytest
+
+from profiling.harness import append_profiling_history
+from profiling.harness import require_postgres
+from profiling.harness import run_profile
+from profiling.seed import seed_permission_dataset
+
+
+@pytest.mark.profiling
+@pytest.mark.django_db
+def test_seed_medium_scale_produces_expected_counts() -> None:
+    require_postgres()
+    data = seed_permission_dataset(scale="medium")
+    assert len(data.documents) == 20_000
+    assert len(data.tags) == 100
+    assert len(data.correspondents) == 300
+    assert len(data.document_types) == 50
+    assert len(data.storage_paths) == 20
+
+    from guardian.models import GroupObjectPermission
+    from guardian.models import UserObjectPermission
+
+    user_perm_count = UserObjectPermission.objects.count()
+    group_perm_count = GroupObjectPermission.objects.count()
+    # within 5% of the ratio-derived target -- exact counts depend on random
+    # sampling without replacement, see seed.py
+    assert 2_242 <= user_perm_count <= 2_478
+    assert 43_111 <= group_perm_count <= 47_649
+
+
+@pytest.mark.profiling
+@pytest.mark.django_db
+def test_run_profile_reports_query_count_and_timing() -> None:
+    require_postgres()
+
+    def trivial() -> list[int]:
+        from documents.models import Document
+
+        return list(Document.objects.values_list("id", flat=True)[:1])
+
+    result = run_profile(trivial, repeat=3)
+    assert result.best_seconds >= 0
+    assert len(result.all_seconds) == 3
+    assert result.query_count >= 1
+
+
+def test_append_profiling_history_writes_a_valid_json_line() -> None:
+    history_path = Path(__file__).parent / "results" / "history.jsonl"
+    before_lines = (
+        history_path.read_text().splitlines() if history_path.exists() else []
+    )
+
+    append_profiling_history(
+        stage="self-check",
+        scenario="test_append_profiling_history_writes_a_valid_json_line",
+        best_seconds=0.001,
+        query_count=0,
+        scale="medium",
+        code_ref="test-run",
+    )
+
+    after_lines = history_path.read_text().splitlines()
+    assert len(after_lines) == len(before_lines) + 1
+    entry = json.loads(after_lines[-1])
+    assert entry["stage"] == "self-check"
+    assert entry["code_ref"] == "test-run"
+    assert entry["scale"] == "medium"
+    assert "timestamp" in entry

profiling/test_stage1_document_calls.py

@@ -0,0 +1,125 @@
+from __future__ import annotations
+
+import json
+from pathlib import Path
+
+import pytest
+
+from documents.models import Document
+from documents.permissions import get_objects_for_user_owner_aware
+from documents.permissions import permitted_document_ids
+from profiling.harness import append_profiling_history
+from profiling.harness import capture_explain_analyze
+from profiling.harness import require_postgres
+from profiling.harness import run_profile
+from profiling.seed import seed_permission_dataset
+
+RESULTS_DIR = Path(__file__).parent / "results"
+
+
+@pytest.mark.profiling
+@pytest.mark.django_db
+def test_profile_get_objects_for_user_owner_aware_document_baseline() -> None:
+    require_postgres()
+    data = seed_permission_dataset(scale="medium")
+    user = data.users[0]
+
+    def call() -> list[int]:
+        return list(
+            get_objects_for_user_owner_aware(
+                user,
+                "documents.view_document",
+                Document,
+            ).values_list("id", flat=True),
+        )
+
+    profile = run_profile(call, repeat=3)
+    plan = capture_explain_analyze(
+        get_objects_for_user_owner_aware(user, "documents.view_document", Document),
+    )
+
+    RESULTS_DIR.mkdir(exist_ok=True)
+    (RESULTS_DIR / "stage1_baseline.json").write_text(
+        json.dumps(
+            {
+                "get_objects_for_user_owner_aware_document": {
+                    "best_seconds": profile.best_seconds,
+                    "query_count": profile.query_count,
+                },
+            },
+            indent=2,
+        ),
+    )
+    (RESULTS_DIR / "stage1_baseline_explain.txt").write_text(plan)
+    append_profiling_history(
+        stage="stage1",
+        scenario="get_objects_for_user_owner_aware_document_baseline",
+        best_seconds=profile.best_seconds,
+        query_count=profile.query_count,
+        scale="medium",
+    )
+
+    print(f"\nBASELINE best={profile.best_seconds:.4f}s queries={profile.query_count}")  # noqa: T201
+    print(plan)  # noqa: T201
+
+
+@pytest.mark.profiling
+@pytest.mark.django_db
+def test_profile_permitted_document_ids_after_stage1() -> None:
+    require_postgres()
+    data = seed_permission_dataset(scale="medium")
+    user = data.users[0]
+
+    def call():
+        return list(
+            Document.objects.filter(id__in=permitted_document_ids(user)).values_list(
+                "id",
+                flat=True,
+            ),
+        )
+
+    profile = run_profile(call, repeat=3)
+    plan = capture_explain_analyze(
+        Document.objects.filter(id__in=permitted_document_ids(user)),
+    )
+
+    baseline = json.loads((RESULTS_DIR / "stage1_baseline.json").read_text())
+    baseline_seconds = baseline["get_objects_for_user_owner_aware_document"][
+        "best_seconds"
+    ]
+    baseline_queries = baseline["get_objects_for_user_owner_aware_document"][
+        "query_count"
+    ]
+
+    (RESULTS_DIR / "stage1_after.json").write_text(
+        json.dumps(
+            {
+                "permitted_document_ids": {
+                    "best_seconds": profile.best_seconds,
+                    "query_count": profile.query_count,
+                },
+                "baseline_best_seconds": baseline_seconds,
+                "baseline_query_count": baseline_queries,
+                "speedup_x": baseline_seconds / profile.best_seconds
+                if profile.best_seconds
+                else None,
+            },
+            indent=2,
+        ),
+    )
+    (RESULTS_DIR / "stage1_after_explain.txt").write_text(plan)
+    append_profiling_history(
+        stage="stage1",
+        scenario="permitted_document_ids_after_stage1",
+        best_seconds=profile.best_seconds,
+        query_count=profile.query_count,
+        scale="medium",
+    )
+
+    print(f"\nBEFORE best={baseline_seconds:.4f}s queries={baseline_queries}")  # noqa: T201
+    print(f"AFTER  best={profile.best_seconds:.4f}s queries={profile.query_count}")  # noqa: T201
+
+    # Hard gate: must not be a regression, and should be meaningfully faster
+    # at this scale (the whole point of this stage).
+    assert profile.best_seconds < baseline_seconds
+    assert profile.query_count <= baseline_queries

profiling/test_stage2_document_loops.py

@@ -0,0 +1,64 @@
+# profiling/test_stage2_document_loops.py
+from __future__ import annotations
+
+import pytest
+
+from documents.permissions import has_perms_owner_aware
+from documents.permissions import permitted_document_ids
+from profiling.harness import append_profiling_history
+from profiling.harness import require_postgres
+from profiling.harness import run_profile
+from profiling.seed import seed_permission_dataset
+
+
+@pytest.mark.profiling
+@pytest.mark.django_db
+def test_profile_per_row_checker_vs_resolved_set_for_bulk_operation() -> None:
+    require_postgres()
+    data = seed_permission_dataset(scale="medium")
+    user = data.users[0]
+    # simulate a bulk operation over 500 documents the user can actually see
+    # (bulk-edit/share/trash all operate on a user's own selection) -- built
+    # from confirmed-visible documents so all() can't short-circuit unfairly
+    # in either old_style or new_style, see amendment note above
+    permitted_ids = set(permitted_document_ids(user))
+    batch = [doc for doc in data.documents if doc.pk in permitted_ids][:500]
+    assert len(batch) == 500, (
+        f"expected at least 500 visible documents to build a fair batch, "
+        f"got {len(batch)} -- scale profile or seed ratios may need adjusting"
+    )
+
+    def old_style():
+        return all(has_perms_owner_aware(user, "view_document", doc) for doc in batch)
+
+    def new_style():
+        permitted = set(permitted_document_ids(user))
+        return all(doc.pk in permitted for doc in batch)
+
+    old_profile = run_profile(old_style, repeat=3)
+    new_profile = run_profile(new_style, repeat=3)
+
+    append_profiling_history(
+        stage="stage2",
+        scenario="per_row_checker_vs_resolved_set_old",
+        best_seconds=old_profile.best_seconds,
+        query_count=old_profile.query_count,
+        scale="medium",
+    )
+    append_profiling_history(
+        stage="stage2",
+        scenario="per_row_checker_vs_resolved_set_new",
+        best_seconds=new_profile.best_seconds,
+        query_count=new_profile.query_count,
+        scale="medium",
+    )
+
+    print(  # noqa: T201
+        f"\nOLD (per-row checker): best={old_profile.best_seconds:.4f}s queries={old_profile.query_count}",
+    )
+    print(  # noqa: T201
+        f"NEW (resolved set):    best={new_profile.best_seconds:.4f}s queries={new_profile.query_count}",
+    )
+
+    assert new_profile.query_count < old_profile.query_count
+    assert new_profile.best_seconds < old_profile.best_seconds