If a stale work directory exists, try deleting it. by chrisstaite-menlo · Pull Request #129 · TraceMachina/nativelink

chrisstaite-menlo · 2023-07-04T20:31:12Z

There are times when a job is not cleaned up due to improper shutdown and the work directory still existed from before. This PR tries to clean it up and create a new one if this occurs.

This change is

allada

Reviewed 1 of 3 files at r1, all commit messages.
Reviewable status: 1 of 3 files reviewed, 1 unresolved discussion (waiting on @chrisstaite-menlo)

a discussion (no related file):
I'm looking over the code and I think if this is happening something is very wrong.

Here we delete everything in the root directory on service startup:
https://github.com/allada/turbo-cache/blob/d5468dc3965be32ffffa516f4f302269715288bf/cas/worker/local_worker.rs#L230C13-L230C27

Here, the cleanup is supposed to happen:
https://github.com/allada/turbo-cache/blob/d5468dc3965be32ffffa516f4f302269715288bf/cas/worker/running_actions_manager.rs#L769

Here's where cleanup should be invoked. It should happen always if create_and_add_action() succeeds (which is where you are trying to cleanup before action is invoked, because it calls make_work_directory()):
https://github.com/allada/turbo-cache/blob/d5468dc3965be32ffffa516f4f302269715288bf/cas/worker/local_worker.rs#L151C63-L151C63
I double checked that .then() works with chaining the way it is dealt with:
https://play.rust-lang.org/?version=stable&mode=debug&edition=2021&gist=e07dfac8760d67d6ee386e0d1cb034ec

I'm curious if this might have been as a side-effect of the previous bug you fixed, where the worker would continue running on the node when the scheduler terminated it, then the scheduler sent the same job to the same node after re-connect and it tried to use the same directory?

chrisstaite-menlo · 2023-07-05T07:46:12Z

Previously, allada (Nathan (Blaise) Bruer) wrote…

I'm looking over the code and I think if this is happening something is very wrong.

Here we delete everything in the root directory on service startup:
https://github.com/allada/turbo-cache/blob/d5468dc3965be32ffffa516f4f302269715288bf/cas/worker/local_worker.rs#L230C13-L230C27

Here, the cleanup is supposed to happen:
https://github.com/allada/turbo-cache/blob/d5468dc3965be32ffffa516f4f302269715288bf/cas/worker/running_actions_manager.rs#L769

Here's where cleanup should be invoked. It should happen always if create_and_add_action() succeeds (which is where you are trying to cleanup before action is invoked, because it calls make_work_directory()):
https://github.com/allada/turbo-cache/blob/d5468dc3965be32ffffa516f4f302269715288bf/cas/worker/local_worker.rs#L151C63-L151C63
I double checked that .then() works with chaining the way it is dealt with:
https://play.rust-lang.org/?version=stable&mode=debug&edition=2021&gist=e07dfac8760d67d6ee386e0d1cb034ec

I'm curious if this might have been as a side-effect of the previous bug you fixed, where the worker would continue running on the node when the scheduler terminated it, then the scheduler sent the same job to the same node after re-connect and it tried to use the same directory?

It may well be true that this can't happen any more.

allada · 2023-07-05T14:45:15Z

If you are ok with it, can we hold off on this PR to see if it was fixed by the other PR?

chrisstaite-menlo · 2023-07-05T14:46:33Z

Yeah, makes sense. I've got to get everything else up to date before I can test all of this because we haven't even started on the Goma PRs yet, but happy to leave this open indefinitely.

allada · 2023-07-05T16:03:07Z

I think I found the problem. Here's the scenario:

Scheduler disconnects
https://github.com/allada/turbo-cache/blob/b354b2511eafd0f58625904d0bb6c3d45d353080/cas/worker/local_worker.rs#L356 triggers
kill_action is triggered
kill_action sends the kill message on the message channel then returns
Scheduler reconnects
Same action is received as before
First action is still running, but about to be killed and cleaned up
New action (with same name) is created and fails because folder exists
Old action is now deleted/cleaned, causing even more chaos

What should happen is kill_action should return only when we are certain the action is 100% finished and no all related objects are dropped. Maybe a CondVar or a OneShot channel would fix this.

chrisstaite-menlo · 2023-07-19T11:57:01Z

I've not seen this error with all the other changes, so I'm going to close this off.

chrisstaite-menlo · 2023-09-07T08:30:50Z

[2023-09-07T08:29:17.678Z WARN  simple_scheduler] Internal error for worker 7b2e3f8d-0afb-4774-82e3-cecef835dbf3: Error { code: AlreadyExists, messages: ["File exists (os error 17) : Error creating work directory /root/.cache/turbo-cache/work/f5596fdea33511e1c7f513873c087faee689c6ee024c9d90d2908c351e5b0e83"] }

A worker OOM-d and when it came back it was assigned the same tasks

External-consistency invariant test for TraceMachina#129. Currently RED — the worker sends ExecuteResult first (line 1618-1626 of local_worker.rs), then BlobsAvailable (line 1677), so the server forwards the action result to the client before the locality_map is populated for the action's output digests. This test asserts the post-fix contract: BlobsAvailable arrives at the worker→scheduler stream BEFORE ExecuteResult, so the server's sequential per-stream processing guarantees the locality_map is populated before the client sees the result. Test failure (current code, mock recorded ExecutionResponse first): expect_blobs_available expected BlobsAvailable, got: ExecutionResponse Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>

) External-consistency invariant: by the time the client sees an action's ExecuteResult, every blob the action produced MUST be observable from the server (in CAS or via locality_map peer-fetch). Before this change the worker sent ExecuteResult first, then BlobsAvailable. Both go on the same bidirectional gRPC stream that the server processes in arrival order (worker_api_server.rs:362-402), so the old ordering meant the server forwarded the action result to the client BEFORE the BlobsAvailable was processed and the worker registered as holder for tree-internal file digests. In the race window: - server CAS slow-tier upload is still in-flight (fire-and-forget), - locality_map has no peer registered for tree-internal digests, - Bazel reading any of those digests hits NotFound and (without rewind_lost_inputs in Bazel 9.0.1) cannot recover. The pre-existing partial mitigation (`register_action_result_digests` in worker_api_server.rs:463-503) covers only the TOP-LEVEL digests (output_files, output_directories.tree_digest, stdout, stderr). It does NOT walk into the Tree proto to register the file digests inside output_directories — those only land in the locality_map when BlobsAvailable is processed. So the race window was real and observable for actions with output directories. Fix: reorder the worker's `make_publish_future` so that 1. tree expansion + BlobsAvailable runs FIRST 2. THEN execution_response 3. THEN execution_complete + cache_action_result + spawn_upload_to_remote The latency cost is the local-CAS read for output_directory Tree protos (produced by `inner_upload_results` immediately before, almost always hot in OS cache; no-op for actions without output_directories). Test: `worker_sends_blobs_available_before_execute_result_test` in local_worker_test.rs (committed in bfe31537) asserts BlobsAvailable arrives at the gRPC client mock BEFORE ExecuteResult. With this fix applied the test passes; reverted to the old ordering it fails with "expect_blobs_available expected BlobsAvailable, got: ExecutionResponse". Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>

…ult (consistency) Reorders worker→server messages so the locality_map registration (BlobsAvailable + expand_tree_file_digests) precedes the action's ExecuteResult. Eliminates the race where the server returns an action_result to a Bazel client while the corresponding output blobs have not yet been registered in the locality_map — a downstream worker that asks for those blobs would race-fail before the registrations land. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>

Invariant violated: inner_upload_results blocked the worker slot for p50≈152ms/p99≈720ms (n=140 actions) waiting for outputs to propagate to the remote CAS via FastSlowStore::update_with_whole_file's join!(). Mechanism that violates it: running_actions_manager.rs inner_upload_results (formerly line 3434) always used &*cas_store (full FSS), so every FastSlowStore::update_with_whole_file call executed join!(slow_fut, fast_fut) blocking the worker until the GrpcStore slow-tier ack. Mechanism that re-establishes it after the fix: when deferred_output_uploads_enabled is true, cas_store is set to cas_store.fast_store().clone() (FilesystemStore directly). inner_upload_results writes to local disk only; the remote slow-store upload is deferred to spawn_upload_to_remote after execution_complete frees the worker slot. The dda09ee has()-skip hole is closed by the existing BlobsAvailable locality map + spawn_upload_to_remote batch-has + UploadMissingBlobs backfill + pin_digest anti-eviction machinery (all verified live; see .claude/audits/f2-deferred-output-uploads-design-2026-06-12.md §2.3). Composite invariants this fix interacts with: (I1) ≥2-replica invariant: deferred path satisfies via spawn_upload_to_remote retries + UploadMissingBlobs drain fallback. (I2) BlobsAvailable ordering (TraceMachina#129): unchanged — BlobsAvailable sent after execution_complete, which follows upload_results. (I3) H4 pending-registry (TraceMachina#12): CCS pre-registration unchanged. (I4) Pin lifecycle: outputs pinned immediately in inner_upload_results; unpinned on BIS-ack. Unchanged. (I5) F3 dedup: spawn_upload_to_remote batch-has queries full FSS; under synchronous mode finds blobs in slow store and skips; under deferred mode finds them absent and uploads. No code change needed. (I6) No fsync: FilesystemStore writes are not fsync'd; durability from ZFS pool tank sync=disabled + ≥2-replica invariant. Tests that prove the fix: deferred_upload_enabled_completes_before_slow_store: deferred=true + blocking slow store → upload_results completes within FAST_DEADLINE=10s (slow store blocks forever). Output blob in fast store. Mutation (deferred→false): timeout fires with bespoke "deferred contract violated" message. deferred_upload_disabled_blocks_on_slow_store: deferred=false + blocking slow store → upload_results parks until release. Spawn task + await update_attempts_count > baseline + assert !is_finished() + release + assert completes. Mutation (deferred→true): timeout fires with bespoke "slow store was never entered" message. Behavior changes: nativelink-worker inner_upload_results: when deferred_output_uploads_enabled is false (DEFAULT), behavior is IDENTICAL to prior — full FastSlowStore write, synchronous. No runtime behavior change unless operator explicitly sets the field to true in LocalWorkerConfig. deferred_output_uploads_enabled: false (default-OFF kill-switch). Bench delta: not run (data_plane_bench has zero GrpcStore client cells; the output-upload path is bench-invisible per .claude/rules/data-plane-bench.md). Data from memory: production traces p50=152ms p99=720ms n=140 actions. Do NOT force-push. Do NOT flip default to true. Do NOT deploy. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>

…ch flip Invariant violated: four MUST-FIX / SHOULD-FIX findings from the Tier-3 review cadre (distributed-systems-reviewer + pair-b) must be resolved before the deferred_output_uploads_enabled kill-switch can be safely flipped in production. Mechanism that violates it: (1) missing startup guard permits deferred_output_uploads_enabled=true + cas_server_port=None — a config that makes BlobsAvailable never fire, leaving outputs unroutable during the upload window (reopens dda09ee hole); (2) doc-comment understated the ≥2→≥1 replica regression and omitted hard prerequisites; (3) kill_switches_test.rs was missing the three schema tests promised by the design doc; (4) setup proto writes in the DISABLED test went through the full FSS, injecting background slow-write tasks that complicated the before_count baseline. Mechanism that re-establishes it after the fix: - local_worker.rs: new startup guard returns make_input_err! if deferred_output_uploads_enabled=true AND cas_server_port.is_none(), naming both fields and explaining the BlobsAvailable dependency (#F2). - cas_server.rs: doc-comment now explicitly states ≥2→≥1 replica regression, quantifies the single-copy window (p50≈152ms, p99≈720ms, source cited), names cas_server_port as a HARD PREREQUISITE, and names --remote_retries≥1 as a CLIENT REQUIREMENT for crash-window recovery. - kill_switches_test.rs: three new tests covering default-false / explicit-true / explicit-false for LocalWorkerConfig.deferred_output_uploads_enabled. - running_actions_manager_test.rs: DISABLED test now writes setup protos to fast_store.as_pin() directly, eliminating background FSS slow-write tasks from setup; import order fixed (config before metric per CLAUDE.md). - P4 code comment corrected: registry is populated asynchronously via the detached AC write task (after execution_complete), NOT before execution_response. - Design doc §3 P4, §4 Invariant 1, §2.3 Layer 4, §6, and §9 corrected to match code reality (distsys F2/F5, auditor 7b, latency provenance). Composite invariants this fix interacts with: - ≥2-replica durability: now explicitly documented as regressed to ≥1-replica during the deferred window (design §4 Invariant 1). - BlobsAvailable ordering (TraceMachina#129): startup guard enforces the cas_server_port prerequisite that makes BlobsAvailable fire. - H4 pending-registry (TraceMachina#12): P4 comment and design doc corrected to reflect asynchronous registration timing. - Pin-until-uploaded: design §2.3 Layer 4 now distinguishes eviction pin (held) from budget-guard (dropped immediately, observation-only). Test that proves the fix re-establishes the invariant: - deferred_uploads_without_cas_server_port_is_rejected: startup guard fires with message naming both fields; mutation (guard commented out) fails with bespoke message "guard missing or condition check is wrong (#F2)". - deferred_uploads_with_cas_server_port_passes_guard: guard does not over-reject valid config (enabled=true + port=Some(0)). - local_worker_deferred_uploads_default_false/explicit_true/explicit_false: schema tests guard against accidental field rename/skip. - deferred_upload_disabled_blocks_on_slow_store: now uses fast_store.as_pin() for setup protos; before_count baseline is clean. Behavior changes: - new_local_worker: REJECTS startup if deferred_output_uploads_enabled=true AND cas_server_port=None. All existing production configs have either (a) both OFF (default, no change) or (b) cas_server_port set (valid). No behavior change for any currently deployed worker. - All other changes: documentation and test only; zero runtime behavior change when deferred_output_uploads_enabled=false (the production default). Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>

Invariant violated: the worker control-plane channel holds at most 1 in-flight message, so concurrent action completions (each emitting blobs_available + execution_response + execution_complete) queue behind a 1-slot buffer → head-of-line blocking → tail-latency amplification. Mechanism that violates it: `tokio::sync::mpsc::channel(1)` at `worker_api_client_wrapper.rs:166` (commit 79c9acd, "Single worker stream") was the initial implementation choice with no documented deliberate flow-control intent. Mechanism that re-establishes it after the fix: `channel(WORKER_API_CHANNEL_CAPACITY)` (16 slots) allows up to 5 concurrent completions to queue without blocking the publisher. Over-cap behavior: standard mpsc backpressure (producer awaits). Consumer remains sequential (single UpdateForWorker loop); FIFO ordering is preserved by mpsc semantics. Composite invariants: (1) TraceMachina#129 blobs_available → execution_response FIFO ordering preserved — deepening the buffer does not reorder; mpsc is strictly FIFO. (2) CAPPED AT WORKER_API_CHANNEL_CAPACITY comment added on the struct field per CLAUDE.md unbounded-buffer rule. (3) `WORKER_API_CHANNEL_CAPACITY` exported as `pub const` for numeric-constant auditability per reviewer-dispatch rules. Test: o2_channel_capacity_constant_is_correct (fails with bespoke message on mutation to 1), o2_concurrent_sends_complete_within_capacity_without_consumer (16 FIXED senders into WORKER_API_CHANNEL_CAPACITY-slot channel; mutation to 1 → 15 senders block → timeout with bespoke "depth-1 channel serializes" message, proving the regression is detectable independently of the constant), o2_blobs_available_arrives_before_execution_response (proves TraceMachina#129 FIFO ordering via in-process gRPC server that records arrival order; Arc<Mutex<>> wrapper removed — arrival_rx accessed from one place only). Behavior changes: - worker_api_client_wrapper: mpsc channel capacity 1 → 16. Publisher no longer blocks when 2–16 messages are in-flight and the consumer is momentarily behind. Runtime composition: single bidirectional gRPC stream loop (local_worker.rs UpdateForWorker); backpressure moves from slot 1 to slot 16. No other behavior change. Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>

Invariant violated: a fresh F2-output AC entry is rejected (false-dangling) by CCS's `get_and_verify_single` → `has_with_results` miss → NotFound, forcing Bazel re-execution when the blob is fetchable from the worker via the existing `BlobLocalityMap` locality_map in `WorkerProxyStore`. Mechanism that violates it: `CompletenessCheckingStore::get_part` → `get_and_verify_single` → CAS `has_with_results` reports missing → NotFound (`completeness_checking_store.rs:666–756`). Mechanism that re-establishes the worker-fetch: `disable_completeness_check: true` causes `get_part` to skip all completeness-check machinery and delegate straight to `ac_store` (`completeness_checking_store.rs:845–851`); the downstream `ByteStream::Read` → `WorkerProxyStore::get_part_sequential` → `try_read_from_worker` → `locality_map` → peer-fetch already serves the blob. Composite invariants (all unaffected — CCS is AC-only; CAS path unchanged): §5.1 ≥2-replica: CAS property; unaffected. §5.2 BIS-ack/mark_stable: delegates through to inner AC store; unaffected. §5.3 F2 pin-until-backfill: BIS pipeline unchanged; unaffected. §5.4 Admission/eviction/pin: no pin path runs through CCS; unaffected. §5.5 TraceMachina#129 BlobsAvailable-before-ExecuteResult: CCS-independent; unaffected. Proving tests: `worker_fetch_goal_peer_fetch_succeeds_when_ccs_disabled` (Test A), `ccs_disable_flag_controls_completeness_check` (Test B, both directions), `wps_stale_ac_counter_increments_and_renders_on_final_notfound` (Test C). ## What this commit does 1. **Config** (`nativelink-config/src/stores.rs`): add `disable_completeness_check: bool` (serde default=false, doc-comment, `#[serde(deny_unknown_fields)]` preserved) to `CompletenessCheckingSpec`. 2. **CCS** (`completeness_checking_store.rs`): add `disable_completeness_check` field + `new_with_disable_flag` constructor. When `true`, `get_part` and `has_with_results` skip all check machinery and delegate straight to `ac_store`. `new` and `new_with_pending_registry` default to `false`. All existing tests still pass unmodified. 3. **Factory** (`default_store_factory.rs`): pass `spec.disable_completeness_check` to `new_with_disable_flag`. Default `false` → zero behavior change at MERGE. 4. **Observability** (`worker_proxy_store.rs`): add `wps_cas_and_peer_notfound_total: CounterWithTime` field incremented in `get_part_sequential` at the final-NotFound path (inner CAS + all workers missed). Published as `<key>_wps_cas_and_peer_notfound_total_counter` via `MetricsComponent::publish`. Replaces `ccs_incomplete_entries_counter` as the stale-AC signal for operators during the soak. Placement rationale: this is the exact event that a stale-AC entry causes — Bazel got a cache-hit AR but the blob is genuinely absent. Counter survives any AC-chain topology change (no CCS dependency). The counter also fires on genuine evictions; the soak gives operators a baseline before §8 Q1 TTL work. 5. **Tests** (`nativelink-store/tests/ccs_phase1_kill_switch_test.rs`): - Test A (§7 goal): worker-fetch via locality_map succeeds without CCS. Mutation: clear locality_map → NotFound bespoke msg. - Test B (flag both directions): flag=true serves AC entry with missing blob; flag=false (default) rejects it. Mutation verified. - Test C (observability render): `wps_cas_and_peer_notfound_total_counter` appears in `render_prometheus` output and increments on final-NotFound. Mutation: skip inc() → counter stays 0, assertion fails with bespoke msg. ## Behavior changes - `CompletenessCheckingStore`: no behavior change when `disable_completeness_check` is absent/false (the default). When set to `true` (opt-in), the completeness check is bypassed. Verified safe: CCS is AC-only; CAS chain untouched. - `WorkerProxyStore`: `wps_cas_and_peer_notfound_total` now increments on the final-NotFound path in `get_part_sequential`. This path was previously a silent NotFound; the new counter adds one atomic increment per event. Production CAS chain path: WPS → VerifyStore → FastSlowStore. Counter fires only when BOTH inner and all workers miss; no other behavior change. Bench: exempt (no data-plane hot path change; only new atomic increment on a cold error path + a new bool check on the AC get path behind a branch predictor). Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>

If a stale work directory exists, try deleting it.

ab89ef9

chrisstaite-menlo force-pushed the delete_stale_work_directory branch from bc16ca5 to ab89ef9 Compare July 4, 2023 20:33

allada suggested changes Jul 4, 2023

View reviewed changes

allada mentioned this pull request Jul 5, 2023

Move trivial data access Mutex's to sync Mutex. #133

Merged

chrisstaite-menlo closed this Jul 19, 2023

chrisstaite-menlo mentioned this pull request Sep 7, 2023

If a worker is killed, stale work directories exist #246

Closed

Navigation Menu

Repository navigation

If a stale work directory exists, try deleting it. - #129

If a stale work directory exists, try deleting it.#129
chrisstaite-menlo wants to merge 1 commit into
TraceMachina:masterfrom
chrisstaite-menlo:delete_stale_work_directory

chrisstaite-menlo commented Jul 4, 2023 •

edited by allada

Loading

Uh oh!

allada left a comment

Uh oh!

chrisstaite-menlo commented Jul 5, 2023

Uh oh!

allada commented Jul 5, 2023

Uh oh!

chrisstaite-menlo commented Jul 5, 2023 •

edited

Loading

Uh oh!

allada commented Jul 5, 2023 •

edited

Loading

Uh oh!

chrisstaite-menlo commented Jul 19, 2023

Uh oh!

chrisstaite-menlo commented Sep 7, 2023

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

Conversation

chrisstaite-menlo commented Jul 4, 2023 • edited by allada Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

allada left a comment

Choose a reason for hiding this comment

Uh oh!

chrisstaite-menlo commented Jul 5, 2023

Uh oh!

allada commented Jul 5, 2023

Uh oh!

chrisstaite-menlo commented Jul 5, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

allada commented Jul 5, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

chrisstaite-menlo commented Jul 19, 2023

Uh oh!

chrisstaite-menlo commented Sep 7, 2023

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

chrisstaite-menlo commented Jul 4, 2023 •

edited by allada

Loading

chrisstaite-menlo commented Jul 5, 2023 •

edited

Loading

allada commented Jul 5, 2023 •

edited

Loading