chore(profiling): record Stage 1 baseline for get_objects_for_user_owner_aware

2026-07-31 16:15:58 +00:00 · 2026-07-27 16:03:15 -07:00
parent 0506dcad05
commit e0902c63d6
4 changed files with 120 additions and 0 deletions
@@ -0,0 +1,3 @@
+{"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}
@@ -0,0 +1,6 @@
+{
+  "get_objects_for_user_owner_aware_document": {
+    "best_seconds": 0.025123266968876123,
+    "query_count": 1
+  }
+}
@@ -0,0 +1,49 @@
+Sort  (cost=2035.14..2035.15 rows=5 width=2900) (actual time=34.879..39.900 rows=20000.00 loops=1)
+  Sort Key: documents_document.created DESC
+  Sort Method: external merge  Disk: 4608kB
+  Buffers: shared hit=632, temp read=576 written=577
+  ->  Seq Scan on documents_document  (cost=1380.96..2035.08 rows=5 width=2900) (actual time=0.013..9.365 rows=20000.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))))
+        Buffers: shared hit=632
+        SubPlan 1
+          ->  Nested Loop Semi Join  (cost=0.27..657.61 rows=1 width=8) (never executed)
+                Join Filter: ((((v0.object_pk)::bigint)::character varying)::text = (((u0.id)::bigint)::character varying)::text)
+                ->  Nested Loop  (cost=0.27..12.79 rows=1 width=516) (never executed)
+                      Join Filter: (v0.permission_id = v2.id)
+                      ->  Index Only Scan using guardian_userobjectpermi_user_id_permission_id_ob_b0b3d2fc_uniq on guardian_userobjectpermission v0  (cost=0.27..8.29 rows=1 width=520) (never executed)
+                            Index Cond: (user_id = 2)
+                            Heap Fetches: 0
+                            Index Searches: 0
+                      ->  Seq Scan on auth_permission v2  (cost=0.00..4.49 rows=1 width=4) (never executed)
+                            Filter: ((content_type_id = 17) AND ((codename)::text = 'view_document'::text))
+                ->  Seq Scan on documents_document u0  (cost=0.00..644.64 rows=6 width=4) (never executed)
+                      Filter: (deleted_at IS NULL)
+        SubPlan 2
+          ->  Nested Loop Semi Join  (cost=4.73..723.34 rows=1 width=8) (never executed)
+                ->  Nested Loop Semi Join  (cost=4.44..722.95 rows=1 width=520) (never executed)
+                      Join Filter: ((((v0_1.object_pk)::bigint)::character varying)::text = (((u0_2.id)::bigint)::character varying)::text)
+                      ->  Nested Loop  (cost=4.44..73.62 rows=24 width=520) (never executed)
+                            ->  Seq Scan on auth_permission v2_1  (cost=0.00..4.49 rows=1 width=4) (never executed)
+                                  Filter: (((codename)::text = 'view_document'::text) AND (content_type_id = 17))
+                            ->  Bitmap Heap Scan on guardian_groupobjectpermission v0_1  (cost=4.44..68.93 rows=20 width=524) (never executed)
+                                  Recheck Cond: (permission_id = v2_1.id)
+                                  ->  Bitmap Index Scan on guardian_groupobjectpermission_permission_id_36572738  (cost=0.00..4.43 rows=20 width=0) (never executed)
+                                        Index Cond: (permission_id = v2_1.id)
+                                        Index Searches: 0
+                      ->  Materialize  (cost=0.00..644.67 rows=6 width=4) (never executed)
+                            ->  Seq Scan on documents_document u0_2  (cost=0.00..644.64 rows=6 width=4) (never executed)
+                                  Filter: (deleted_at IS NULL)
+                ->  Nested Loop  (cost=0.30..0.37 rows=1 width=8) (never executed)
+                      Join Filter: (u0_1.id = u1.group_id)
+                      ->  Index Only Scan using auth_group_pkey on auth_group u0_1  (cost=0.14..0.17 rows=1 width=4) (never executed)
+                            Index Cond: (id = v0_1.group_id)
+                            Heap Fetches: 0
+                            Index Searches: 0
+                      ->  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) (never executed)
+                            Index Cond: ((user_id = 2) AND (group_id = v0_1.group_id))
+                            Heap Fetches: 0
+                            Index Searches: 0
+Planning:
+  Buffers: shared hit=3
+Planning Time: 1.721 ms
+Execution Time: 42.131 ms
@@ -0,0 +1,62 @@
+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 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