Part of #2874 - #2901
Part of #2874#2901
Conversation
All 193 command sites in PerformanceMonitor.Darling.Viewer set no CommandTimeout and inherited Npgsql's undocumented 30s default. The 193rd is a shape #2874's census cannot match: ViewerDataService.Blocking.cs handed connection.CreateCommand over as a bare method group to PgBlockingPairRowQuery.AppendDmvSnapshotRowsAsync, which constructs the command in another project. It now takes a factory lambda that stamps the deadline. Three budget regimes, each with its own derived constant: - InteractiveReadSeconds = 15 (188 sites). Nothing encloses these reads -- no CancelAfter, no SemaphoreSlim, no request timeout (WinExe/UseWPF hosts no web endpoint) -- so the deadline is itself the budget. Bounded below by 3.01s, the cold cost of the heaviest shipped read (TopQueriesSql over a 30-day custom range) on a V109 TimescaleDB store seeded to production per-server density across the full 30-day retention horizon. Bounded above by a permit rather than a budget: MaxPoolSize = 10, and CorrelatedTimelineLanesControl awaits one Task.WhenAll over exactly ten reads, so one panel can hold every connection while every other panel and the sidebar dots get nothing. - CommandPlaneSeconds = 5 (3 sites). Pinned relationally against the 45s DefaultCommandTimeout poll loop it runs inside. The poll is a single-row primary-key lookup at 3.9ms cold. - ConnectGateSeconds = 10 (2 sites). information_schema and has_table_privilege only, so it does not grow with the store (79ms cold for all 85 schema sentinels). Both probes swallow their own failures, so an overshoot mis-classifies the store silently rather than reporting. Interactive and background-refresh reads are not separable: the timers call the same methods a gesture calls, and the set of reads reached only by the unattended fleet fan-out is empty. An export regime does not exist -- DataGridExport is synchronous and store-unaware. 15 is not StorageCommandDeadlines.McpReadSeconds re-used. It was re-derived: the viewer's worst read is 4.4x slower than the MCP family's, against a permit ten times scarcer, so it lands below 30 rather than at it. Pin is directory-scoped over both construction shapes plus a method-group scan that strips comments and strings. Values are pinned as bands carrying their derivation, not as equalities. Part of #2874
# Conflicts: # CHANGELOG.md
The .Storage pin this one is modelled on uses SearchOption.TopDirectoryOnly, which is fine there but leaves a gap against the claim this pin actually makes: "every command THIS PROJECT creates". A .cs file added under a subdirectory would escape the sweep entirely, and the viewer already carries a Themes/ folder, so subdirectories are not hypothetical. Now AllDirectories, with bin/ and obj/ excluded by path SEGMENT rather than by name match -- that is where the generated .AssemblyInfo.cs and .g.cs land during a CI build and they are not source. Measured on a built tree: 190 source files from 234 enumerated. Proven load-bearing rather than assumed: an untimed command dropped into Themes/ is reported (`2874vProbe.cs:6`), where TopDirectoryOnly saw nothing. Part of #2874
The CHANGELOG entry said "all nine CSV/copy paths". It is ten: ViewerServerTab.CopyExport, JobHistoryTab, ProcedureHistoryWindow, QueryStatsHistoryWindow, ManageServersWindow, QueryStoreHistoryWindow, CollectionLogWindow, WaitDrillDownWindow, AlertsHistoryTab and FinOpsTab. An eleventh grep hit in ViewerAppSettings.cs is a doc comment, not a call. The claim the count supports is unchanged and re-verified: DataGridExport is entirely `public static void` / `public static string` with no async, no Npgsql and no ViewerDataService, so there is no export regime. Part of #2874
# Conflicts: # CHANGELOG.md
|
Reviewed. This is a mechanical, well-verified change — every
One adjacent finding, out of scope for this PR but worth a follow-up issue: |
| await PgBlockingPairRowQuery.AppendDmvSnapshotRowsAsync( | ||
| connection.CreateCommand, rows, serverId, startUtc, endUtc, cancellationToken); | ||
| () => | ||
| { | ||
| var command = connection.CreateCommand(); | ||
| command.CommandTimeout = ViewerCommandDeadlines.InteractiveReadSeconds; | ||
| return command; | ||
| }, | ||
| rows, serverId, startUtc, endUtc, cancellationToken); | ||
|
|
There was a problem hiding this comment.
Nice catch on this method-group handoff — but the same shape (bare connection.CreateCommand passed to PgBlockingPairRowQuery.AppendDmvSnapshotRowsAsync, which builds the command in a different project and never sets CommandTimeout) still exists in two sibling call sites that aren't touched by this PR:
Darling/PerformanceMonitor.Darling.Analysis/PgDrillDownCollector.Blocking.cs:160Darling/PerformanceMonitor.Darling.Analysis/PgFactCollector.Waits.cs:230
Both pass connection.CreateCommand as a bare method group exactly like the pre-fix Viewer code did. I checked whether this is actually a latent hang risk:
- On the scheduled collector path,
context.CancellationTokencomes fromDarlingWorker'sCancelAfter(s_analysisTimeout)(120 s), so a stuck DMV-snapshot read there is bounded — worst case it burns the whole analysis pass instead of the collector's usual 30/60 s budget. - But
AnalysisContext.CancellationTokendefaults toCancellationToken.Nonefor callers that don't plumb one (per its own doc comment, "the fact-inspection paths") — for those callers this command is genuinely unbounded, relying on Npgsql's undocumented 30 s default same as the bug this PR fixes. - Neither existing pin catches it:
ViewerCommandTimeoutTests's new method-group scan is scoped toDarling/PerformanceMonitor.Darling.Vieweronly (ViewerSources()), andFactCollectorCommandTimeoutTests'ss_commandCtorregex only matchesnew NpgsqlCommand(, not.CreateCommandor a bare method-group handoff.
Worth a small follow-up (same factory-lambda fix, or a CommandTimeout set inside AppendDmvSnapshotRowsAsync itself as a shared floor) so this defect class doesn't have two known survivors right after being fixed once. Not a blocker for this PR since its stated scope is the .Viewer group of #2874.
There was a problem hiding this comment.
Confirmed, and it is worse than two — the shape survives in six places repo-wide. But only your two are the same defect, and the distinction matters:
Genuine Npgsql-default inheritors (2). Both of yours, and I verified the mechanism rather than the pattern: PgBlockingPairRowQuery.AppendDmvSnapshotRowsAsync takes Func<NpgsqlCommand> and sets only CommandText on what the factory returns — never CommandTimeout — so a bare method group there inherits the 30 s default exactly as the Viewer site did.
Darling/PerformanceMonitor.Darling.Analysis/PgFactCollector.Waits.cs:231Darling/PerformanceMonitor.Darling.Analysis/PgDrillDownCollector.Blocking.cs:161
That helper's own doc comment says "Three callers share this fetch", which corroborates the census: three Darling-side callers, one of them the Viewer site fixed here, two left.
Same shape, different provider (4) — probably not the same defect. These are DuckDB.NET.Data, not Npgsql, so there is no undocumented 30 s ceiling to inherit and CommandTimeout may not even be honoured:
Lite/Analysis/DuckDbFactCollector.Waits.cs:234Lite/Analysis/DrillDownCollector.Blocking.cs:165Lite/Services/LocalDataService.Blocking.cs:426and:547
I would not sweep those in on this reasoning; whether a DuckDB command wants a deadline at all is a separate question from #2874's, and asserting one would be a pin that cannot fail.
Not fixing either here, deliberately. .Analysis is #2871's group and it has already landed, so re-opening it belongs to that lane rather than to a .Viewer PR — and the better fix is probably not six call sites at all but a shared floor inside AppendDmvSnapshotRowsAsync itself, which is a decision about that helper's contract and wants its own review. Filed with the mechanism, both candidate fixes, and the DuckDB caveat.
Your read on the exposure is also right and worth keeping on the record: the scheduled path is bounded by DarlingWorker's 120 s CancelAfter, so the unbounded case is specifically the callers that leave AnalysisContext.CancellationToken at None. That is the half a fix should target.
On the pin scoping — correct, and intentional. ViewerCommandTimeoutTests globs Darling/PerformanceMonitor.Darling.Viewer only, because a pin that swept another project would go red on a lane that has not agreed to the claim. A repo-wide method-group scan is the right instrument and belongs with whoever takes the fix.
|
Reviewed the mechanical sweep against the actual diff rather than just the PR narrative. Summary: Mechanical correctness — verified, looks solid. Cross-checked every command-construction site in One finding posted inline on Lite parity: not applicable here — this is Npgsql/Postgres-specific plumbing for the Darling Viewer, and Lite's local DuckDB reads have no equivalent connection-pool/network-timeout failure mode this is closing. No parity gap. No correctness, security, or performance issues found in the changed files themselves. |
# Conflicts: # CHANGELOG.md
|
Reviewed. This is a large but almost entirely mechanical PR (193
Lite/Darling parity (informational, not a blocker): No correctness, security, or performance issues found in the actual changes. |
) Second review observation, taken. The scan's class was [,)], which catches a hand-off INLINED as an argument - the only form in the repo today. A hand-off through a local ends in a semicolon: Func<NpgsqlCommand> factory = connection.CreateCommand; and would slip past both argument forms AND s_commandCtor, a method group having no '(' either way. One character closes it. Taken rather than deferred as latent because this entire issue exists because a census regex missed a shape; leaving a KNOWN missed shape in the replacement regex would be the same mistake in miniature. Measured before changing it: the widened class produces zero hits across both .Analysis and .Viewer, the called form CreateCommand() staying excluded by the '('. Proven red by narrowing the class back, which fails the new fixture. The viewer's otherwise identical regex still carries [,)]. Left alone rather than reached into - it is #2901's landed pin and has no live instance either - and noted on the PR so it is not lost. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Nine sites across four regimes inherited Npgsql's undocumented 30 s default. Two of them sit under an enclosing budget that never bounded them, which is the finding worth keeping. BackfillSliceDeadline is 300 s over a Query Store backfill slice, but AbandonableStep ABANDONS rather than cancels: it races the work against a Task.Delay and returns without signalling anything. Measured against a live store rather than reasoned about -- a 20 s statement with CommandTimeout = 0 under a 3 s deadline returned Abandoned at 3.0 s while pg_stat_activity still reported that backend state='active', and the same statement with CommandTimeout = 5 faulted at 5.0 s with the backend gone. The command deadline is the only instrument. With the shipped shape -- no deadline, 300 s budget -- a 40 s statement faulted at 30.0 s with "Exception while reading from stream": the 300 s was never reached. Both backfill reads are unbounded across retention on query_store_stats and both are in erikdarlingdata#2795's production cancellation census -- the candidate-database scan's own form 631 times in one day, the MIN ceiling read's shape-twin MAX 2,092 times at 40,743-50,560 ms cold on 62.5 GB / 19 chunks. The candidate scan's collection_time predicate is inert (a 7-day window against 4-day raw retention), and the MIN cannot be bounded the way erikdarlingdata#2344 and erikdarlingdata#2795 bounded their MAX siblings because it exists to find the OLDEST stored row. So 120 s: above the default rather than below it, 2.4x the measured cold worst, strictly under the abandon threshold so the statement dies before the loop walks away from it. The command plane's 5-minute claim lease turned out to be the wrong instrument to derive against, and that was measured too. Replaying the shipped claim, reaper and report SQL: the reaper marks a still-running command terminal failed and a second worker then finds nothing to claim, because it deliberately does not re-queue to pending -- so there is no double-execution to guard. What it does is misreport, and ReportCommandSql has no status guard, so a late report flips the row failed -> succeeded after a viewer has read the failure. A per-command deadline narrows that rather than closing it, following erikdarlingdata#2888's lock wait and erikdarlingdata#2901's own command plane. 5 s, floored on the 3.9 ms cold erikdarlingdata#2901 measured for the identical single-row config_command shape and capped by the plane's own 5 s poll cadence, on a single-threaded loop whose reaper runs first every tick. The actual-plan resolve is its own regime because its floor exceeds the plane's whole value: none of its three resolvers predicates on collection_time, so each is a LIMIT 1 over every chunk in retention. 45 s is what the command's budget has left after the 120 s re-execution plus the claim and report inside the viewer's 180 s poll. ReadConfigVersionAsync is claimed here rather than with the startup group on this project's own rule -- which token does the site receive, and what re-runs it. It takes the plain stopping token and the sweep re-runs it every 15 s forever, while the other twelve sites in that file run once per process start. 3 s, tighter than the plane despite the same millisecond floor: the read is awaited on the serial sweep thread ahead of every server's launch, so an overrun is fleet-wide collection latency while a failure costs one tick of config-change delay. Pinned by (member, constant) PAIRS rather than by "has a deadline", so a site cross-wired to a neighbouring regime's number fails. The value bands read their premises out of source where the field is private, so raising the sweep interval fails the beacon's band instead of silently invalidating it. One scanner change, found by a fixture: every pin in this sweep matches its value regex over StatementSpanFrom's RAW span, so a comment inside the two-statement window that spells the deadline satisfies the regex and an untimed site reads as clean. Controlled both ways -- the same source reads TIMED over the raw span and as an offender over the stripped one. This pin takes the span from stripped text.
Part of #2874 — the
.Viewergroup. Does not close the tracking issue.Census (corrected)
193 command sites, not 192. The tracking issue's shapes find 192 (191
.CreateCommand(+ 2new NpgsqlCommand(), all of them previously untimed. The 193rd is a shape neither regex can match:ViewerDataService.Blocking.cshandedconnection.CreateCommandover as a bare method group toPgBlockingPairRowQuery.AppendDmvSnapshotRowsAsync, which constructs the command and sets itsCommandTextin a different project. No(follows the name, so the site read as clean while inheriting the default. It now takes a factory lambda that stamps the deadline, and the pin has a second scan for that shape.189
.csfiles and "0 sites setCommandTimeout" both confirmed exactly. The pre-existingCommandTimeouthits in this project are orchestration budgets (DefaultCommandTimeout,ImperativeCommandTimeout), not Npgsql command timeouts.Three regimes, and why only three
.Vieweris a WPFWinExe— no Kestrel, noRequestTimeout, no web endpoint.Interactive and background-refresh reads are not separable. The fleet timer and the per-tab auto-refresh timer call the same
ViewerDataServicemethods a gesture calls (RefreshActiveInnerTabAsyncis the tab-activation method), and the set of reads reached only by the unattended fleet fan-out is empty — all seven are also reached by a gesture or a visible-tab load. Splitting them needs a budget threaded through every call site, not a constant.An export regime does not exist.
PerformanceMonitor.Ui.DataGridExportis synchronous, store-unaware, and iteratesgrid.Items; all ten CSV/copy surfaces format rows a panel load already paid for. There is no Excel export and no bulk report generator.InteractiveReadSeconds = 15CommandPlaneSeconds = 5ConnectGateSeconds = 10Derivations
Interactive — 15 s
Below. Timed against a store stood up by the product's own
PgMigrations.MigrateAsyncat V109 with TimescaleDB, seeded to exact production per-server density (fromget_collector_cost, 2 days × 42 servers: 189,414query_statsrows/server/day) across the collector's full 30-day retention horizon — 5.68 Mquery_statsand 1.98 Mprocedure_statsrows for one server. The heaviest shipped per-server read,TopQueriesSql(dumped from the built assembly, not retyped), cold:30 days is the real ceiling on the window: retention drops the data behind it.
Above — and this is a permit argument, not a budget one. Nothing encloses these reads: zero
CancelAfter, zeroSemaphoreSlim, zero.WaitAsync, zeroTask.WhenAny, and no request timeout. The fournew CancellationTokenSource()are plain cancel-the-previous-plan-load tokens with no delay. So the deadline is the budget — the same finding #2882 and #2888 both made, and the same reason this errs short.What they compete for is the pool:
MaxPoolSize = 10on the managed-derived string (#1566), andCorrelatedTimelineLanesControlawaits oneTask.WhenAllover exactly ten reads — a single panel can hold every permit. While held, the sidebar freshness dots, the alert poll and every other panel get nothing, and read eleven waitsConnectionTimeoutSeconds(default 5) for a slot then throws a connect error, misattributing a slow store to the network. Ten concurrent 30-day reads on that rig measured 24.4–64.1 s, six past the silent default they used to inherit; cutting each at 15 s returns permits sooner in exactly the state that produces the misdiagnosis.Restart cadence pushes the same way without being an achievable ceiling: the per-tab timer floors at 30 s (guarded by
_refreshInFlight), the fleet timer floors at 10 s, andRefreshServerStatusAsync/RefreshStoreSizeAsyncare fired unawaited with no in-flight guard. A deadline under 10 s would fail measured-legitimate 30-day panels, so the cadence is a pressure toward short rather than a bound.Asymmetry, worked out for this surface. Too short: one panel shows an error the user can retry — and the auto-refresh retries it within 30 s unprompted. Too long: the user watches a spinner while a pooled connection is held, which cannot be diagnosed from the UI.
Not a copied 30.
StorageCommandDeadlines.McpReadSeconds = 30was re-derived and rejected: the viewer's worst read is 4.4× slower than the MCP family's 685 ms worst, yet its permit is ten times scarcer and it has a fan-out that can take all ten. A slower read against a scarcer permit lands below 30, not at it.Command plane — 5 s
The only regime with a real enclosing budget:
PollCommandResultAsyncloops untilDefaultCommandTimeout(45 s) orImperativeCommandTimeout(3 min), re-issuing the poll every 400 ms. The poll is a single-row primary-key lookup at 3.9 ms cold / 0.1 ms warm; the enqueue and delete are single-row writes on the same table. Pinned relationally againstDefaultCommandTimeoutrather than against a copied number, so the two can't drift apart.This narrows a real overshoot rather than closing it. The loop checks its budget only between iterations, so with no deadline on the read a hung poll could exceed the 45 s a dialog promises by up to Npgsql's 30 s. It is now bounded at 5 s — but the loop still does not cancel an in-flight read, so the stated budget can still be exceeded by that much.
Connect gate — 10 s
ReadOnlyProbeSqlandStoreSchemaProbeSqlreadinformation_schema/has_table_privilegeonly — no hypertable, no data scan — so they do not grow with the store: all 85 schema sentinels measured 79 ms cold / 49 ms warm. Bounded above by the 60 s ceiling the viewer's own connection-timeout preference is clamped to, since these are the first two statements after connect, run inOnLoadedbefore any timer starts and before the window is usable, with no splash to explain a wait.Its asymmetry is why it is separate: both probes catch their own failures — the schema probe fails open (returns null so a healthy store is never blocked) and the read-only probe fails safe (records read-only). A blown deadline there raises nothing and instead silently mis-classifies the store, hiding every write affordance on a writable one.
The pin
Darling/Darling.Tests/ViewerCommandTimeoutTests.cs, directory-scoped likeStorageCommandTimeoutTestsso a future viewer file is covered the day it appears — but recursively, where that pin usesTopDirectoryOnly. The claim is "every command this project creates", and a.csfile added under a subdirectory would otherwise escape entirely (the viewer already carries aThemes/folder).bin/andobj/are excluded by path segment, since that is where the generated.AssemblyInfo.cs/.g.csland in CI: 190 source files from 234 enumerated on a built tree. Asserts the structural claim (a deadline was SET) over both construction shapes; values are pinned as bands carrying their derivation, not as equalities. Span walker terminates atdepth <= 0— the depth-clamping bug that made two scanners miss real sites during #2888 — and the method-group scan strips comments and strings so the prose explaining the fix cannot fail the build.Proven red six ways, each failing a different assertion (via a
net10.0harness mirroring the pin assertion-for-assertion, reading constants out of the built DLL's metadata, becausenet10.0-windowsxUnit cannot execute on macOS):EveryViewerCommand_SetsAnExplicitDeadline→1 viewer command(s) inherit Npgsql's 30s default …: ViewerDataService.Overview.cs:179NoViewerCommand_IsCreatedByABareMethodGroupHandoff→1 site(s) hand CreateCommand over as a method group …: ViewerDataService.Blocking.cs:380…StaysInsideItsJustifiedBand[ceiling]→30s is not meaningfully under the inherited Npgsql default it replaces…StaysInsideItsJustifiedBand[floor]→3s is at or under the 3.01 s worst measured shipped read…StaysWellInsideItsEnclosingBudget[ceiling]→30s is not comfortably inside the 45s poll-loop budgetThemes/EveryViewerCommand_SetsAnExplicitDeadline→…: 2874vProbe.cs:6— invisible underTopDirectoryOnly, which is what makes the recursion load-bearingThe reflected constant tracked each rebuild (30, 30, 3), so the assembly-not-source check is live rather than decorative.
Verified against the built assembly
Not verified
Darling.Testsbuilds withEnableWindowsTargetingbut cannot execute; CI is the arbiter for the xUnit pin itself.MaxPoolSize = 10and the ten-wideTask.WhenAllin source, not from watching a WPF seat starve.One claim I got wrong and corrected
An earlier revision of this body and the CHANGELOG said "nine CSV/copy paths". It is ten —
WaitDrillDownWindowwas missed. Re-counted directly: ten files callDataGridExport.{CopyCell,CopyRow,CopyAllRows,ExportToCsv}, and an eleventh grep hit inViewerAppSettings.csis a doc comment. The conclusion it supports is unchanged.Scope note
Three regimes shipped as one PR, matching #2888's precedent of five regimes in one PR for one project. Happy to split by regime if you'd rather review them separately.
Out of scope, noticed in passing
CHANGELOG.md's link-reference block already carries three duplicate refs ondev([#2860],[#828],[#887]) — pre-existing, not introduced here, and Define the 38 issue link references the CHANGELOG used but never declared #2889 is rewriting that block anyway.RefreshServerStatusAsyncandRefreshStoreSizeAsyncare fired unawaited from both fleet timers with no in-flight guard, and the Overview tab runs both timers at the same interval, so it issues two concurrent freshness read-pairs per cycle. Bounded by this change but not fixed by it.