Skip to content

fix(subscriptions): emit commit diagnostic on the worker thread to stop a _positions data race#552

Open
alexeyzimarev wants to merge 1 commit into
devfrom
fix/checkpoint-commit-positions-race
Open

fix(subscriptions): emit commit diagnostic on the worker thread to stop a _positions data race#552
alexeyzimarev wants to merge 1 commit into
devfrom
fix/checkpoint-commit-positions-race

Conversation

@alexeyzimarev

Copy link
Copy Markdown
Contributor

Problem

CheckpointCommitHandler.Commit builds the commit diagnostic on the ACK caller's thread and reads _positions.Min there:

public ValueTask Commit(CommitPosition position, CancellationToken cancellationToken) {
    if (Diagnostic.IsEnabled(CommitOperation))
        Diagnostic.Write(CommitOperation, new CommitEvent(_subscriptionId, position, _positions.Min)); // ← caller-thread read
    ...
}

_positions (CommitPositionSequence : SortedSet<CommitPosition>) is not thread-safe and is otherwise confined to the single commit-worker thread (ProcessUnionWith/RemoveWhere). The caller-thread _positions.Min read therefore races the worker's mutations. SortedSet.Min walks .Left pointers that RemoveWhere transiently nulls during red-black-tree rebalancing, so the read can throw NullReferenceException out of the ack path → Dropped(SubscriptionError) → resubscribe that never resumes committing → the subscription wedges with the checkpoint frozen and no self-recovery.

The race only surfaces when a subscription diagnostic listener is attached (Diagnostic.IsEnabled("Commit") is true), i.e. when the app calls AddEventuousSubscriptions() — which is why it hit a production app but never the test suite. #540 guarded the null CheckpointCommitHandler on this path but not this cross-thread _positions access.

Reproduced in isolation: one thread doing UnionWith+RemoveWhere on a SortedSet while others read .Min throws NullReferenceException within ~1s. (Insert-only UnionWith does not — it's the removal-driven rebalancing near Min that does it, matching the worker's commit-trim.)

Fix

Move the commit-diagnostic emission from Commit (ack caller thread) into the worker's Process loop, where _positions is owned and read safely. It reads Max (latest received ≈ "last processed", used by the gap metric) and Min (FirstPending, used by the pending-checkpoints gauge). Commit no longer touches _positions.

Telemetry is preserved — both SubscriptionMetrics consumers (checkpoint queue length / pending gauge via Record(), and GapCount/GapTime via GetLastCommitPosition/GetLastTimestamp) are still fed equivalent values. Emission is now per processed batch on the worker, so it also fires during a commit stall, keeping the backlog gauge fresh.

Test

Adds CheckpointCommitHandlerConcurrencyTests: a deterministic regression test asserting the commit diagnostic is not emitted on the caller thread. Commit is invoked from a dedicated Thread (whose ManagedThreadId is never a thread-pool id, so the comparison can't collide under load). RED before the fix (emitted synchronously in Commit), GREEN after (emitted on the worker). The full Eventuous.Tests.Subscriptions suite (32 tests) stays green.

🤖 Generated with Claude Code

…op a _positions data race

CheckpointCommitHandler.Commit built the commit diagnostic on the ack
caller's thread and read _positions.Min there, while the commit worker
thread mutates the same non-thread-safe SortedSet (UnionWith/RemoveWhere).
SortedSet.Min walks .Left pointers that RemoveWhere transiently nulls
during red-black-tree rebalancing, so the read can throw
NullReferenceException out of the ack path -> Dropped(SubscriptionError)
-> resubscribe that never resumes committing -> the subscription wedges
with the checkpoint frozen and no self-recovery.

The race only surfaces when a subscription diagnostic listener is attached
(Diagnostic.IsEnabled("Commit") is true), which is why it hit an app using
AddEventuousSubscriptions() but never the test suite. #540 guarded the
null CheckpointCommitHandler but not this cross-thread _positions read.

Move the diagnostic emission into the worker's Process loop, where
_positions is owned and read safely, reading Max (last processed, for the
gap metric) and Min (FirstPending, for the pending-checkpoints gauge).
Commit no longer touches _positions. Telemetry is preserved.

Adds a deterministic regression test asserting the commit diagnostic is
not emitted on the caller thread (Commit invoked from a dedicated Thread
so the thread-id comparison cannot collide with a pool thread under load).

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
@qodo-free-for-open-source-projects

Copy link
Copy Markdown
Contributor

PR Summary by Qodo

Fix checkpoint commit diagnostics to avoid cross-thread _positions race

🐞 Bug fix 🧪 Tests 🕐 20-40 Minutes

Grey Divider

AI Description

• Move commit diagnostic emission onto the commit worker thread to avoid SortedSet data races.
• Ensure ack-thread Commit() never reads worker-owned _positions.
• Add a regression test asserting diagnostics are not emitted on the caller thread.
Diagram

graph TD
  Ack(("ACK caller thread")) --> Commit["CheckpointCommitHandler.Commit()"] --> Worker["Commit worker Process"] --> Positions["_positions (SortedSet)"] --> Internal["CommitInternal()"] --> Store[("Checkpoint store")]
  Worker --> Diag["DiagnosticSource (Commit)"]
  subgraph Legend
    direction LR
    _thr(("Thread")) ~~~ _cmp["Component"] ~~~ _db[("Store")]
  end
Loading
High-Level Assessment

The following are alternative approaches to this PR:

1. Lock around _positions reads/writes
  • ➕ Minimal behavioral change; keep emitting diagnostic from Commit()
  • ➖ Adds contention to a hot path and complicates the single-thread ownership model
  • ➖ Risk of lock ordering issues if future code adds more shared state
2. Maintain worker-updated Min/Max snapshots
  • ➕ Commit() could emit diagnostics without touching SortedSet
  • ➕ Avoids locking the whole set
  • ➖ Introduces extra state and synchronization requirements (volatile/Interlocked)
  • ➖ Snapshots can become stale or inconsistent if not carefully updated
3. Replace SortedSet with a thread-safe ordered structure
  • ➕ Eliminates the immediate data-race class of issues
  • ➖ No simple built-in equivalent; likely requires custom implementation or different algorithm
  • ➖ Higher complexity and performance risk vs. preserving single-thread ownership

Recommendation: Keep the PR’s approach: emitting diagnostics inside the worker Process loop is the simplest and safest fix because it preserves the existing single-thread ownership of _positions and avoids adding locking/snapshot complexity. It also aligns diagnostic emission with the code that mutates/trims the set, preventing the production wedge triggered by cross-thread SortedSet.Min reads.

Files changed (2) +76 / -2

Bug fix (1) +11 / -2
CheckpointCommitHandler.csEmit commit diagnostics in worker Process; remove _positions access from Commit() +11/-2

Emit commit diagnostics in worker Process; remove _positions access from Commit()

• Moves DiagnosticSource Commit event emission into the worker-thread Process loop after _positions is updated, ensuring Min/Max are read only where the SortedSet is owned. Removes diagnostic emission from Commit() and documents the concurrency rationale (AI-1329), preventing ack-thread races with UnionWith/RemoveWhere.

src/Core/src/Eventuous.Subscriptions/Checkpoints/CheckpointCommitHandler.cs

Tests (1) +65 / -0
CheckpointCommitHandlerConcurrencyTests.csAdd deterministic regression test for diagnostic emission thread +65/-0

Add deterministic regression test for diagnostic emission thread

• Adds a test listener that captures the thread ID where the commit diagnostic is emitted and asserts it differs from a dedicated caller thread that invokes Commit(). This guards against reintroducing cross-thread _positions reads when diagnostics are enabled.

src/Core/test/Eventuous.Tests.Subscriptions/CheckpointCommitHandlerConcurrencyTests.cs

@qodo-free-for-open-source-projects

Copy link
Copy Markdown
Contributor

Code Review by Qodo

🐞 Bugs (1) 📘 Rule violations (1) 📜 Skill insights (0)

Grey Divider


Remediation recommended

1. Blocking GetResult() in test 📘 Rule violation ☼ Reliability
Description
The new concurrency test blocks on handler.Commit(...).AsTask().GetAwaiter().GetResult() which
violates the repo guidance to avoid blocking waits in async flows. Even though it’s test code, this
can hide deadlocks/hangs and conflicts with the async/.NoContext() convention.
Code

src/Core/test/Eventuous.Tests.Subscriptions/CheckpointCommitHandlerConcurrencyTests.cs[R51-54]

+        var caller = new Thread(() => {
+            callerThreadId = Environment.CurrentManagedThreadId;
+            handler.Commit(new CommitPosition(0, 0, DateTime.UtcNow), ct).AsTask().GetAwaiter().GetResult();
+        }) { IsBackground = true };
Evidence
PR Compliance ID 1 forbids introducing blocking waits in async flows. The added test thread
synchronously blocks on Commit(...).AsTask().GetAwaiter().GetResult(), which is a sync-over-async
pattern.

CLAUDE.md: All I/O APIs Must Be Asynchronous and Use .NoContext() for ConfigureAwait(false)
src/Core/test/Eventuous.Tests.Subscriptions/CheckpointCommitHandlerConcurrencyTests.cs[51-54]

Agent prompt
The issue below was found during a code review. Follow the provided context and guidance below and implement a solution

## Issue description
`CheckpointCommitHandlerConcurrencyTests` blocks on an async operation via `GetAwaiter().GetResult()`, which conflicts with the repository’s async-first convention.

## Issue Context
This code is in a test, but blocking waits can still create brittle hangs/deadlock-like behavior and violates the compliance guidance to avoid sync-over-async.

## Fix Focus Areas
- src/Core/test/Eventuous.Tests.Subscriptions/CheckpointCommitHandlerConcurrencyTests.cs[51-54]

ⓘ Copy this prompt and use it to remediate the issue with your preferred AI generation tools


2. Metrics can go stale 🐞 Bug ◔ Observability
Description
SubscriptionMetrics derives gap/time and pending-checkpoints from CommitEvent diagnostics, but
diagnostics now emit only from the single commit-worker Process loop. If the worker is blocked
awaiting CommitInternal (e.g., slow checkpoint store), ACKs can keep calling Commit and enqueueing
positions while no new CommitEvent is emitted, causing metrics to lag/freeze and misrepresent
backlog and processing lag.
Code

src/Core/src/Eventuous.Subscriptions/Checkpoints/CheckpointCommitHandler.cs[R72-74]

+            if (Diagnostic.IsEnabled(CommitOperation))
+                Diagnostic.Write(CommitOperation, new CommitEvent(_subscriptionId, _positions.Max, _positions.Min));
+
Evidence
The diagnostic event is now emitted only inside the worker-thread Process() loop and is no longer
emitted in Commit() (ACK path). SubscriptionMetrics computes the gap gauges and pending
checkpoint gauge solely from CheckpointCommitMetrics, which only records CommitEvent from that
diagnostic source. Because the batched worker runs with concurrencyLevel=1 on a single Task.Run
loop, if CommitInternal blocks, the worker cannot read more batches and therefore cannot emit new
diagnostics, making these metrics stale even while ACKs continue writing to the channel.

src/Core/src/Eventuous.Subscriptions/Checkpoints/CheckpointCommitHandler.cs[55-80]
src/Core/src/Eventuous.Subscriptions/Checkpoints/CheckpointCommitHandler.cs[89-96]
src/Core/src/Eventuous.Subscriptions/Diagnostics/CheckpointCommitMetrics.cs[12-37]
src/Core/src/Eventuous.Subscriptions/Diagnostics/SubscriptionMetrics.cs[44-63]
src/Core/src/Eventuous.Subscriptions/Diagnostics/SubscriptionMetrics.cs[109-120]
src/Core/src/Eventuous.Subscriptions/Channels/ChannelWorkers.cs[17-18]
src/Core/src/Eventuous.Subscriptions/Channels/ChannelWorkerBase.cs[21-25]
src/Core/src/Eventuous.Subscriptions/EventSubscriptionWithCheckpoint.cs[91-108]

Agent prompt
The issue below was found during a code review. Follow the provided context and guidance below and implement a solution

### Issue description
`SubscriptionMetrics` uses `CheckpointCommitMetrics`, which only updates on `CheckpointCommitHandler`'s `CommitOperation` diagnostic events. This PR moved `Diagnostic.Write("Commit", ...)` from `Commit()` (ACK caller thread) to the worker-thread `Process()` loop. Because the worker is single-threaded and awaits checkpoint-store I/O in `CommitInternal`, diagnostics (and thus metrics) can stop updating while ACKs continue enqueueing positions.

### Issue Context
This change fixes a real data race, but it also changes telemetry semantics: metrics now reflect *worker ingestion/progress*, not *ACK/processing progress*, and can appear frozen during slow checkpoint commits.

### Fix Focus Areas
- src/Core/src/Eventuous.Subscriptions/Checkpoints/CheckpointCommitHandler.cs[64-96]
- src/Core/src/Eventuous.Subscriptions/Diagnostics/CheckpointCommitMetrics.cs[12-37]
- src/Core/src/Eventuous.Subscriptions/Diagnostics/SubscriptionMetrics.cs[44-63]

### Suggested fix approach
Choose one (or combine):
1) **Keep ACK-path diagnostic emission without `_positions` access**
  - Have the worker maintain a thread-safe snapshot (e.g., boxed `CommitPosition?` or an atomic `ulong firstPendingSequence`) updated inside `Process()` / after `RemoveWhere`.
  - In `Commit()`, emit the diagnostic with `CommitPosition = position` and `FirstPending = snapshot` (no `SortedSet` reads on caller thread).
2) **Split diagnostics**
  - Emit a lightweight “ACK received” diagnostic from `Commit()` (no `_positions`), and a separate “pending range” diagnostic from `Process()`.
  - Update `CheckpointCommitMetrics` to use the ACK diagnostic for gap/time, and the worker diagnostic for pending-checkpoints.
3) **If the new semantics are intended**, update metric descriptions/documentation so `gap` and `time lag` explicitly reflect commit-worker progress rather than last processed/acked event.

ⓘ Copy this prompt and use it to remediate the issue with your preferred AI generation tools


Grey Divider

Qodo Logo

Comment on lines +51 to +54
var caller = new Thread(() => {
callerThreadId = Environment.CurrentManagedThreadId;
handler.Commit(new CommitPosition(0, 0, DateTime.UtcNow), ct).AsTask().GetAwaiter().GetResult();
}) { IsBackground = true };

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Remediation recommended

1. Blocking getresult() in test 📘 Rule violation ☼ Reliability

The new concurrency test blocks on handler.Commit(...).AsTask().GetAwaiter().GetResult() which
violates the repo guidance to avoid blocking waits in async flows. Even though it’s test code, this
can hide deadlocks/hangs and conflicts with the async/.NoContext() convention.
Agent Prompt
## Issue description
`CheckpointCommitHandlerConcurrencyTests` blocks on an async operation via `GetAwaiter().GetResult()`, which conflicts with the repository’s async-first convention.

## Issue Context
This code is in a test, but blocking waits can still create brittle hangs/deadlock-like behavior and violates the compliance guidance to avoid sync-over-async.

## Fix Focus Areas
- src/Core/test/Eventuous.Tests.Subscriptions/CheckpointCommitHandlerConcurrencyTests.cs[51-54]

ⓘ Copy this prompt and use it to remediate the issue with your preferred AI generation tools

Comment on lines +72 to +74
if (Diagnostic.IsEnabled(CommitOperation))
Diagnostic.Write(CommitOperation, new CommitEvent(_subscriptionId, _positions.Max, _positions.Min));

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Remediation recommended

2. Metrics can go stale 🐞 Bug ◔ Observability

SubscriptionMetrics derives gap/time and pending-checkpoints from CommitEvent diagnostics, but
diagnostics now emit only from the single commit-worker Process loop. If the worker is blocked
awaiting CommitInternal (e.g., slow checkpoint store), ACKs can keep calling Commit and enqueueing
positions while no new CommitEvent is emitted, causing metrics to lag/freeze and misrepresent
backlog and processing lag.
Agent Prompt
### Issue description
`SubscriptionMetrics` uses `CheckpointCommitMetrics`, which only updates on `CheckpointCommitHandler`'s `CommitOperation` diagnostic events. This PR moved `Diagnostic.Write("Commit", ...)` from `Commit()` (ACK caller thread) to the worker-thread `Process()` loop. Because the worker is single-threaded and awaits checkpoint-store I/O in `CommitInternal`, diagnostics (and thus metrics) can stop updating while ACKs continue enqueueing positions.

### Issue Context
This change fixes a real data race, but it also changes telemetry semantics: metrics now reflect *worker ingestion/progress*, not *ACK/processing progress*, and can appear frozen during slow checkpoint commits.

### Fix Focus Areas
- src/Core/src/Eventuous.Subscriptions/Checkpoints/CheckpointCommitHandler.cs[64-96]
- src/Core/src/Eventuous.Subscriptions/Diagnostics/CheckpointCommitMetrics.cs[12-37]
- src/Core/src/Eventuous.Subscriptions/Diagnostics/SubscriptionMetrics.cs[44-63]

### Suggested fix approach
Choose one (or combine):
1) **Keep ACK-path diagnostic emission without `_positions` access**
   - Have the worker maintain a thread-safe snapshot (e.g., boxed `CommitPosition?` or an atomic `ulong firstPendingSequence`) updated inside `Process()` / after `RemoveWhere`.
   - In `Commit()`, emit the diagnostic with `CommitPosition = position` and `FirstPending = snapshot` (no `SortedSet` reads on caller thread).
2) **Split diagnostics**
   - Emit a lightweight “ACK received” diagnostic from `Commit()` (no `_positions`), and a separate “pending range” diagnostic from `Process()`.
   - Update `CheckpointCommitMetrics` to use the ACK diagnostic for gap/time, and the worker diagnostic for pending-checkpoints.
3) **If the new semantics are intended**, update metric descriptions/documentation so `gap` and `time lag` explicitly reflect commit-worker progress rather than last processed/acked event.

ⓘ Copy this prompt and use it to remediate the issue with your preferred AI generation tools

@github-actions

Copy link
Copy Markdown

Test Results

0 files   -  22  0 suites   - 22   0s ⏱️ - 12m 43s
0 tests  - 352  0 ✅  - 352  0 💤 ±0  0 ❌ ±0 
0 runs   - 363  0 ✅  - 363  0 💤 ±0  0 ❌ ±0 

Results for commit 0019676. ± Comparison against base commit c7ed4f4.

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