Skip to content

cpu_scheduler_stats no longer stores or reads ambiguous same-instant snapshots (#3936) - #4010

Merged
erikdarlingdata merged 2 commits into
devfrom
fix/3936-cpu-scheduler-collection-time-collision
Sep 23, 2026
Merged

erikdarlingdata merged 2 commits into
devfrom
fix/3936-cpu-scheduler-collection-time-collision

Conversation

@erikdarlingdata

@erikdarlingdata erikdarlingdata commented Sep 23, 2026 •

Copy link
Copy Markdown
Owner

Closes #3936.

Why

cpu_scheduler_stats is written by exactly one query per run (GROUP BY over single-row CROSS JOINed
DMVs, verified: the query cannot itself return more than one row) and every collection_log entry for the
collector reports rows_collected = 1. Yet the store held pairs of rows under one collection_time with
DIFFERENT payload data (e.g. total_current_workers_count 104 vs 27) and consecutive collection_ids.

I ruled out, with code citations, every same-process race that could explain two writes landing on one
timestamp: the SQL query producing >1 row, the on-load pass racing the scheduled sweep (mutually exclusive
by construction, gated on Runtime is null), an operator snapshot_now racing the scheduled sweep (shared
CollectionGate), the three detached collectors overlapping the sequential body (cpu_scheduler_stats
isn't detached), a duplicate dispatch-table entry (there is exactly one), and the store-write reattempt
retrying a failed COPY (which resends the SAME in-memory row, so it can only ever produce byte-identical
duplicates, not the differing payloads seen in the field).

What's left, and what both hosts actually had: collectionTime = DateTime.UtcNow was captured fresh every
run with nothing guaranteeing it differs from the previous run's stamp for the SAME (server, collector) pair
— a retried run, an orphaned body from a config reload, or plain clock-resolution coincidence under load can
all hand two runs the identical instant. Once two rows share one collection_time, every "newest reading"
query in the fleet card, get_cpu_scheduler_pressure, the analysis fact collector, and both viewers picks
between them with a bare ORDER BY collection_time DESC LIMIT 1 — no tiebreak — so which snapshot answers
is undefined and can flip between reads.

What changes

Write side (PerformanceMonitor.Collectors/CollectionTimeClock.cs, new): a small per-process, per
-(server, collector) monotonic clock. DarlingCollectorRunner.RunAsync and
RemoteCollectorService.RunCollectorDefinitionAsync (Lite) now nudge their captured DateTime.UtcNow
forward by the smallest possible amount (one tick = 100ns — immaterial to any rate/delta calculation) when
it would not be strictly later than that same (server, collector) pair's last stamp. This closes the
ambiguity at its source for every one-row-per-run collector sharing this shape, not just this one, with no
store migration.

Read side (9 SQL sites, both hosts): every "latest cpu_scheduler_stats row" query now breaks a
collection_time tie on collection_id DESC — the per-process monotonic counter every row already carries
— instead of leaving it to an undefined LIMIT 1. Trend reads get the same tiebreak ascending, so two
same-instant points plot in a stable order instead of whatever the scan happens to return.

  • Darling: DarlingFleetReader.FleetThreadsSql (fleet card Threads chip), DarlingPlanCacheSchedulerReader .CpuSchedulerPressureSql (get_cpu_scheduler_pressure), ViewerDataService.CpuSchedulerSnapshotSql +
    CpuSchedulerTrendSql (viewer CPU Scheduler tab), ViewerDataService.ServerSummaryThreadsSql (viewer
    overview Threads row), PgFactCollector.RunnableTaskStatsSql (RUNNABLE_TASKS analysis fact).
  • Lite: LocalDataService.CpuScheduler's snapshot + trend SQL (metric grid, and get_cpu_scheduler_pressure
    since Lite's MCP tool reads through the same method), DuckDbFactCollector's twin of the analysis fact.

This makes already-stored duplicate rows (the store keeps them for retention) read deterministically too,
without a migration.

Test plan

  • CollectionTimeClockTests (8 cases, new): the clock returns the input unchanged when it's already
    later than the last stamp, nudges forward by one tick on a collision (and keeps nudging across
    repeated collisions), nudges forward rather than going backwards when the clock appears to regress,
    tracks each (server, collector) key independently, and preserves the caller's DateTimeKind.
  • DarlingMcpPlanCacheSchedulerToolsLivePostgresTests .GetCpuSchedulerPressure_TwoSnapshotsShareOneCollectionTime_ReadsTheNewerByCollectionId (new, live
    Postgres): plants a CRITICAL-shaped row and a NORMAL-shaped row under one collection_time, the
    NORMAL row inserted physically last. Before the fix this failed (get_cpu_scheduler_pressure
    answered NORMAL, not CRITICAL — verified by reverting the tiebreak and rerunning); with the fix it
    deterministically reads CRITICAL from the higher-collection_id row.
  • CpuSchedulerSnapshotCollisionTests .GetCpuSchedulerSnapshotAsync_TwoSnapshotsShareOneCollectionTime_ReadsTheNewerByCollectionId (Lite,
    new): the same scenario against DuckDB. DuckDB's own tie-break for the unfixed query returns the
    FIRST-inserted row (the opposite of Postgres's last-inserted tie-break for the same shape) — the test
    seeds accordingly and fails before the fix (60 expected, 5 actual — verified by reverting and
    rerunning), passes after.
  • Existing pins updated for the new SQL shape: DarlingFleetReaderTests's FleetThreadsSql ordering
    InlineData now expects ORDER BY collection_time DESC, collection_id DESC. Every other existing pin
    on these 9 queries uses Assert.Contains on a prefix substring, so they were unaffected.
  • Targeted classes before/after: DarlingFleetReaderSqlTests, DarlingMcpPlanCacheSchedulerTools*Tests,
    ViewerCpuScheduler*Tests, ViewerOverviewSqlTests, ViewerServerSummaryDisplayTests,
    McpLatestSnapshotStampTests (+ its live-Postgres arm), PgFactCollectorTests,
    CollectionTimeClockTests, CpuSchedulerSnapshotCollisionTests — all green.
  • Full suite once at the end: Darling.Tests (DARLING_TEST_PG set) and Lite.Tests — see totals below.
  • dotnet build both test projects: Build succeeded, 0 Warning(s).

Darling.Tests full run: Total 12957, Errors 0, Failed 0, Skipped 29, Time 398.1s.
Lite.Tests full run: Total 5162, Errors 0, Failed 0, Skipped 0, Time 236.9s.

Follow-up commit (coordinator)

  • CollectionTimeClock stepped by one .NET tick (100 ns). PostgreSQL's timestamp and DuckDB's TIMESTAMP keep microseconds and truncate below them, so a nudged run still stored the SAME collection_time, and two instants a few ticks apart were never treated as a collision. It now floors to the microsecond and steps a whole microsecond.
  • New test: two instants inside one microsecond store one microsecond apart. Clock tests 9/9; the CPU-scheduler, collector-runner and fleet classes pass in both SKUs.

🤖 Generated with Claude Code

https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv

erikdarlingdata and others added 2 commits September 23, 2026 04:36
…snapshots (#3936)

Two runs of the same one-row-per-run collector could land on the identical
collection_time (a retried run, an orphaned config-reload body, or plain
clock-resolution coincidence), and every "newest reading" query then picked
between the resulting rows with a bare ORDER BY collection_time DESC LIMIT 1
and no tiebreak.

Write side: DarlingCollectorRunner.RunAsync and
RemoteCollectorService.RunCollectorDefinitionAsync now stamp collection_time
through the new CollectionTimeClock, which nudges the captured instant
forward by the smallest amount needed to stay strictly after that same
(server, collector) pair's last stamp. No store migration.

Read side: the fleet card's Threads chip, get_cpu_scheduler_pressure, the
CPU Scheduler viewer tab and overview, and the RUNNABLE_TASKS analysis fact
(both hosts) now break a collection_time tie on collection_id, so rows
already stored this way also read deterministically.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
… tick (#3936)

PostgreSQL's timestamp and DuckDB's TIMESTAMP keep microseconds and truncate
below them, so a one-tick nudge left two colliding runs on the SAME stored
collection_time, and two instants differing only below a microsecond were
never seen as a collision at all. The clock now floors to the microsecond
and steps a whole microsecond, which makes "strictly after" hold in the
store. New test: two instants inside one microsecond store one microsecond
apart.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01GdmA4ND1wLSqA91ax1m4xv
@erikdarlingdata
erikdarlingdata enabled auto-merge (squash) September 23, 2026 08:39
@erikdarlingdata
erikdarlingdata merged commit 5c30dd5 into dev Sep 23, 2026
16 of 18 checks passed
@erikdarlingdata
erikdarlingdata deleted the fix/3936-cpu-scheduler-collection-time-collision branch September 23, 2026 08:47
erikdarlingdata added a commit that referenced this pull request Sep 23, 2026
…ntries in their sections (#4080)

Adds 42 entries and 42 link refs (#3992, #3995, #3996, #3998, #4001, #4002, #4003, #4007, #4010, #4011, #4013, #4015, #4020, #4022, #4025, #4029, #4030, #4031, #4036, #4038, #4039, #4040, #4044, #4047, #4048, #4049, #4050, #4051, #4055, #4061, #4063, #4064, #4065, #4066, #4067, #4068, #4069, #4070, #4071, #4073, #4074, #4078). Each PR's entry was buffered, and this lands every entry whose PR was merged on origin/dev when it ran.

#3989 left 26 entries under bare 'Changed' and 'Fixed' lines above '### Added'. They move into '### Changed' and '### Fixed', below the new entries, and one blank line stays under [Unreleased].


Claude-Session: https://claude.ai/code/session_01Ua31ugERL5DmhFVRtf6keQ

Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
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