perf(layer-loading): establish baseline and instrumentation [1/5]

api/hastefuncapi/function_app.py

@@ -8,6 +8,7 @@
 import os
 import re
 import tempfile
+import time
 import traceback
 
 import azure.functions as func  # type: ignore
@@ -72,6 +73,7 @@
     PublishingSourceNotFoundError,
     PublishingSourceResolver,
 )
+from hastegeo.core.utils import perf
 from hastegeo.core.utils.blob import (
     download_blob_to_tempfile,
     parse_byte_range,
@@ -735,6 +737,12 @@ async def GetProjectDetails(req: func.HttpRequest) -> func.HttpResponse:
             f"GetProjectDetails HTTP trigger function processed a request for project id: {project_id} with includeModels: {include_models}"
         )
 
+        # Phase 0 baseline instrumentation (spec/features/perf-layer-loading).
+        # Opt-in via HASTE_PERF=true; zero overhead when disabled.
+        _perf_on = os.environ.get("HASTE_PERF", "false").lower() == "true"
+        _perf = perf.begin(_perf_on)
+        _perf_wall = time.perf_counter()
+
         project = await asyncio.to_thread(
             MetadataProcessor(
                 data_type=config.get_metadata_types().PROJECT.value,
@@ -839,7 +847,21 @@ async def GetProjectDetails(req: func.HttpRequest) -> func.HttpResponse:
         project["imageLayer"].sort(
             key=lambda x: x["creationDate"], reverse=True
         )
-        return func.HttpResponse(json.dumps(project), status_code=200)
+        _payload = json.dumps(project)
+        _perf_headers = perf.headers(_perf, _perf_wall)
+        perf.log_summary(
+            logger,
+            "GetProjectDetails",
+            _perf,
+            _perf_wall,
+            project_id=project_id,
+            include_models=include_models,
+            layers=len(image_layers),
+            payload_bytes=len(_payload),
+        )
+        return func.HttpResponse(
+            _payload, status_code=200, headers=_perf_headers or None
+        )
 
     except FileNotFoundError as e:
         logger.error(f"Project not found: {e}\n{traceback.format_exc()}")
@@ -1470,9 +1492,9 @@ async def GetModelArtifact(req: func.HttpRequest) -> func.HttpResponse:
     # interactive labeler's other artifacts are fetched by range and parsed
     # in-browser, so they must NOT be forced as downloads).
     if kind == "gpkg":
-        headers[
-            "Content-Disposition"
-        ] = f'attachment; filename="building_predictions_{model_id}.gpkg"'
+        headers["Content-Disposition"] = "; ".join(
+            ["attachment", f'filename="building_predictions_{model_id}.gpkg"']
+        )
     if result.etag:
         headers["ETag"] = (
             result.etag if result.etag.startswith('"') else f'"{result.etag}"'

docker/docker-compose.perf.yml

@@ -0,0 +1,20 @@
+# Perf-baseline overlay for the perf-layer-loading spec (Phase 0).
+#
+# Enables the opt-in HASTE_PERF instrumentation and bind-mounts the working-tree
+# copies of the API handler + hastegeo library over the image's runtime paths, so
+# the current branch's code runs without an image rebuild.
+#
+# Usage:
+#   docker compose -f docker/docker-compose.yml -f docker/docker-compose.perf.yml \
+#     up -d hastefuncapi api-proxy
+services:
+  hastefuncapi:
+    environment:
+      HASTE_PERF: "true"
+    volumes:
+      # hastegeo exists in two places (a site-packages install and a wwwroot
+      # copy); sys.path order varies by process, so overlay the working-tree
+      # source over BOTH to guarantee the worker imports the updated code.
+      - ../hastelib/src/hastegeo:/usr/local/lib/python3.11/site-packages/hastegeo:ro
+      - ../hastelib/src/hastegeo:/home/site/wwwroot/hastegeo:ro
+      - ../api/hastefuncapi/function_app.py:/home/site/wwwroot/function_app.py:ro

hastelib/src/hastegeo/core/processors/metadata.py

@@ -5,6 +5,7 @@
 from hastegeo.core.config import Config
 
 from ..data_layer.unified import UnifiedDataLayer
+from ..utils.perf import timed
 
 
 class MetadataProcessor:
@@ -96,19 +97,23 @@ def load(self, key, data_format="json"):
         """
         Load metadata from the backend storage.
         """
-        metadata = self.storage.load(
-            identifier=key, data_type=self.data_type, data_format=data_format
-        )
+        with timed("load"):
+            metadata = self.storage.load(
+                identifier=key,
+                data_type=self.data_type,
+                data_format=data_format,
+            )
         return metadata
 
     def load_all(self, data_format="json"):
         """
         Load all metadata from the backend storage.
         """
         metadata = []
-        metadata_list = self.storage.load_all(
-            data_type=self.data_type, data_format=data_format
-        )
+        with timed("load_all"):
+            metadata_list = self.storage.load_all(
+                data_type=self.data_type, data_format=data_format
+            )
         for each_metadata in metadata_list:
             metadata.append(each_metadata)
         return metadata
@@ -118,9 +123,10 @@ def load_all_from_partition(self, data_format="json"):
         Load all metadata from the backend storage.
         """
         metadata = []
-        metadata_list = self.storage.load_all_from_partition(
-            data_type=self.data_type, data_format=data_format
-        )
+        with timed("load_all_from_partition"):
+            metadata_list = self.storage.load_all_from_partition(
+                data_type=self.data_type, data_format=data_format
+            )
         for each_metadata in metadata_list:
             metadata.append(each_metadata)
         return metadata
@@ -225,8 +231,9 @@ def export(self, key, data_format="json"):
         """
         # NOTE: This is a quick method to make the export work for Azure blob storage layer.
         # Rework needed to handle different storage types and formats properly.
-        return self.storage.get_file_remote_path(
-            identifier=key,
-            data_type=self.data_type,
-            data_format=data_format,
-        )
+        with timed("export"):
+            return self.storage.get_file_remote_path(
+                identifier=key,
+                data_type=self.data_type,
+                data_format=data_format,
+            )

hastelib/src/hastegeo/core/utils/perf.py

@@ -0,0 +1,123 @@
+# Copyright (c) Microsoft Corporation. All rights reserved.
+# Licensed under the MIT License.
+"""Lightweight, opt-in performance instrumentation.
+
+Counts and times backend storage round-trips for a single logical request so we
+can establish a baseline (Phase 0 of the perf-layer-loading spec) and later prove
+the O(layers x models) -> O(1) improvement.
+
+Design notes:
+- A ``ContextVar`` holds a shared ``PerfCounter`` *object*. ``asyncio.to_thread``
+  copies the current context into the worker thread, so a read method running in
+  the thread sees the *same* counter instance and its (lock-guarded) mutations are
+  visible back in the calling coroutine. The ContextVar value (the reference) is
+  never reassigned inside the thread, only the object it points to is mutated.
+- When tracking is not enabled, ``timed()`` is a no-op with no measurable overhead,
+  so instrumenting the shared data layer is safe for every caller (API + queues).
+"""
+import contextvars
+import threading
+import time
+from contextlib import contextmanager
+
+_current: "contextvars.ContextVar[PerfCounter | None]" = (
+    contextvars.ContextVar("haste_perf_counter", default=None)
+)
+
+
+class PerfCounter:
+    """Thread-safe accumulator of storage round-trip count and duration."""
+
+    def __init__(self):
+        self.calls = 0
+        self.seconds = 0.0
+        self.by_op = {}
+        self._lock = threading.Lock()
+
+    def record(self, op, elapsed):
+        with self._lock:
+            self.calls += 1
+            self.seconds += elapsed
+            entry = self.by_op.get(op)
+            if entry is None:
+                self.by_op[op] = {"calls": 1, "seconds": elapsed}
+            else:
+                entry["calls"] += 1
+                entry["seconds"] += elapsed
+
+
+def begin(enabled=True):
+    """Start tracking for the current context. Returns the counter (or None)."""
+    if not enabled:
+        _current.set(None)
+        return None
+    counter = PerfCounter()
+    _current.set(counter)
+    return counter
+
+
+def end():
+    """Stop tracking for the current context."""
+    _current.set(None)
+
+
+def get_counter():
+    return _current.get()
+
+
+@contextmanager
+def timed(op):
+    """Time an ``op`` and record it on the active counter, if any.
+
+    Zero-overhead when tracking is disabled (no active counter).
+    """
+    counter = _current.get()
+    if counter is None:
+        yield
+        return
+    start = time.perf_counter()
+    try:
+        yield
+    finally:
+        counter.record(op, time.perf_counter() - start)
+
+
+def headers(counter, wall_start):
+    """Response headers exposing round-trip count/timing for benchmarking."""
+    if counter is None:
+        return {}
+    storage_ms = counter.seconds * 1000.0
+    wall_ms = (time.perf_counter() - wall_start) * 1000.0
+    return {
+        "X-Haste-Storage-Calls": str(counter.calls),
+        "X-Haste-Storage-Ms": f"{storage_ms:.1f}",
+        "X-Haste-Wall-Ms": f"{wall_ms:.1f}",
+        "Server-Timing": ", ".join(
+            [
+                ";".join(["storage", "desc=storage", f"dur={storage_ms:.1f}"]),
+                ";".join(["wall", "desc=wall", f"dur={wall_ms:.1f}"]),
+            ]
+        ),
+    }
+
+
+def log_summary(logger, name, counter, wall_start, **fields):
+    """Emit a single structured ``PERF`` line and stop tracking."""
+    if counter is None:
+        return
+    wall_ms = (time.perf_counter() - wall_start) * 1000.0
+    ops = {
+        op: {"calls": e["calls"], "ms": round(e["seconds"] * 1000, 1)}
+        for op, e in counter.by_op.items()
+    }
+    extra = " ".join(f"{k}={v}" for k, v in fields.items())
+    logger.info(
+        "PERF %s %s storage_calls=%d storage_ms=%.1f wall_ms=%.1f ops=%s",
+        name,
+        extra,
+        counter.calls,
+        counter.seconds * 1000.0,
+        wall_ms,
+        ops,
+    )
+    end()

spec/features/perf-layer-loading/README.md

@@ -0,0 +1,70 @@
+# Feature: Image Layer & Model Run Loading Performance
+
+**Status:** draft
+**Author:** prbatero
+**Date:** 2026-08-03
+**Target Release:** TBD
+**Priority:** P1
+
+## Summary
+
+The HASTE UI takes too long to load a project's image layers and their associated
+model runs, and the delay grows roughly linearly (in places quadratically) with the
+number of image layers on a project. The root cause is a set of N+1 storage access
+patterns in the `GetProjectDetails` API path, fully-sequential (never parallelized)
+blob I/O in `hastelib`, full-container blob scans without prefix filtering, and a UI
+that re-fetches the entire project — every model of every layer — every 20 seconds
+while re-rendering the whole component tree. This spec catalogs the verified
+bottlenecks and lays out a phased plan to make layer/run loading fast and roughly
+constant-time regardless of project size.
+
+## Motivation
+
+- **Problem:** Disaster-response users open a project and wait many seconds for the
+  layer list to appear; the wait scales with project size, so the most active
+  (large) projects are the slowest — exactly when responders can least afford it.
+- **Trigger:** Direct user report — "the HASTE UI takes too long to load image
+  layers and their model runs when there are multiple image layers on a project."
+- **Cost of inaction:** Load time degrades as projects accumulate layers and models;
+  the 20s polling loop multiplies backend load and cost, and the app feels
+  progressively slower the more it is used.
+
+## Success Criteria
+
+- [ ] `GET GetProjectDetails?includeModels=True` for a 50-layer / ~5-models-per-layer
+      project returns in **< 1.5s p95** (from a current baseline measured in Phase 0).
+- [ ] Backend storage round-trips for that request drop from **O(layers × models)**
+      (~600 for the 50×5 case) to **O(1) small constant** (≤ ~6 partition reads).
+- [ ] UI time-to-interactive for the project page is **< 2s p95** on the same project
+      and no longer scales linearly with layer count.
+- [ ] Background refresh no longer refetches unchanged data or re-renders the full
+      tree; idle CPU and network on an open project page drop measurably.
+
+## HASTE Components Affected
+
+| Component | Impact |
+|---|---|
+| `hastelib/src/hastegeo/core/data_layer/` | Add prefix-scoped listing, parallel/metadata-only reads, fix double-deserialize |
+| `hastelib/src/hastegeo/core/processors/` | `MetadataProcessor` filtered load + optional request-scoped cache |
+| `hastelib/src/hastegeo/core/artifact_storage/` | Parallelize multi-blob fetch |
+| `api/hastefuncapi/` | Rewrite `GetProjectDetails` layer loop; add cache headers |
+| `api/hastefuncqueues/` | Parallelize independent loads; fix N+1 label lookup; batch saves |
+| `ui/src/Components/` | Smart polling, memoization, split context, lazy model expansion |
+
+## Related Specs
+
+| Spec | Relationship |
+|---|---|
+| [../batch-config-drift/](../batch-config-drift/) | related (queue/Batch path) |
+
+## Document Index
+
+| Document | Purpose | Status |
+|---|---|---|
+| [findings.md](findings.md) | Verified bottleneck inventory with file:line evidence | draft |
+| [design.md](design.md) | Technical design of each fix | draft |
+| [plan.md](plan.md) | Phased execution plan | Phase 0 done |
+| [impact-analysis.md](impact-analysis.md) | Risk, blast radius, backward compat | draft |
+| [test-plan.md](test-plan.md) | Benchmark harness & regression coverage | draft |
+| [results.md](results.md) | **Phase 0 measured baseline** (603 round-trips, 20.8 s API, 40.3 s UI TTI @ 50×5) | done |
+| [tools/](tools/) | Seed + benchmarks: `phase0_baseline.py`, `bench_api_http.py`, `ui_bench.cjs`; `docker/docker-compose.perf.yml` overlay | done |