Skip to content

Add get_read_latency: p50/p95/p99 durations per web and MCP read, and name the web and MCP store connections (#4442) - #4454

Merged
erikdarlingdata merged 5 commits into
devfrom
feat/4442-get-read-latency
Sep 27, 2026
Merged

erikdarlingdata merged 5 commits into
devfrom
feat/4442-get-read-latency

Conversation

@erikdarlingdata

@erikdarlingdata erikdarlingdata commented Sep 26, 2026 •

Copy link
Copy Markdown
Owner

Refs #4442 (scope 2).

Why

The service now records every web read's and composed-panel read's duration into hourly latency
histograms (collect.read_latency), but nothing reads that table back yet. This adds the read that
answers "what's really slow": p50/p95/p99, count, mean, max and timeout counts per (surface, route),
so a regression shows on a dashboard instead of a guess from the last slow-query log line. It also
names the web dashboard's and MCP server's own store connections in pg_stat_activity, which today
show up as an unlabeled viewer/mcp backend indistinguishable from any other session under that role.

What changes

  • DarlingReadLatencyReader (new): reads collect.read_latency for a window, summing run_count,
    total_ms, and the timeout count straight off the table, and separately exploding bucket_counts
    with unnest(...) WITH ORDINALITY to sum it ELEMENT-WISE per (surface, route) before re-collecting it
    with array_agg(... ORDER BY ord). Two joined CTEs rather than one pass, because summing run_count
    off the exploded rows would multiply every row by its own bucket-array length.
  • DarlingMcpReadLatencyTools.GetReadLatency (new MCP tool get_read_latency): hours (default 24,
    validated by the shared ValidateHoursBack), optional surface/route filters, limit (default 25,
    validated by ValidateTop). Computes p50/p95/p99 in C# from the summed bucket histogram via the
    existing ReadLatencyPercentiles.FromBuckets, sorts by p95 descending then count, and returns the house
    JSON envelope (mirrors get_collector_cost's shape) with a top-level note that every percentile is a
    bucket UPPER-BOUND estimate, never an interpolation. An empty window returns an honest empty status
    naming the reason (pre-V148 store, or a genuinely quiet window).
  • The web read: a CatalogDescriptors entry and a BuildReadDispatch row for get_read_latency,
    same params, so catalog/dispatch key parity holds.
  • ApplicationName on the web and MCP store connections: DarlingManagedPostgres.BuildRoleConnectionString
    now takes an optional applicationName, set to the new WebApplicationName/McpApplicationName constants
    (PerformanceMonitorDarling-Web / PerformanceMonitorDarling-Mcp) for the managed-mode viewer/mcp role
    connection strings. DarlingStoreLogins.BuildComposeStoreRoleConnectionString sets the same names on the
    compose-store role path (bring-your-own and container-provisioned stores). The service's own collection
    connections to a monitored server are untouched.
  • Not touched: MCP host registration / per-tool timing wrapper (a separate change, per scope).

/core membership

Not added to DarlingCoreToolProfile's closure: it is not one of the four entry tools and no
next_tools table names it, so it follows the profile's own computed-closure rule rather than a manual
add. It is reachable on the default / path.

Test plan

Build: Darling.Tests.csproj and Lite.Tests.csproj both build with EnableWindowsTargeting=true,
0 warnings-as-relevant / 0 errors on both.

Ran in-process on this machine (Darling.Tests.dll, -class):

  • DarlingCoreToolProfileTests: Total: 8, Failed: 0 — the closure count and membership are unaffected
    by the new tool, confirming it correctly sits outside /core.
  • DarlingCustomViewsTests: Total: 71, Failed: 0 — includes
    CatalogDescriptors_Keys_EqualTheReadDispatchKeys and Catalog_Viz_IsExactlyKnownViz (the
    BuildReadDispatch().Count vs the emitted catalog's reads array length), both computed rather than a
    hardcoded total, so they pass with the new entry present on both sides.
  • DocCommentHygieneTests: Total: 77, Failed: 0.
  • ReadmeDerivedCountPinTests: Total: 5, Failed: 0 — unaffected; this tool isn't one of the counted
    claims in Darling/README.md.

Lite/Darling MCP-tool census (Lite.Tests/CrossAppMcpToolInventoryPinTests.cs): added
get_read_latency to KnownLiteMissingMcpTools with the same architectural-boundary rationale as
get_collector_cost and its neighbors (an internal self-metric over the central store's read pipeline,
which Lite — no central store, no /api/read/* dispatch loop of this shape — has no twin for). Not run
here (it's a Lite.Tests-only class, cross-referencing source text, not requiring the live rig); the build
passing is the compile-time check, and CI runs the assertion.

Live pins added (GetReadLatencyLiveTests, new file)

Run on a scratch Postgres container (macOS in-process Darling.Tests.dll): Total: 4, Failed: 0.

  • Field fixture (TwoRoutesAcrossTwoHours_MatchHandComputedPercentilesCountsAndSortOrder): seeds
    collect.read_latency across two hours through ReadLatencyAccumulator, then reads it back through
    DarlingMcpReadLatencyTools.GetReadLatency (the tool's own call path, not the reader directly):
    • Route A (get_wait_stats, web, fast): 100 rows, 50 at 50 ms and 50 at 90 ms. n=100, total=7,000,
      mean=70, max=90, 0 timeouts. Hand-computed: p50=50 ms (bucket cumulative reaches the p50 target at
      the 50 ms bound), p95=100 ms, p99=100 ms.
    • Route B (get_plan_cache, web, a slow tail): 94 rows at 150 ms, 5 rows at 2,000 ms (~5% at 1-5 s),
      1 row at 30,000 ms (~1% at 20-60 s), plus 2 rows recorded with outcome Timeout at 61,000 ms each
      (the accumulator's exact lowercase "timeout" spelling). n=102, total=176,100, mean=1,726
      (integer division), max=61,000, timeouts=2. Hand-computed: p50=150 ms, p95=2,000 ms, p99=90,000 ms
      (the first bound at/above the cumulative 99th-percentile row, which falls in the same bucket as the
      two Timeout rows).
    • Asserts sort order too: Route B leads (p95 2,000 > Route A's p95 100), the documented "worst tail
      first" order.
  • Filters (SurfaceAndRouteFilters_EachScopeToOneRow): one surface-filtered call returns exactly
    the compose/custom-view row, one route-filtered call returns exactly the web/get_wait_stats
    row, from a fixture with both present.
  • Empty window (AnEmptyWindow_GivesTheDocumentedHonestEmptyResult): a freshly migrated store with
    no rows returns {"status":"empty", ...} with the documented message, not an error.
  • ApplicationName (ApplicationName_ThroughTheProductsOwnConnectionBuilder_NamesEachSurfacesBackend):
    creates viewer/mcp logins on the scratch store, builds their connection strings through the
    product's own DarlingStoreLogins.BuildComposeStoreRoleConnectionString (no hand-written connection
    string), opens each, and asserts SELECT application_name FROM pg_stat_activity WHERE pid = pg_backend_pid() returns PerformanceMonitorDarling-Web for the viewer login and
    PerformanceMonitorDarling-Mcp for the mcp login.

Two real bugs the fixture found and fixed in DarlingReadLatencyReader

Building the fixture surfaced two bugs in the read SQL, both now fixed in this PR:

  1. Timeouts came back NULL, not 0, for a route with no timeout rows. sum(run_count) FILTER (WHERE outcome = 'timeout') returns NULL when no row in the group matches the filter (proven against
    Postgres directly: SELECT sum(x) FILTER (WHERE false) FROM (VALUES(1),(2)) t(x) returns NULL, not
    0), and the reader read that column with GetInt64, which throws on NULL. Fixed with
    coalesce(..., 0).
  2. The element-wise bucket sum returned numeric[], which failed to cast to long[]. Postgres's
    sum() over a bigint column returns numeric, so array_agg(sum(b.bucket_count) ...) produced a
    numeric[], and (long[])reader.GetValue(5) threw InvalidCastException: Unable to cast object of type 'System.Decimal[]' to type 'System.Int64[]' on every window with more than one flushed hour.
    Fixed with an explicit ::bigint cast on the summed value before it goes into array_agg.

Both would have hit any real store with more than a trivial amount of read-latency history; the field
fixture (two hours, two routes) was enough to trip both.

Mutation: the element-wise bucket sum

Changed sum(b.bucket_count) to min(b.bucket_count) (uncommitted, in the working tree) in the
buckets CTE: TwoRoutesAcrossTwoHours_MatchHandComputedPercentilesCountsAndSortOrder went RED
(percentile/count assertions failed against the mutated histogram). Reverted; the class is GREEN again
at the head of this PR. (An earlier attempt with max(...) did not go red for this fixture's shape —
min is the mutation that actually exercises the element-wise-sum claim end to end.)

Full pin run (this machine, in-process, against a scratch Postgres 18 + TimescaleDB container)

  • GetReadLatencyLiveTests: Total: 4, Failed: 0
  • DarlingCoreToolProfileTests: Total: 8, Failed: 0
  • DarlingCustomViewsTests: Total: 71, Failed: 0
  • ReadmeDerivedCountPinTests: Total: 5, Failed: 0
  • DocCommentHygieneTests: Total: 77, Failed: 0
  • Darling.Tests.csproj and Lite.Tests.csproj both build with EnableWindowsTargeting=true: 0
    warnings-as-relevant / 0 errors on both.

The RED against dev's pre-fix code is compile-only (GetReadLatencyLiveTests calls a tool that does not
exist there); the mutation above is the runtime proof that the live pin actually exercises the summed
histogram, not just that the tool compiles and runs.

CHANGELOG entry

SECTION: Added
ENTRY:

… name the web and MCP store connections

Adds get_read_latency on web and MCP, reading collect.read_latency's
hourly histograms: per (surface, route), summed run_count/total_ms,
MAX max_ms, element-wise summed bucket_counts, and the timeout run
count, with p50/p95/p99 computed from the summed histogram as bucket
upper-bound estimates. Sorted p95 desc.

Also sets ApplicationName (PerformanceMonitorDarling-Web /
PerformanceMonitorDarling-Mcp) on the web and MCP store connections,
both the managed-mode role connection strings and the compose-store
role connection strings, so each surface's pool names itself in the
store's pg_stat_activity.

Refs #4442
…dow, ApplicationName

Adds GetReadLatencyLiveTests: a two-hour field fixture with hand-computed
p50/p95/p99, count, mean, max and timeouts for a fast route and a route
with a slow tail plus two timeout rows, asserted through the tool's own
call path so the sort order (worst p95 first) is pinned too; surface and
route filter pins; the honest-empty-window pin; and an ApplicationName
pin that opens the web and MCP store connections through the product's
own DarlingStoreLogins.BuildComposeStoreRoleConnectionString builder and
checks pg_stat_activity.

Fixes two real bugs the fixture surfaced in DarlingReadLatencyReader:
a route with zero timeout rows returned NULL instead of 0 for timeouts
(a FILTERed sum with no matching rows is NULL, not 0), and the bucket
sum's result was numeric (Postgres sum() over bigint), which failed to
cast to long[] on every read with more than one flushed row. Both are
now explicit casts/coalesces in the read SQL.

Refs #4442
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant