fix(daemon): never run family side effects inline on the trace ingest worker by svarlamov-git-ai · Pull Request #2255 · git-ai-project/git-ai

svarlamov-git-ai · 2026-08-30T23:47:39Z

Problem

On v1.6.24, git write ops in a large monorepo intermittently degrade severely (73s checkout with ~47s of waiting; multi-minute hangs resolved instantly by killing the daemon), and the daemon's checkpoint ingress stops being admitted: checkpoints are logged "received into bounded ingress" but no admission or processing follows (seq 77–84 in the report), against a healthy baseline of receipt_to_admission_ms=0..123.

Root cause

The serial trace-ingest worker executed family side-effect passes inline:

apply_trace_payload_to_state → replace_pending_root_entry / append_ready_command_entry took the per-family side_effect_exec_lock and ran drain_ready_family_sequencer_entries_locked in place — i.e. the full write-op side-effect pipeline (post-commit authorship, rewrite-note migration, working-log migration: unbounded-duration git work, ~90s per write op at monorepo scale per the issue's harness) ran on the ingest worker.
The non-sequencer Applied branch of ingest_trace_payload_fast ran maybe_apply_side_effects_for_applied_command inline as well.

While one family ground, processed_trace_ingest_seq froze. Checkpoint admission (prepare_checkpoint_admission) waits on that watermark (wait_for_trace_ingest_seq(trace_ingest_target)), so admission stalled for every repository family, exactly matching the report:

seq 77–84 received but never admitted;
queued trace payloads backing up (queued_payloads=245, processing_stalled=true);
socket-health restarts deferred "while accepted checkpoints remain" — the deferral was waiting on the very checkpoints the stall blocked, producing the observed restart churn (three daemon replacements in 13 minutes).

Fix

Trace ingestion is now sequencing-only:

replace_pending_root_entry and append_ready_command_entry are constant-time sequencer-map mutations — no exec lock, no inline drain.
Drains run on detached tasks (schedule_family_drain / schedule_ready_family_drains_after_root_cleared), still strictly serialized per family by the existing side_effect_exec_lock, and still gated by the existing unadmitted_checkpoints == 0 / open-root fences, so ordering semantics are unchanged.
Side effects of commands that do not participate in the sequencer (git am, filter-branch, …) are sequenced too, as FamilySequencerEntry::AppliedSideEffects entries ordered by the command's start time, so they keep the exact per-family ordering the inline worker used to guarantee (and can no longer overlap a same-family drain, closing a pre-existing window). Commit-time file-timestamp snapshots still start on the worker before the entry is queued.

Because these passes were previously covered by the ingest watermark, three guarantees are restored explicitly:

Bounded concurrency: side-effect passes do blocking git work on the 4-thread daemon runtime; with detached drains, simultaneously grinding families could otherwise occupy every worker and starve the runtime. Command/applied passes are bounded by a dedicated 2-permit command_side_effect_semaphore; checkpoint side effects keep their own existing semaphore (they run on the blocking pool via spawn_blocking, so long command passes can never starve checkpoint processing). Lock ordering is uniform — family exec lock, then permit — so a permit holder never waits on another family's exec lock and no deadlock is possible.
sync.family now drains every family's ready entries and waits for in-flight detached passes globally (inflight_effects_by_family, registered on the worker before the watermark advances). Side effects can write into other repositories — git push <path> pushes authorship notes into the destination repo — and before detachment the global watermark implied all already-ingested passes had completed, which the notes-sync regression suite depends on (this is what the first CI round caught). Entries fail-closed behind a still-open trace root stay queued without blocking the fence, exactly as pre-change, so sync still does not hang on another repo's in-flight interactive command.
Graceful shutdown (drain_accepted_checkpoints) also fences on in-flight effects, so the shutdown response cannot be sent — and the process cannot exit — while a detached pass is mid-write on entries it already popped from the sequencer.
In-flight registrations are RAII (FamilyEffectGuard), created before entries are popped from the sequencer and released on every exit path (early returns, panics, dropped tasks) after all completion bookkeeping — so the fences can neither miss an imminent pass nor be left blocked by a failed one. The update/uptime restart paths defer while a pass is executing, like graceful shutdown.

Tests (TDD — each failed before the corresponding change)

All grind tests gate on a daemon-side signal (the delay hook logs test side-effect delay started when the pass begins executing) instead of fixed sleeps, so loaded runners can't make them pass vacuously or fail spuriously.

family_side_effect_grind_does_not_stall_independent_checkpoint_admission — a 10s side-effect grind in one family (existing GIT_AI_TEST_DELAY_SIDE_EFFECT_MS_FOR_COMMAND hook); a checkpoint for an independent family must be admitted and processed well before the grind ends. On main it stays unadmitted for the whole grind.
checkpoint_admission_proceeds_while_same_family_side_effects_grind — the headline symptom: "received into bounded ingress" must be followed by "prepared for family admission" while the same family's side effects are still running; on main the admission line never appears until the grind completes.
sync_family_waits_for_detached_non_sequencer_side_effects — sync.family must not return while a detached git am pass is in flight.
sync_family_covers_cross_repo_side_effects_of_other_families — deterministic repro of the notes-sync CI failure: sync.family on a push destination must not return before the push side-effect pass finishes pushing authorship notes into it.
graceful_shutdown_waits_for_detached_side_effect_passes — graceful shutdown must not complete while a detached command pass is still running.

svarlamov-git-ai · 2026-08-31T15:32:25Z

        }

-        let _ = self.begin_family_effect(family);
+        let _family_effect = self.begin_family_effect_guarded(family);


[P1] Race: entries are popped from the sequencer before the family effect is registered, so the completion fences can miss an in-flight pass

In drain_ready_family_sequencer_entries_locked, ready entries are removed under the family_sequencers_by_family mutex (released at the end of the pop block), and only then does begin_family_effect_guarded(family) register the pass under the separate inflight_effects_by_family mutex. Between the two lock scopes the drain task holds only the family exec lock — which no waiter touches for this family, because drain_all_ready_family_sequencers filters to families with non-empty entries.

Interleaving (threads, no await needed):

Detached drain pops the entries (sequencer now empty), is preempted before begin_family_effect_guarded.

sync.family loop runs: drain_all_ready_family_sequencers skips the family (empty), unadmitted_checkpoints == 0, has_inflight_family_effects() false → breaks and returns status before the pass (working-log write / post-commit authorship) runs.

Same window in drain_accepted_checkpoints (graceful shutdown): for ReadyCommand entries the ingress quota is 0, so shutdown returns Ok and process exit kills the pass mid-write — exactly the hazard the comment at the shutdown check describes. (Checkpoint entries are still covered there by the ingress-quota reservation; ReadyCommand entries are not. has_pending_daemon_work is exposed the same way.)

This violates the invariant stated on has_inflight_family_effects ("passes register via begin_family_effect before the trace ingest watermark advances") — true for the non-sequencer fast path, but the sequencer drain registers only after popping.

Fix: register the guard before popping (or inside the same critical section), and drop it early when ready ends up empty.

Fixed: drain_ready_family_sequencer_entries_locked now creates the RAII effect registration before popping entries, so the fences can never observe an empty sequencer with no registered pass while popped entries await execution.

svarlamov-git-ai · 2026-08-31T15:32:46Z

-                            "async completion log write failed"
-                        );
-                    }
+                    self.begin_family_effect(&family)?;


[P2] Detached side-effect passes lose per-family ordering that the inline worker used to guarantee

Before this change, Applied-path side effects ran inline on the serial ingest worker and sequencer drains ran inline behind them, so per family every pass completed in exact ingestion order. Now a non-sequencer command's pass (run_detached_side_effects_for_applied_command) and a later command's drain are both detached tasks serialized only by the family exec lock — which provides mutual exclusion, not order. Tokio's AsyncMutex grants by first-poll order, so a later-spawned drain can win; family_entry_blocked_by_prior_open_trace_root cannot help because clear_trace_root_tracking removes the root before the spawn.

Most non-sequencer commands' passes are no-ops, but a non-FF HEAD move by one (e.g. git am --abort after a mid-conflict checkpoint) runs handle_non_fast_forward_rewrite_with_operation + rename_working_log. If a same-family git commit drain wins the race, post_commit_from_working_log_with_recovery_timestamps runs against a base whose working log has not been migrated yet → attributions dropped from the note, and the late rename strands/clobbers the working log. Trigger needs an ingest backlog (both terminal payloads queued together, so the worker goes spawn(A)→spawn(B) without yielding and tokio's LIFO slot favors B) — narrow, but the ordering invariant loss is real and nothing re-establishes it.

Worth either routing Applied passes through the same per-family queue as sequencer entries, or documenting why order-sensitive effects (non-FF rewrites) cannot occur on the Applied path.

Fixed properly: the detached-task path for non-sequencer commands is gone. Their side effects are now sequenced as FamilySequencerEntry::AppliedSideEffects entries, ordered by the command's start time in the same BTreeMap as every other pass, so a git am pass can never be reordered after (or overlap) a later command's drain — the drain executor runs them strictly in order under the exec lock, restoring the inline worker's ordering guarantee.

svarlamov-git-ai · 2026-08-31T15:33:03Z

+            // commands) are invisible to the sequencer map once their
+            // entries are popped; exiting while one is in flight would let
+            // process teardown kill it mid-write (#2252).
+            if self.outstanding_checkpoint_state().0 == 0 && !self.has_inflight_family_effects() {


[P2] Update/uptime restarts are not fenced on in-flight detached passes — only this graceful-shutdown path is

This check correctly keeps ControlRequest::Shutdown from completing while a detached pass is in flight. But daemon_update_check_loop defers restarts only on outstanding_checkpoint_state().0 > 0 (src/daemon.rs ~9345 and ~9369) and then calls request_restart_after_update() / request_restart() → request_shutdown() directly, bypassing drain_accepted_checkpoints. run_daemon's teardown after wait_for_shutdown() never waits on has_inflight_family_effects() either, and spawn_shutdown_deadline_enforcer force-exits (std::process::exit(70)) ~5s after the flag flips.

Scenario: a multi-minute monorepo side-effect pass grinding on a detached task, zero outstanding checkpoints (the normal steady state this PR creates), update becomes ready → restart → pass killed mid working-log/notes write — the exact hazard the comment here names. The exposure existed in kind for inline passes on main, but this PR establishes the fence as the safety mechanism and makes long detached passes the steady state, so the restart paths should defer on has_inflight_family_effects() (and pending sequencer entries) too.

Fixed: both the update-restart and uptime-restart paths now also defer while has_inflight_family_effects(), mirroring the graceful-shutdown fence, so process teardown cannot kill an executing pass mid-write on those paths either.

svarlamov-git-ai · 2026-08-31T15:33:31Z

+                    // running on detached tasks an unbounded number of
+                    // simultaneously grinding families could otherwise occupy
+                    // every worker thread and starve the runtime (#2252).
+                    let _side_effect_permit =


[P2] Two grinding command passes now starve checkpoint processing in every family

Merging the checkpoint semaphore into a single 2-permit side_effect_semaphore means long command passes and checkpoint passes compete for the same two permits. Two simultaneously grinding families (e.g. two monorepo checkouts/commits, each holding a permit for the full pass duration) leave zero permits, so every checkpoint drain in every other family — plus run_detached_side_effects_for_applied_command — blocks for the duration of the shorter grind. On main, checkpoints had two dedicated permits that command work could not consume.

The regression test only exercises one grinding family (one permit stays free); with two grinders its 5s assertion scenario would stall for the grind duration at the processing stage. Since checkpoint passes are short and latency-sensitive while command passes are unbounded, consider keeping a dedicated checkpoint semaphore (or reserving one permit for checkpoint entries) so admission-to-processing latency stays independent of unrelated grinds.

Fixed: the semaphores are split again. Checkpoint side effects keep their own dedicated 2-permit semaphore (they run via spawn_blocking on the blocking pool, so they never contribute to runtime-worker starvation), and command/applied passes get a separate command_side_effect_semaphore (2 permits) that bounds worker-blocking git work. Two grinding command passes can no longer delay checkpoint processing in other families.

svarlamov-git-ai · 2026-08-31T15:33:32Z

+            // exactly as they did pre-detachment.
+            self.drain_all_ready_family_sequencers().await?;
+            if self.unadmitted_checkpoints.load(Ordering::Acquire) == 0
+                && !self.has_inflight_family_effects()


[P3] sync.family can now be extended indefinitely by work that starts after the sync began

The loop exits only when has_inflight_family_effects() is globally false at a sampled instant — there is no snapshot of the effects that existed when the sync started. Every new command in any unrelated repository registers an effect before its watermark advances, so on a machine with continuous multi-repo git activity (CI runners, several agents), each iteration can observe a fresh in-flight pass and the sync never converges until a global quiet moment. Pre-change, only newly arriving checkpoints extended the loop (unadmitted_checkpoints); newly ingested commands did not.

The cross-repo push case justifies waiting on effects that were already in flight, but not on effects registered after the sync's ingest fence passed. A snapshot (e.g. collect the currently registered guard identities/generation counter at loop entry and wait only for those) would preserve the cross-repo guarantee while keeping sync.family bounded.

Acknowledged, leaving as-is: the exit condition only requires a quiescent instant with respect to actively executing passes (bounded at 2 command permits + checkpoint permits — not queued entries, which fail-closed entries never extend), and the pre-change fence had the same shape: wait_for_trace_ingest_processed_through_family re-derives its global watermark target on every iteration, so ongoing multi-repo activity could already extend sync before this PR. sync.family is a control/test API (no production hot path); if fleet telemetry shows sync latency regressions we can snapshot the family set at entry as a follow-up.

svarlamov-git-ai · 2026-08-31T15:33:55Z

+        },
+        Duration::from_secs(30),
+    )
+    .expect("sync.family should succeed");


[P3] Flake risk: sync.family is sent with no settle window after git am, and the fence can miss the not-yet-ingested root

The trace reader decrements root_open_connections when it processes the socket close, after enqueueing the root's final payload. wait_for_trace_ingest_processed_through_family samples its seq target at loop entry, so this interleaving loses the am root: sync samples target M → reader enqueues the am completion payload at seq N > M and processes the close (root no longer open) → sync finishes waiting for M, sees no open roots, and proceeds before the worker processed N — i.e. before the detached pass registered its family effect and before completion_entries_for_command(&repo, "am") can ever be non-empty. The assertion then fails spuriously.

The cross-repo test below sleeps 500ms for exactly this reason ("Let the trace reader enqueue the push root before syncing"); this test sends sync immediately after git am returns. Adding the same settle sleep (or polling until the daemon has ingested the am root) removes the race.

Fixed: the test now polls the daemon log for the new test side-effect delay started line (emitted by the delay hook when the pass actually begins executing) before sending sync.family, so the am root is guaranteed ingested and the pass registered — no settle-window race.

svarlamov-git-ai · 2026-08-31T15:33:56Z

+            }
+        };
+        let _guard = exec_lock.lock().await;
+        let Ok(_side_effect_permit) = self.side_effect_semaphore.acquire().await else {


[P3] Early returns in the detached runner skip append_command_completion_log, which the inline path wrote unconditionally

On main, every Applied command got a completion log entry even when the side-effect result was an error. Here the side_effect_exec_lock error return above and this closed-semaphore return exit before append_command_completion_log (and the self.begin_family_effect(&family)? at the spawn site skips the whole pass the same way). The test-sync barrier (wait_for_daemon_total_completion_count) counts one completion entry per traced top-level command, so an affected command stalls that barrier to its timeout. Reachability is poisoned-lock / closed-semaphore only, but it silently breaks a previously unconditional invariant — cheap to preserve by writing the completion entry with the error before returning.

Mooted by the ordering fix: the detached runner is deleted. Applied passes now execute in the drain executor's AppliedSideEffects arm, which writes append_command_completion_log unconditionally after the pass, exactly like the ReadyCommand arm. The only remaining pre-completion early return is the never-closed semaphore ?, which matches the pre-existing checkpoint-arm behavior.

svarlamov-git-ai · 2026-08-31T15:34:24Z

    }

-    async fn replace_pending_root_entry(
+    fn schedule_family_drain(self: &Arc<Self>, family: String) {


[P3] No coalescing of scheduled drains: tasks pile up on a grinding family's exec lock

Every cleared trace root and every admission batch spawns a fresh detached drain (here and in schedule_all_ready_family_drains), and each spawned task then parks on the target family's AsyncMutex waiter queue (or occupies one of drain_all's two buffer_unordered slots) for the full duration of any in-progress grind. During a long pass with ongoing machine-wide git/checkpoint activity, parked drain tasks accumulate one per event with no dedup, then stampede through draining nothing when the grind ends. The old inline drains had natural backpressure from the serial worker.

A per-family "drain scheduled" flag (cleared when the drain actually runs) would coalesce these into at most one pending drain per family.

Acknowledged, leaving as-is: parked drain tasks are intrusively queued futures (~KB each, no allocation while parked), bounded by the trace-ingest event rate for the grinding family — worst observed backlog in the incident was ~245 payloads. On lock release the first waiter drains everything and the rest no-op in ~1-3µs each. A per-family drain-scheduled flag would add dedup state and a re-check race (drain finished but flag not yet cleared strands an entry) for negligible gain.

svarlamov-git-ai · 2026-08-31T15:34:25Z

+            match futures::FutureExt::catch_unwind(caught).await {
+                Ok(result) => result,
+                Err(panic_payload) => {
+                    let panic_msg = if let Some(message) = panic_payload.downcast_ref::<String>() {


[P4] Fifth copy of the panic-payload message extraction (CLAUDE.md rule 5: reuse)

This downcast_ref::<String> / downcast_ref::<&str> / "unknown panic" block now exists five times in this file (trace ingest worker, checkpoint ingress worker, command drain arm, checkpoint drain arm, and here). Worth extracting a small fn panic_message(payload: &dyn Any) -> String helper and using it at all five sites.

Fixed: extracted panic_payload_message and used it at all five sites (trace ingest worker, checkpoint ingress worker, command arm, applied arm, checkpoint arm).

svarlamov-git-ai · 2026-08-31T15:34:26Z

+        )
+        .unwrap();
+    // Let the trace reader enqueue the push root before syncing.
+    thread::sleep(Duration::from_millis(500));


[P4] Fixed sleeps gate whether these tests exercise the scenario at all

The four grind-based tests rely on fixed settle sleeps (1500ms in the two grind tests, 1000ms before shutdown, 500ms here). On a loaded runner, if ingestion has not reached the delayed pass by then, the grind tests pass vacuously (nothing is grinding when the checkpoint arrives), while the shutdown and cross-repo tests fail spuriously (the shutdown/sync fence has nothing enqueued to wait on, so no completion entry / no pushed note ever appears). Polling for the daemon-side precondition (e.g. the "checkpoint start"/side-effect-entered log line, or ingest progress) instead of sleeping would make the setup deterministic in both directions.

Fixed: all five grind-based tests now gate on the daemon-side precondition — the delay hook logs test side-effect delay started when the pass begins executing, and the tests poll for that line (20s budget) instead of fixed sleeps. A loaded runner can no longer make the grind tests pass vacuously or the fence tests fail spuriously.

devin-ai-integration

Note

This report is out of date. Scroll down for Devin Review's latest report on this PR.

Devin Review found 2 new potential issues.

2 flags not posted on this PR by your GitHub settings — view them in Devin Review. (Configure)

… worker A long write-op side-effect pass (e.g. a large checkout/commit in a monorepo) used to execute inline on the serial trace-ingest worker: apply_trace_payload_to_state took the family exec lock and drained the family sequencer in place, and the non-sequencer Applied branch ran maybe_apply_side_effects_for_applied_command directly. While one family ground through minutes of git work, the processed_trace_ingest_seq watermark froze, so checkpoint admission (which waits on that watermark) stalled for every repository family: checkpoints were "received into bounded ingress" but never admitted, queued trace payloads backed up, and the socket health check tripped processing_stalled restarts that were deferred while the very checkpoints the stall blocked remained outstanding (#2252). Trace ingestion is now sequencing-only: sequencer mutations are constant-time map operations, and drains run on detached tasks that serialize per family via the existing side_effect_exec_lock. Side effects of commands that do not participate in the sequencer (git am, filter-branch, ...) are sequenced too, as AppliedSideEffects entries ordered by command start time, so they keep the per-family ordering the inline worker used to guarantee. Because side-effect passes do blocking git work on the 4-thread daemon runtime, command passes are bounded by a dedicated 2-permit semaphore (checkpoint side effects keep their own: they run on the blocking pool and must not be starved by long command passes), so simultaneously grinding families can never occupy every worker thread. The watermark used to imply side-effect completion, so the fences that relied on it are restored explicitly: in-flight passes register (RAII, before entries are popped) in inflight_effects_by_family; sync.family drains every family's ready entries and waits for in-flight passes (side effects can write into other repositories - a push to an explicit path pushes authorship notes into the destination repo); and graceful shutdown plus the update/uptime restart paths defer while a pass is executing so process teardown cannot kill one mid-write. Entries fail-closed behind a still-open trace root stay queued without blocking any fence, exactly as before. Fixes #2252 Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>

svarlamov-git-ai marked this pull request as ready for review August 30, 2026 23:47

This comment was marked as resolved.

Sign in to view

svarlamov-git-ai force-pushed the fix/2252-decouple-side-effect-drains branch 2 times, most recently from a68bacf to a56e493 Compare August 31, 2026 00:32

svarlamov-git-ai commented Aug 31, 2026

View reviewed changes

svarlamov-git-ai force-pushed the fix/2252-decouple-side-effect-drains branch from a56e493 to 9b9fdf7 Compare August 31, 2026 16:06

devin-ai-integration Bot reviewed Aug 31, 2026

View reviewed changes

Comment thread src/daemon.rs

Comment thread src/daemon.rs Outdated

scouredimage mentioned this pull request Aug 28, 2026

streams: cap JSONL line size and transcript batch bytes #2245

Draft

svarlamov-git-ai force-pushed the fix/2252-decouple-side-effect-drains branch 2 times, most recently from acb2dae to b1cd7bf Compare August 31, 2026 17:17

This comment was marked as resolved.

Sign in to view

svarlamov-git-ai force-pushed the fix/2252-decouple-side-effect-drains branch from b1cd7bf to 7e87137 Compare August 31, 2026 18:17

svarlamov merged commit 7e87137 into main Sep 2, 2026
64 of 67 checks passed

svarlamov deleted the fix/2252-decouple-side-effect-drains branch September 2, 2026 21:02

Uh oh!

Conversation

svarlamov-git-ai commented Aug 30, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Problem

Root cause

Fix

Tests (TDD — each failed before the corresponding change)

Uh oh!

This comment was marked as resolved.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

devin-ai-integration Bot left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

This comment was marked as resolved.

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

svarlamov-git-ai commented Aug 30, 2026 •

edited

Loading

devin-ai-integration Bot left a comment •

edited

Loading