Skip to content

[Bug]: Worker pool permanently deadlocks in RunningActionsManagerImpl::cleanup_action after sustained load, requires manual restart #2672

Open
Open
[Bug]: Worker pool permanently deadlocks in RunningActionsManagerImpl::cleanup_action after sustained load, requires manual restart#2672

Description

@msshapira
msshapira
opened on Aug 7, 2026

Version

1.6.4

Client

Bazel

OS / Architecture

macOS 15.7.3 (24G419), Apple Silicon (ARM64)

Deployment method

Nix

Storage backend

S3

Number of workers

1

Rough size of CAS

No response

Configuration

{
  stores: [
    {
      name: "AC_MAIN_STORE",
      filesystem: {
        content_path: "/tmp/nativelink/data-worker-test/content_path-ac",
        temp_path: "/tmp/nativelink/data-worker-test/tmp_path-ac",
        eviction_policy: {
          // 10gb.
          max_bytes: 10000000000,
        },
      },
    },
    {
      name: "WORKER_FAST_SLOW_STORE",
      fast_slow: {
        // "fast" must be a "filesystem" store because the worker uses it to make
        // hardlinks on disk to a directory where the jobs are running.
        fast: {
          filesystem: {
            content_path: "/tmp/nativelink/data-worker-test/content_path-cas",
            temp_path: "/tmp/nativelink/data-worker-test/tmp_path-cas",
            eviction_policy: {
              // 100gb.
              max_bytes: 100000000000,
            },
          },
        },
        slow: {
          /// Discard data.
          /// This example usage has the CAS and the Worker live in the same place,
          /// so they share the same underlying CAS. Since workers require a fast_slow
          /// store, we use the fast store as our primary data store, and the slow store
          /// is just a noop, since there's no shared storage in this config.
          noop: {},
        },
      },
    },
  ],
  schedulers: [
    {
      name: "MAIN_SCHEDULER",
      simple: {
        supported_platform_properties: {
          cpu_count: "minimum",
          memory_kb: "minimum",
          network_kbps: "minimum",
          disk_read_iops: "minimum",
          disk_read_bps: "minimum",
          disk_write_iops: "minimum",
          disk_write_bps: "minimum",
          shm_size: "minimum",
          gpu_count: "minimum",
          gpu_model: "exact",
          cpu_vendor: "exact",
          cpu_arch: "exact",
          cpu_model: "exact",
          kernel_version: "exact",
          OSFamily: "priority",
          "container-image": "priority",
          "lre-rs": "priority",
          ISA: "exact",
          InputRootAbsolutePath: "ignore", // used by chromium builds, but we can drop it
        },
      },
    },
  ],
  workers: [
    {
      local: {
        worker_api_endpoint: {
          uri: "grpc://127.0.0.1:50061",
        },
        cas_fast_slow_store: "WORKER_FAST_SLOW_STORE",
        upload_action_result: {
          ac_store: "AC_MAIN_STORE",
        },
        work_directory: "/tmp/nativelink/work",
        additional_environment: {
          foo: "from_environment",
          bar: {
            value: "something",
          },
          baz: "timeout_millis",
          channel: "side_channel_file",
          action: "action_directory",
        },
        platform_properties: {
          cpu_count: {
            values: [
              "16",
            ],
          },
          memory_kb: {
            values: [
              "500000",
            ],
          },
          network_kbps: {
            values: [
              "100000",
            ],
          },
          cpu_arch: {
            values: [
              "x86_64",
            ],
          },
          OSFamily: {
            values: [
              "",
            ],
          },
          "container-image": {
            values: [
              "",
            ],
          },
          "lre-rs": {
            values: [
              "",
            ],
          },
          ISA: {
            values: [
              "x86-64",
            ],
          },
        },
      },
    },
  ],
  servers: [
    {
      name: "public",
      listener: {
        http: {
          socket_address: "0.0.0.0:50051",
        },
      },
      services: {
        cas: [
          {
            instance_name: "",
            cas_store: "WORKER_FAST_SLOW_STORE",
          },
          {
            instance_name: "main",
            cas_store: "WORKER_FAST_SLOW_STORE",
          },
        ],
        ac: [
          {
            instance_name: "",
            ac_store: "AC_MAIN_STORE",
          },
          {
            instance_name: "main",
            ac_store: "AC_MAIN_STORE",
          },
        ],
        execution: [
          {
            instance_name: "",
            cas_store: "WORKER_FAST_SLOW_STORE",
            scheduler: "MAIN_SCHEDULER",
          },
          {
            instance_name: "main",
            cas_store: "WORKER_FAST_SLOW_STORE",
            scheduler: "MAIN_SCHEDULER",
          },
        ],
        capabilities: [
          {
            instance_name: "",
            remote_execution: {
              scheduler: "MAIN_SCHEDULER",
            },
          },
          {
            instance_name: "main",
            remote_execution: {
              scheduler: "MAIN_SCHEDULER",
            },
          },
        ],
        bytestream: [
          {
            instance_name: "",
            cas_store: "WORKER_FAST_SLOW_STORE",
          },
          {
            instance_name: "main",
            cas_store: "WORKER_FAST_SLOW_STORE",
          },
        ],
      },
    },
    {
      name: "private_workers_servers",
      listener: {
        http: {
          socket_address: "0.0.0.0:50061",
        },
      },
      services: {
        // Note: This should be served on a different port, because it has
        // a different permission set than the other services.
        // In other words, this service is a backend api. The ones above
        // are a frontend api.
        worker_api: {
          scheduler: "MAIN_SCHEDULER",
        },
        admin: {},
        health: {},
      },
    },
  ],
  global: {
    max_open_files: 24576,
  },
}

Expected behavior

Workers pick up and complete queued build/cache actions continuously. When one worker slot frees up, the scheduler should be able to dispatch the next queued action to it.

Actual behavior

After roughly an hour of sustained build load, the process stops making any progress: all worker/tokio-runtime threads become permanently blocked, and the scheduler logs "All workers are fully allocated" continuously (multiple times per second) forever. Actions queued behind this eventually have their originating clients give up, which shows up as a burst of "Operation timed out having no more clients listening" warnings once the scheduler catches up on the backlog. The process itself stays alive and keeps logging/serving some RPCs (e.g. in-flight ByteStream writes) — only the action-execution path is wedged. The only recovery is a full process restart (launchctl kickstart -k in our case); the deadlock never clears on its own.

Logs / error output

2026-08-06T18:33:23.101379Z  WARN nativelink_scheduler::simple_scheduler_state_manager: Operation timed out having no more clients listening, operation_id: Uuid(ffd83d40-55c3-4531-a2f7-23891deae6d1), timeout_secs: 60.0
    at nativelink-scheduler/src/simple_scheduler_state_manager.rs:417
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:33:23.106459Z  WARN nativelink_scheduler::simple_scheduler_state_manager: Operation timed out having no more clients listening, operation_id: Uuid(ffe11ca0-503a-4d3e-a0fc-55002e4fa0aa), timeout_secs: 60.0
    at nativelink-scheduler/src/simple_scheduler_state_manager.rs:417
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:33:23.112990Z  WARN nativelink_scheduler::simple_scheduler_state_manager: Operation timed out having no more clients listening, operation_id: Uuid(fff32010-840a-48ec-b65f-546d19f3ebdb), timeout_secs: 60.0
    at nativelink-scheduler/src/simple_scheduler_state_manager.rs:417
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching
2. Worker pool permanently saturated — "All workers are fully allocated" repeating continuously

This message repeats every 100–500ms indefinitely, with no drop-off, alongside in-flight bytestream traffic that also stalls mid-write:

2026-08-06T18:26:13.201063Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:13.242545Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:13.345085Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:13.815006Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:13.905917Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:14.429294Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:14.650722Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:15.067891Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:15.120765Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:15.157175Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:15.728209Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:15.823260Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:15.901575Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:15.929788Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:15.997523Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:16.106884Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:16.438250Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:16.587679Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:16.611260Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:17.121902Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:17.187130Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:17.375243Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:17.784096Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:17.833493Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:18.155863Z  INFO nativelink_service::bytestream_server: msg: "Joining existing stream", uuid: "e96d391bf06f4b24aa75b1840c79a590"
    at nativelink-service/src/bytestream_server.rs:658
    in nativelink_service::bytestream_server::inner_write with digest: DigestInfo("b83af338132d1c68c1e124e3d54629c284b35738ec936b298dfeae3ec7707b5c-122363"), digest_function: Sha256, stream: WriteRequestStreamWrapper { resource_info: ResourceInfo { instance_name: "main", uuid: Some("e96d391b-f06f-4b24-aa75-b1840c79a590"), compressor: None, digest_function: None, hash: "b83af338132d1c68c1e124e3d54629c284b35738ec936b298dfeae3ec7707b5c", size: "122363", expected_size: 122363, optional_metadata: None }, bytes_received: 0, first_msg: Some(WriteRequest { resource_name: "main/uploads/e96d391b-f06f-4b24-aa75-b1840c79a590/blobs/b83af338132d1c68c1e124e3d54629c284b35738ec936b298dfeae3ec7707b5c/122363", write_offset: 0, finish_write: true, .. }), write_finished: false }
    in nativelink_service::bytestream_server::bytestream_write
    in nativelink_service::bytestream_server::write with request: Streaming
    in nativelink_util::task::http_executor
    in nativelink::services::http_connection with remote_addr: 10.10.3.126:53153, socket_addr: 0.0.0.0:50051

2026-08-06T18:26:18.455494Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:18.672122Z  WARN nativelink_util::buf_channel: Stream already closed when eof already was sent. This is often ok for retry was triggered, but should not happen on happy path.
    at nativelink-util/src/buf_channel.rs:185
    in nativelink_service::bytestream_server::inner_write with digest: DigestInfo("b83af338132d1c68c1e124e3d54629c284b35738ec936b298dfeae3ec7707b5c-122363"), digest_function: Sha256, stream: WriteRequestStreamWrapper { resource_info: ResourceInfo { instance_name: "main", uuid: Some("e96d391b-f06f-4b24-aa75-b1840c79a590"), compressor: None, digest_function: None, hash: "b83af338132d1c68c1e124e3d54629c284b35738ec936b298dfeae3ec7707b5c", size: "122363", expected_size: 122363, optional_metadata: None }, bytes_received: 0, first_msg: Some(WriteRequest { resource_name: "main/uploads/e96d391b-f06f-4b24-aa75-b1840c79a590/blobs/b83af338132d1c68c1e124e3d54629c284b35738ec936b298dfeae3ec7707b5c/122363", write_offset: 0, finish_write: true, .. }), write_finished: false }
    in nativelink_service::bytestream_server::bytestream_write
    in nativelink_service::bytestream_server::write with request: Streaming
    in nativelink_util::task::http_executor
    in nativelink::services::http_connection with remote_addr: 10.10.3.126:53153, socket_addr: 0.0.0.0:50051

2026-08-06T18:26:19.099392Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:19.335141Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:19.576466Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:19.771912Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:20.046901Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:20.400334Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_matching

2026-08-06T18:26:20.593113Z  INFO nativelink_scheduler::api_worker_scheduler: All workers are fully allocated
    at nativelink-scheduler/src/api_worker_scheduler.rs:250
    in nativelink_scheduler::simple_scheduler::simple_scheduler_task_worker_


ps -eo pid,etime,command | grep -i nativelink
 4574 03:36:44 /nix/store/2vp2sainqmdlqwrzzbn6szgdwrk4hn15-nativelink-1.6.4/bin/nativelink ./basic_cas.json5

$ sample 4574 10 -f /tmp/stuck-action.txt
Sampling process 4574 for 10 seconds with 1 millisecond of run time between samples
Sampling completed, processing symbols...
Sample analysis of process 4574 written to file /tmp/stuck-action.txt

Analysis of sampling nativelink (pid 4574) every 1 millisecond
Process:         nativelink [4574]
Path:            /Volumes/VOLUME/*/nativelink
Version:         0
Code Type:       ARM64
Platform:        macOS
OS Version:      macOS 15.7.3 (24G419)
Launch Time:     2026-08-06 17:59:29.670 +0200
Date/Time:       2026-08-06 21:36:49.076 +0200

Physical footprint:         1.6G
Physical footprint (peak):  3.0G

Call graph:
    7859 Thread_205345   DispatchQueue_1: com.apple.main-thread  (serial)
    + 7859 start  (in dyld) + 6076
    +   7859 main  (in nativelink) + 872
    +     7859 nativelink::main
    +       7859 tokio::runtime::park::Inner::park
    +         7859 parking_lot::condvar::Condvar::wait_until_internal
    +           7859 _pthread_cond_wait
    +             7859 __psynch_cvwait   <-- normal tokio runtime idle park (main thread)

    7859 Thread_205348: tokio-rt-worker
    + ... tokio::runtime::task::raw::poll
    +   ... nativelink_worker::running_actions_manager::RunningActionsManagerImpl::cleanup_action
    +     7859 parking_lot::raw_rwlock::RawRwLock::lock_exclusive_slow
    +       7859 _pthread_cond_wait
    +         7859 __psynch_cvwait        <-- BLOCKED trying to take an EXCLUSIVE lock

    7859 Thread_205349: tokio-rt-worker
    + ... nativelink_worker::running_actions_manager::RunningActionsManagerImpl::cleanup_action
    +   7859 parking_lot::raw_mutex::RawMutex::lock_slow
    +     7859 _pthread_cond_wait
    +       7859 __psynch_cvwait          <-- BLOCKED on a Mutex

    [ ... same "cleanup_action -> RawMutex::lock_slow -> __psynch_cvwait" stack
          repeats identically on threads 205350, 205351, 205352, 205353,
          205354, 205357, 205358, 205359, 205360, 205361 ... ]

    7859 Thread_205356: tokio-rt-worker
    + ... nativelink_worker::local_worker::LocalWorker<T,C,U>::run::{{closure}}::{{closure}}
    +   7859 parking_lot::raw_mutex::RawMutex::lock_slow
    +     7859 _pthread_cond_wait
    +       7859 __psynch_cvwait          <-- the main LocalWorker loop itself is ALSO blocked

    7859 Thread_205362: OpenTelemetry.Logs.BatchProcessor       (normal semaphore wait, unrelated)
    7859 Thread_205363: OpenTelemetry.Traces.BatchProcessor     (normal semaphore wait, unrelated)
    7859 Thread_205364: OpenTelemetry.Metrics.PeriodicReader    (normal semaphore wait, unrelated)

Total number in stack (recursive counted multiple, when >=5):
        17       _pthread_start  (in libsystem_pthread.dylib)
        17       std::sys::thread::unix::Thread::new::thread_start
        17       thread_start  (in libsystem_pthread.dylib)
        15       __psynch_cvwait  (in libsystem_kernel.dylib)
        15       _pthread_cond_wait  (in libsystem_pthread.dylib)
        14       tokio::runtime::task::raw::poll
        13       parking_lot::raw_mutex::RawMutex::lock_slow
        13       tokio::runtime::scheduler::multi_thread::worker::Context::run_task
        12       nativelink_worker::running_actions_manager::RunningActionsManagerImpl::cleanup_action

Sort by top of stack, same collapsed (when >= 5):
        __psynch_cvwait  (in libsystem_kernel.dylib)        117885
        semaphore_wait_trap  (in libsystem_kernel.dylib)        23577

Additional context

This looks related to #1978 ("Fast-slow deadlock"), which is still open. That PR's discussion describes the same class of symptom — "workers which start up, get issued a few actions and then sit there idling with no logs" — but the lock contention we captured is in RunningActionsManagerImpl::cleanup_action rather than the fast-slow-store semaphore path discussed there, so this may be a related but distinct deadlock in the same area of the codebase.

As a stopgap, we're running a watchdog that samples the process every 2 minutes and force-restarts it via launchctl if threads stay blocked on the same parking_lot lock for 3 consecutive checks (~6 min) — happy to share that script if useful for reproduction/monitoring purposes.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions