Coverage Report

Created: 2026-09-18 20:40

next uncovered line (L), next uncovered region (R), next uncovered branch (B)
/build/source/nativelink-worker/src/running_actions_manager.rs
Line
Count
Source
1
// Copyright 2024 The NativeLink Authors. All rights reserved.
2
//
3
// Licensed under the Functional Source License, Version 1.1, Apache 2.0 Future License (the "License");
4
// you may not use this file except in compliance with the License.
5
// You may obtain a copy of the License at
6
//
7
//    See LICENSE file for details
8
//
9
// Unless required by applicable law or agreed to in writing, software
10
// distributed under the License is distributed on an "AS IS" BASIS,
11
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12
// See the License for the specific language governing permissions and
13
// limitations under the License.
14
15
use core::cmp::min;
16
use core::convert::Into;
17
use core::fmt::Debug;
18
use core::pin::Pin;
19
use core::sync::atomic::{AtomicBool, Ordering};
20
use core::time::Duration;
21
use std::borrow::Cow;
22
use std::collections::vec_deque::VecDeque;
23
use std::collections::{HashMap, HashSet};
24
use std::env;
25
use std::ffi::{OsStr, OsString};
26
#[cfg(target_family = "unix")]
27
use std::fs::Permissions;
28
#[cfg(target_family = "unix")]
29
use std::os::unix::fs::{MetadataExt, PermissionsExt};
30
use std::path::{Path, PathBuf};
31
use std::process::Stdio;
32
use std::sync::{Arc, Weak};
33
use std::time::SystemTime;
34
35
use bytes::{Bytes, BytesMut};
36
use filetime::{FileTime, set_file_mtime};
37
use formatx::Template;
38
use futures::future::{
39
    BoxFuture, Future, FutureExt, TryFutureExt, join_all, try_join, try_join_all,
40
};
41
use futures::stream::{FuturesUnordered, StreamExt, TryStreamExt};
42
use nativelink_config::cas_server::{
43
    EnvironmentSource, UploadActionResultConfig, UploadCacheResultsStrategy,
44
};
45
use nativelink_error::{Code, Error, ResultExt, make_err, make_input_err};
46
use nativelink_metric::MetricsComponent;
47
use nativelink_proto::build::bazel::remote::execution::v2::{
48
    Action, ActionResult as ProtoActionResult, Command as ProtoCommand,
49
    Directory as ProtoDirectory, Directory, DirectoryNode, ExecuteResponse, FileNode, SymlinkNode,
50
    Tree as ProtoTree, UpdateActionResultRequest,
51
};
52
use nativelink_proto::com::github::trace_machina::nativelink::remote_execution::{
53
    ActionResourceUsage, HistoricalExecuteResponse, StartExecute,
54
};
55
use nativelink_store::ac_utils::{
56
    ESTIMATED_DIGEST_SIZE, compute_buf_digest, get_and_decode_digest, serialize_and_upload_message,
57
};
58
use nativelink_store::cas_utils::is_zero_digest;
59
use nativelink_store::fast_slow_store::FastSlowStore;
60
use nativelink_store::filesystem_store::{FileEntry, FileEntryImpl, FilesystemStore};
61
use nativelink_store::grpc_store::GrpcStore;
62
use nativelink_util::action_messages::{
63
    ActionInfo, ActionResult, DirectoryInfo, ExecutionMetadata, FileInfo, NameOrPath, OperationId,
64
    SymlinkInfo, to_execute_response,
65
};
66
use nativelink_util::common::{DigestInfo, fs};
67
use nativelink_util::digest_hasher::{DigestHasher, DigestHasherFunc};
68
use nativelink_util::metrics_utils::{AsyncCounterWrapper, CounterWithTime};
69
use nativelink_util::store_trait::{Store, StoreLike, UploadSizeInfo};
70
use nativelink_util::{background_spawn, spawn, spawn_blocking};
71
use parking_lot::Mutex;
72
use prost::Message;
73
use relative_path::RelativePath;
74
use scopeguard::{ScopeGuard, guard};
75
use serde::Deserialize;
76
use tokio::io::{AsyncReadExt, AsyncSeekExt, AsyncWriteExt};
77
use tokio::process;
78
use tokio::sync::{Notify, oneshot, watch};
79
use tokio::time::Instant;
80
use tokio_stream::wrappers::ReadDirStream;
81
use tonic::Request;
82
use tracing::{debug, error, info, trace, warn};
83
use uuid::Uuid;
84
85
use crate::persistent_worker::{
86
    Input as PersistentWorkerInput, PersistentWorkerPool, WireFormat, WorkRequest, WorkerKey,
87
};
88
89
/// For simplicity we use a fixed exit code for cases when our program is terminated
90
/// due to a signal.
91
const EXIT_CODE_FOR_SIGNAL: i32 = 9;
92
93
const SUPPORTS_WORKERS_PROPERTY: &str = "supports-workers";
94
const REQUIRES_WORKER_PROTOCOL_PROPERTY: &str = "requires-worker-protocol";
95
96
/// Default strategy for uploading historical results.
97
/// Note: If this value changes the config documentation
98
/// should reflect it.
99
const DEFAULT_HISTORICAL_RESULTS_STRATEGY: UploadCacheResultsStrategy =
100
    UploadCacheResultsStrategy::FailuresOnly;
101
102
#[cfg(target_os = "linux")]
103
const RESOURCE_USAGE_SAMPLE_INTERVAL: Duration = Duration::from_millis(250);
104
105
/// What the sampler observed over an action's lifetime.
106
#[cfg(target_os = "linux")]
107
#[derive(Debug, Default, Clone, Copy, PartialEq, Eq)]
108
struct SampledResourceUsage {
109
    peak_memory_kb: u64,
110
    cpu_time_ms: u64,
111
}
112
113
#[cfg(target_os = "linux")]
114
struct ActionResourceUsageSampler {
115
    stop_tx: watch::Sender<bool>,
116
    handle: tokio::task::JoinHandle<SampledResourceUsage>,
117
}
118
119
#[cfg(target_os = "linux")]
120
18
fn start_action_resource_usage_sampler(pgid: u32) -> ActionResourceUsageSampler {
121
18
    let (stop_tx, stop_rx) = watch::channel(false);
122
18
    let handle = background_spawn!(
123
        "action_resource_usage_sampler",
124
18
        sample_action_resource_usage(pgid, stop_rx)
125
    );
126
18
    ActionResourceUsageSampler { stop_tx, handle }
127
18
}
128
129
#[cfg(target_os = "linux")]
130
0
async fn finish_action_resource_usage_sampler(
131
0
    sampler: ActionResourceUsageSampler,
132
18
) -> Option<SampledResourceUsage> {
133
18
    let _ = sampler.stop_tx.send(true);
134
18
    sampler.handle.await.ok()
135
18
}
136
137
#[cfg(target_os = "linux")]
138
18
async fn sample_action_resource_usage(
139
18
    pgid: u32,
140
18
    mut stop_rx: watch::Receiver<bool>,
141
18
) -> SampledResourceUsage {
142
18
    let mut peak_memory_kb = 0;
143
    // CPU time is cumulative per process and a process that exits stops
144
    // appearing, so summing the live group at the end would lose everything
145
    // short-lived. Keep the last figure seen for each pid and total them at
146
    // the end instead.
147
18
    let mut cpu_ticks_by_pid = HashMap::new();
148
149
36
    let 
sample18
= |peak_memory_kb: &mut u64, cpu_ticks_by_pid: &mut HashMap<u32, u64>| {
150
36
        let observed = sample_process_group(pgid, cpu_ticks_by_pid);
151
36
        if let Some(
memory_kb16
) = observed {
152
16
            *peak_memory_kb = (*peak_memory_kb).max(memory_kb);
153
20
        }
154
36
        observed
155
36
    };
156
157
    loop {
158
18
        if sample(&mut peak_memory_kb, &mut cpu_ticks_by_pid).is_none()
159
2
            && !Path::new(&format!("/proc/{pgid}")).exists()
160
        {
161
            // The group leader has been reaped and no member process remains,
162
            // so the action is finished.
163
0
            break;
164
18
        }
165
166
18
        if *stop_rx.borrow() {
167
0
            break;
168
18
        }
169
170
18
        tokio::select! {
171
18
            changed = stop_rx.changed() => {
172
18
                if changed.is_ok() && *stop_rx.borrow() {
173
18
                    sample(&mut peak_memory_kb, &mut cpu_ticks_by_pid);
174
18
                    break;
175
0
                }
176
            }
177
18
            () = tokio::time::sleep(RESOURCE_USAGE_SAMPLE_INTERVAL) => 
{}0
178
        }
179
    }
180
181
18
    SampledResourceUsage {
182
18
        peak_memory_kb,
183
18
        cpu_time_ms: ticks_to_millis(cpu_ticks_by_pid.values().sum()),
184
18
    }
185
18
}
186
187
/// Converts clock ticks from `/proc` into milliseconds.
188
///
189
/// `_SC_CLK_TCK` is 100 on every Linux we run on, but it is queryable so ask
190
/// rather than assume, and fall back to 100 if the query fails.
191
#[cfg(target_os = "linux")]
192
18
fn ticks_to_millis(ticks: u64) -> u64 {
193
    // SAFETY: `sysconf` takes an int and returns a long, with no memory
194
    // safety considerations.
195
18
    let hz = unsafe { libc::sysconf(libc::_SC_CLK_TCK) };
196
18
    let hz = if hz > 0 { hz as u64 } else { 
1000
};
197
18
    ticks.saturating_mul(1_000) / hz
198
18
}
199
200
/// Sums the resident memory of every process in the action's process group.
201
///
202
/// The action is spawned as its own process-group leader (see
203
/// `command_builder.process_group(0)` in `inner_execute`), so `pgid` equals
204
/// the spawned child's pid and every descendant inherits it. Sampling by
205
/// process group — rather than walking the parent/child tree from the spawned
206
/// pid — is required because an intermediate shell frequently exits and
207
/// reparents the real workload to the worker (PID 1); the tree walk then sees
208
/// only a childless zombie and reports zero. Process-group membership is
209
/// inherited and survives reparenting, and excludes the worker's own group.
210
/// Returns `None` when no member process can be read (the group is empty).
211
#[cfg(target_os = "linux")]
212
36
fn sample_process_group(pgid: u32, cpu_ticks_by_pid: &mut HashMap<u32, u64>) -> Option<u64> {
213
36
    let Ok(entries) = std::fs::read_dir("/proc") else {
214
0
        return None;
215
    };
216
217
36
    let mut total_kb = 0;
218
36
    let mut found_any_process = false;
219
2.40k
    for entry in 
entries36
.
flatten36
() {
220
2.40k
        let Ok(
member_pid177
) = entry.file_name().to_string_lossy().parse::<u32>() else {
221
2.23k
            continue;
222
        };
223
177
        let Ok(stat) = std::fs::read_to_string(format!("/proc/{member_pid}/stat")) else {
224
0
            continue;
225
        };
226
177
        if parse_pgid_from_stat(&stat) != Some(pgid) {
227
144
            continue;
228
33
        }
229
33
        if let Some(ticks) = parse_cpu_ticks_from_stat(&stat) {
230
33
            // Monotonic per process, but a pid could in principle be reused
231
33
            // within one action, so never let the figure go backwards.
232
33
            let entry = cpu_ticks_by_pid.entry(member_pid).or_insert(0);
233
33
            *entry = (*entry).max(ticks);
234
33
        
}0
235
33
        if let Some(
memory_kb28
) = read_process_rss_kb(member_pid) {
236
28
            total_kb += memory_kb;
237
28
            found_any_process = true;
238
28
        
}5
239
    }
240
241
36
    found_any_process.then_some(total_kb)
242
36
}
243
244
#[cfg(target_os = "linux")]
245
33
fn read_process_rss_kb(pid: u32) -> Option<u64> {
246
33
    let status = std::fs::read_to_string(format!("/proc/{pid}/status")).ok()
?0
;
247
853
    
status.lines()33
.
find_map33
(|line| {
248
853
        let 
rest28
= line.strip_prefix("VmRSS:")
?825
;
249
28
        rest.split_whitespace().next()
?0
.parse().ok()
250
853
    })
251
33
}
252
253
/// Parses the process group id (`pgrp`, field 5) from the contents of a
254
/// `/proc/<pid>/stat` line.
255
///
256
/// `comm` (field 2) can contain spaces and parentheses, so fields are parsed
257
/// relative to the final `)` to avoid miscounting. Returns `None` when the
258
/// line is malformed.
259
#[cfg(target_os = "linux")]
260
182
pub fn parse_pgid_from_stat(stat: &str) -> Option<u32> {
261
182
    let 
after_comm180
= stat.rsplit_once(')')
?2
.1;
262
    // Fields after the final ')': state(0) ppid(1) pgrp(2) ...
263
180
    after_comm.split_whitespace().nth(2)
?1
.
parse179
().
ok179
()
264
182
}
265
266
/// Sums user and system CPU ticks (`utime` + `stime`, fields 14 and 15) from
267
/// the contents of a `/proc/<pid>/stat` line.
268
///
269
/// Parsed relative to the final `)` for the same reason as the pgid above:
270
/// `comm` can contain spaces and parentheses. Returns `None` when the line is
271
/// malformed.
272
///
273
/// `cutime`/`cstime` are deliberately not included. They only cover children
274
/// this process has already reaped, so adding them here would double count
275
/// every child that is still its own entry in the group.
276
#[cfg(target_os = "linux")]
277
38
pub fn parse_cpu_ticks_from_stat(stat: &str) -> Option<u64> {
278
38
    let 
after_comm36
= stat.rsplit_once(')')
?2
.1;
279
36
    let mut fields = after_comm.split_whitespace();
280
    // Fields after the final ')': state(0) ppid(1) pgrp(2) session(3) tty(4)
281
    // tpgid(5) flags(6) minflt(7) cminflt(8) majflt(9) cmajflt(10)
282
    // utime(11) stime(12) ...
283
36
    let 
utime35
:
u6435
= fields.nth(11)
?1
.
parse35
().
ok35
()
?0
;
284
35
    let stime: u64 = fields.next()
?0
.parse().ok()
?0
;
285
35
    Some(utime.saturating_add(stime))
286
38
}
287
288
/// Valid string reasons for a failure.
289
/// Note: If these change, the documentation should be updated.
290
#[derive(Debug, Deserialize)]
291
#[serde(rename_all = "snake_case")]
292
enum SideChannelFailureReason {
293
    /// Task should be considered timed out.
294
    Timeout,
295
}
296
297
/// This represents the json data that can be passed from the running process
298
/// to the parent via the `SideChannelFile`. See:
299
/// `config::EnvironmentSource::sidechannelfile` for more details.
300
/// Note: Any fields added here must be added to the documentation.
301
#[derive(Debug, Deserialize, Default)]
302
struct SideChannelInfo {
303
    /// If the task should be considered a failure and why.
304
    failure: Option<SideChannelFailureReason>,
305
}
306
307
20
fn action_supports_persistent_workers(
308
20
    action_info: &ActionInfo,
309
20
) -> Option<Result<WireFormat, Error>> {
310
20
    if action_info
311
20
        .platform_properties
312
20
        .get(SUPPORTS_WORKERS_PROPERTY)
313
20
        .is_none_or(|value| 
value2
!=
"1"2
)
314
    {
315
18
        return None;
316
2
    }
317
318
2
    let protocol = action_info
319
2
        .platform_properties
320
2
        .get(REQUIRES_WORKER_PROTOCOL_PROPERTY)
321
2
        .map_or("proto", String::as_str);
322
2
    Some(WireFormat::parse(protocol))
323
20
}
324
325
2
fn os_args_to_strings(args: &[&OsStr]) -> Result<Vec<String>, Error> {
326
2
    args.iter()
327
4
        .
map2
(|arg| {
328
4
            arg.to_str().map(str::to_owned).ok_or_else(|| 
{0
329
0
                make_err!(
330
0
                    Code::InvalidArgument,
331
                    "Persistent worker command arguments must be valid UTF-8: {arg:?}"
332
                )
333
0
            })
334
4
        })
335
2
        .collect()
336
2
}
337
338
2
fn persistent_worker_request_arguments(argv: &[String]) -> Vec<String> {
339
2
    argv.iter()
340
2
        .skip(1)
341
2
        .skip_while(|arg| !arg.starts_with('@'))
342
2
        .cloned()
343
2
        .collect()
344
2
}
345
/// Maximum number of file-materialization (hardlink) or subdirectory
346
/// recursion futures polled concurrently per directory level. Higher values
347
/// drown APFS's per-volume metadata lock with `hardlink(2)` syscalls and
348
/// regress overall throughput vs lower-contention concurrency.
349
///
350
/// 64 is well above the inflection point on any modern Linux filesystem,
351
/// so this is also a no-op on Linux beyond replacing tokio scheduling
352
/// overhead.
353
const DOWNLOAD_TO_DIRECTORY_CONCURRENCY: usize = 64;
354
355
/// Keeps every digest used by an action present in locally eviction-managed
356
/// CAS tiers.
357
///
358
/// A lease is registered before a digest is populated. This is important for
359
/// blobs that are not yet in the fast tier: reserving the key first prevents
360
/// the insertion that follows from immediately evicting the blob under pressure.
361
/// Every directly discoverable filesystem tier of the worker's
362
/// `FastSlowStore` is leased when present (including a `RefStore` target).
363
/// Transforming wrappers remain opaque by design. The reference count lets
364
/// concurrent actions share a digest safely.
365
#[derive(Debug)]
366
struct ActionInputLease {
367
    filesystem_stores: Vec<Arc<FilesystemStore>>,
368
    digests: Mutex<Option<HashSet<DigestInfo>>>,
369
}
370
371
impl ActionInputLease {
372
1
    fn new(
373
1
        cas_store: &FastSlowStore,
374
1
        command_digest: DigestInfo,
375
1
        input_root_digest: DigestInfo,
376
1
    ) -> Arc<Self> {
377
1
        let lease = Arc::new(Self {
378
1
            filesystem_stores: cas_store.get_filesystem_stores(),
379
1
            digests: Mutex::new(Some(HashSet::new())),
380
1
        });
381
1
        lease.lease_digest(&command_digest);
382
1
        lease.lease_digest(&input_root_digest);
383
1
        lease
384
1
    }
385
386
4
    fn lease_digest(&self, digest: &DigestInfo) {
387
4
        let mut digests = self.digests.lock();
388
4
        let Some(digests) = digests.as_mut() else {
389
0
            return;
390
        };
391
4
        if digests.insert(*digest) {
392
3
            for filesystem_store in &self.filesystem_stores {
393
3
                filesystem_store.lease_digest(digest);
394
3
            }
395
1
        }
396
4
    }
397
398
2
    fn take_release_work(&self) -> Option<(Vec<Arc<FilesystemStore>>, Vec<DigestInfo>)> {
399
2
        let 
digests1
= self.digests.lock().take()
?1
.
into_iter1
().
collect1
();
400
1
        Some((self.filesystem_stores.clone(), digests))
401
2
    }
402
403
2
    fn spawn_release(&self) -> Option<tokio::task::JoinHandle<()>> {
404
2
        let (
filesystem_stores1
,
digests1
) = self.take_release_work()
?1
;
405
1
        Some(background_spawn!(
406
            "action_input_lease_release",
407
1
            release_filesystem_stores(filesystem_stores, digests)
408
        ))
409
2
    }
410
411
2
    async fn release(self: Arc<Self>) 
{1
412
1
        let Some(handle) = self.spawn_release() else {
413
0
            return;
414
        };
415
        // Detach the actual release before awaiting it so cancellation of the
416
        // action cleanup future cannot strand leases in a later filesystem
417
        // tier.
418
1
        let _result = handle.await;
419
1
    }
420
}
421
422
impl crate::directory_cache::DigestLease for ActionInputLease {
423
2
    fn acquire(&self, digest: &DigestInfo) {
424
2
        self.lease_digest(digest);
425
2
    }
426
}
427
428
impl Drop for ActionInputLease {
429
1
    fn drop(&mut self) {
430
1
        drop(self.spawn_release());
431
1
    }
432
}
433
434
1
async fn release_filesystem_stores(
435
1
    filesystem_stores: Vec<Arc<FilesystemStore>>,
436
1
    digests: Vec<DigestInfo>,
437
1
) {
438
1
    join_all(
439
1
        filesystem_stores
440
1
            .iter()
441
1
            .map(|filesystem_store| filesystem_store.release_digests(&digests)),
442
    )
443
1
    .await;
444
1
}
445
446
/// Aggressively download the digests of files and make a local folder from it. This function
447
/// gates each directory level to at most `DOWNLOAD_TO_DIRECTORY_CONCURRENCY`
448
/// concurrent in-flight materialization futures.
449
/// We require the `FilesystemStore` to be the `fast` store of `FastSlowStore`. This is for
450
/// efficiency reasons. We will request the `FastSlowStore` to populate the entry then we will
451
/// assume the `FilesystemStore` has the file available immediately after and hardlink the file
452
/// to a new location.
453
// Sadly we cannot use `async fn` here because the rust compiler cannot determine the auto traits
454
// of the future. So we need to force this function to return a dynamic future instead.
455
// see: https://github.com/rust-lang/rust/issues/78649
456
5
pub fn download_to_directory<'a>(
457
5
    cas_store: &'a FastSlowStore,
458
5
    filesystem_store: Pin<&'a FilesystemStore>,
459
5
    digest: &'a DigestInfo,
460
5
    current_directory: &'a str,
461
5
) -> BoxFuture<'a, Result<(), Error>> {
462
5
    download_to_directory_with_lease(cas_store, filesystem_store, digest, current_directory, None)
463
5
}
464
465
28
fn download_to_directory_with_lease<'a>(
466
28
    cas_store: &'a FastSlowStore,
467
28
    filesystem_store: Pin<&'a FilesystemStore>,
468
28
    digest: &'a DigestInfo,
469
28
    current_directory: &'a str,
470
28
    input_lease: Option<Arc<ActionInputLease>>,
471
28
) -> BoxFuture<'a, Result<(), Error>> {
472
28
    async move {
473
28
        let (dirs, files, inline_nodes) =
474
28
            collect_download_links(cas_store, digest, current_directory, input_lease).await
?0
;
475
476
28
        let (exec_files, plain_files): (Vec<_>, Vec<_>) =
477
28
            files.into_iter().partition(|file| file.executable);
478
28
        let mut links = resolve_plain_files(cas_store, filesystem_store, plain_files).await
?0
;
479
28
        links.extend(resolve_exec_files(cas_store, filesystem_store, exec_files).await
?0
);
480
481
        // Every directory exists before anything is written into one, so no
482
        // later pass has to create a parent it happens to need.
483
28
        fs::create_dir_many(dirs).await
?0
;
484
28
        materialize_inline_nodes(cas_store, filesystem_store, inline_nodes).await
?0
;
485
28
        materialize_links(filesystem_store, links).await
486
28
    }
487
28
    .boxed()
488
28
}
489
490
/// A hardlink deferred to the end of the input-tree walk, so the whole tree is
491
/// materialized by one batched [`fs::hard_link_many`] pass instead of one
492
/// `spawn_blocking` dispatch per file.
493
struct PendingLink {
494
    src: PathBuf,
495
    dst: PathBuf,
496
    /// Keeps the CAS blob's `FileEntry` alive until the link is made, so the
497
    /// inode cannot be dropped out from under the batch. `None` for an
498
    /// executable variant, which is a private file outside the entry map and so
499
    /// has no entry to hold.
500
    ///
501
    /// Neither case is fully closed: a held entry pins the inode but does not
502
    /// stop an eviction from *renaming* the blob, and a variant is deleted
503
    /// outright by the eviction callback. Both races predate batching, which
504
    /// widens the window from a single file to a whole input tree. An operator
505
    /// seeing `NotFound` during staging should enable
506
    /// `experimental_active_input_leases`, since a leased digest is not
507
    /// evicted, or raise the store's `max_bytes`. The durable fix is a
508
    /// `hard_link_locked_many` holding every read guard across the batch.
509
    _keepalive: Option<Arc<FileEntryImpl>>,
510
}
511
512
/// A file whose CAS blob has not been resolved to a path yet.
513
struct PendingFile {
514
    digest: DigestInfo,
515
    dst: String,
516
    executable: bool,
517
}
518
519
/// The directories to create, the files to hardlink, and the nodes to
520
/// materialize one at a time, for one input subtree.
521
type CollectedTree = (Vec<PathBuf>, Vec<PendingFile>, Vec<InlineNode>);
522
523
/// Executes every deferred hardlink of an input tree in one batched pass.
524
28
async fn materialize_links(
525
28
    filesystem_store: Pin<&FilesystemStore>,
526
28
    links: Vec<PendingLink>,
527
28
) -> Result<(), Error> {
528
28
    let pairs = links
529
28
        .iter()
530
28
        .map(|link| (
link.src12
.
clone12
(),
link.dst12
.
clone12
()))
531
28
        .collect();
532
28
    for (
link12
,
result12
) in links.iter().zip(fs::hard_link_many(pairs).await
?0
) {
533
12
        let (src_path, dest) = (&link.src, &link.dst);
534
12
        result.map_err(|e| 
{0
535
0
            let src_metadata = std::fs::metadata(src_path);
536
0
            let dest_metadata = std::fs::metadata(dest);
537
0
            let dest_parent_metadata = dest.parent().map(Path::metadata);
538
0
            let snapshot = filesystem_store.get_eviction_snapshot();
539
0
            warn!(?e, fs_eviction_snapshot = %snapshot, ?src_path, ?src_metadata, ?dest, ?dest_metadata, ?dest_parent_metadata, "Could not make hardlink");
540
0
            if e.code == Code::NotFound {
541
0
                e.append(
542
0
                    format!(
543
                    "Could not make hardlink from {} to {}, file was likely evicted from cache.\n\
544
                    This error often occurs when the filesystem store's max_bytes is too small for your workload.\n\
545
                    To fix this issue:\n\
546
                    1. Increase the 'max_bytes' value in your filesystem store configuration\n\
547
                    2. Example: Change 'max_bytes: 10000000000' to 'max_bytes: 50000000000' (or higher)\n\
548
                    3. The setting is typically found in your nativelink.json config under:\n\
549
                    stores -> [your_filesystem_store] -> filesystem -> eviction_policy -> max_bytes\n\
550
                    4. Restart NativeLink after making the change\n\n\
551
                    If this error persists after increasing max_bytes several times, please report at:\n\
552
                    https://github.com/TraceMachina/nativelink/issues\n\
553
                    Include your config file and both server and client logs to help us assist you.",
554
0
                    src_path.display(), dest.display()
555
                ))
556
            } else {
557
0
                e.append(format!("Could not make hardlink from {} to {}", src_path.display(), dest.display()))
558
            }
559
0
        })?;
560
    }
561
28
    Ok(())
562
28
}
563
564
/// Resolves every non-executable file of an input tree to its CAS blob path.
565
///
566
/// The blob is nearly always resident, and `populate_fast_store` would take the
567
/// store's eviction lock only to discover that, so resolving the entry directly
568
/// answers the same question and yields the path. Only a genuine miss pays the
569
/// populate round trip.
570
28
async fn resolve_plain_files(
571
28
    cas_store: &FastSlowStore,
572
28
    filesystem_store: Pin<&FilesystemStore>,
573
28
    files: Vec<PendingFile>,
574
28
) -> Result<Vec<PendingLink>, Error> {
575
28
    let mut tasks = Vec::with_capacity(files.len());
576
28
    for 
file9
in files {
577
9
        tasks.push(async move {
578
9
            let file_entry = if let Ok(
entry2
) = filesystem_store
579
9
                .get_file_entry_for_digest(&file.digest)
580
9
                .await
581
            {
582
2
                entry
583
            } else {
584
7
                cas_store
585
7
                    .populate_fast_store(file.digest.into())
586
7
                    .await
587
7
                    .err_tip(|| "Populating fast store for hard link")
?0
;
588
7
                filesystem_store
589
7
                    .get_file_entry_for_digest(&file.digest)
590
7
                    .await
591
7
                    .err_tip(|| "During hard link")
?0
592
            };
593
            // TODO: add a test for #2051: deadlock with large number of files
594
9
            let src_path = file_entry
595
18
                .
get_file_path_locked9
(|src| async move
{9
Ok(src)9
})
596
9
                .await
597
9
                .err_tip(|| 
format!0
("for digest {}", file.digest))
?0
;
598
9
            Ok::<_, Error>(PendingLink {
599
9
                src: PathBuf::from(src_path),
600
9
                dst: PathBuf::from(file.dst),
601
9
                _keepalive: Some(file_entry),
602
9
            })
603
9
        });
604
    }
605
28
    collect_links(tasks).await
606
28
}
607
608
/// Runs the resolution tasks of one input tree, bounded, into the link batch.
609
56
async fn collect_links(
610
56
    tasks: Vec<impl Future<Output = Result<PendingLink, Error>>>,
611
56
) -> Result<Vec<PendingLink>, Error> {
612
56
    futures::stream::iter(tasks)
613
56
        .buffer_unordered(DOWNLOAD_TO_DIRECTORY_CONCURRENCY)
614
56
        .try_collect()
615
56
        .await
616
56
}
617
618
/// Resolves every executable file of an input tree to its 0o555 variant.
619
///
620
/// The shared 0o444 CAS blob cannot carry the executable bit, so each of these
621
/// digests hardlinks a private variant instead, and the batch checks the whole
622
/// tree's variants for existence in one dispatch.
623
///
624
/// A variant cannot be built from a blob that is not resident, and only this
625
/// caller can fetch one, so those digests are populated and retried here.
626
28
async fn resolve_exec_files(
627
28
    cas_store: &FastSlowStore,
628
28
    filesystem_store: Pin<&FilesystemStore>,
629
28
    files: Vec<PendingFile>,
630
28
) -> Result<Vec<PendingLink>, Error> {
631
28
    let digests: Vec<DigestInfo> = files.iter().map(|file| file.digest).collect();
632
28
    let sources = filesystem_store
633
28
        .get_executable_hardlink_sources(&digests)
634
28
        .await;
635
636
28
    let mut tasks = Vec::with_capacity(files.len());
637
28
    for (
file3
,
source3
) in files.into_iter().zip(sources) {
638
3
        tasks.push(async move {
639
3
            let src_path = if let Ok(
src_path2
) = source {
640
2
                src_path
641
            } else {
642
1
                cas_store
643
1
                    .populate_fast_store(file.digest.into())
644
1
                    .await
645
1
                    .err_tip(|| "Populating fast store for executable")
?0
;
646
1
                filesystem_store
647
1
                    .get_executable_hardlink_source(&file.digest)
648
1
                    .await
649
1
                    .err_tip(|| 
format!0
("Resolving executable variant for {}", file.digest))
?0
650
            };
651
3
            Ok::<_, Error>(PendingLink {
652
3
                src: PathBuf::from(src_path),
653
3
                dst: PathBuf::from(file.dst),
654
3
                _keepalive: None,
655
3
            })
656
3
        });
657
    }
658
28
    collect_links(tasks).await
659
28
}
660
661
/// Walks the input tree, reading its `Directory` protos and sorting every node
662
/// into one of the passes the caller then runs: directories to create, files to
663
/// hardlink in a batch, and the few nodes that need individual treatment.
664
///
665
/// Nothing is written to disk here, which is what lets the caller create every
666
/// directory before any node is materialized into one.
667
40
fn collect_download_links<'a>(
668
40
    cas_store: &'a FastSlowStore,
669
40
    digest: &'a DigestInfo,
670
40
    current_directory: &'a str,
671
40
    input_lease: Option<Arc<ActionInputLease>>,
672
40
) -> BoxFuture<'a, Result<CollectedTree, Error>> {
673
40
    async move {
674
40
        if let Some(
input_lease0
) = &input_lease {
675
0
            input_lease.lease_digest(digest);
676
40
        }
677
40
        let directory = get_and_decode_digest::<ProtoDirectory>(cas_store, digest.into())
678
40
            .await
679
40
            .err_tip(|| "Converting digest to Directory")
?0
;
680
40
        let mut futures = Vec::new();
681
40
        let mut pending_files = Vec::new();
682
40
        let mut inline_nodes = Vec::new();
683
684
40
        for 
file18
in directory.files {
685
18
            let digest: DigestInfo = file
686
18
                .digest
687
18
                .err_tip(|| "Expected Digest to exist in Directory::file::digest")
?0
688
18
                .try_into()
689
18
                .err_tip(|| "In Directory::file::digest")
?0
;
690
18
            let dest = format!("{}/{}", current_directory, file.name);
691
18
            let is_executable = file.is_executable;
692
18
            let (mtime, custom_unix_mode) = match file.node_properties {
693
2
                Some(properties) => (properties.mtime, properties.unix_mode),
694
16
                None => (None, None),
695
            };
696
18
            if let Some(
input_lease0
) = &input_lease {
697
0
                input_lease.lease_digest(&digest);
698
18
            }
699
            // Hot path: nothing to stamp, so the file needs nothing from the
700
            // walk beyond its digest. Hand it up unresolved and let the caller
701
            // resolve and link the whole tree in one batch.
702
18
            if mtime.is_none() && 
custom_unix_mode16
.
is_none16
() &&
!is_zero_digest(digest)16
{
703
12
                pending_files.push(PendingFile {
704
12
                    digest,
705
12
                    dst: dest,
706
12
                    executable: is_executable,
707
12
                });
708
12
                continue;
709
6
            }
710
6
            inline_nodes.push(InlineNode::File {
711
6
                digest,
712
6
                dst: dest,
713
6
                is_executable,
714
6
                mtime: mtime
715
6
                    .map(|mtime| 
FileTime::from_unix_time2
(
mtime.seconds2
,
mtime.nanos as u322
)),
716
6
                custom_unix_mode,
717
            });
718
        }
719
720
40
        for 
sub_directory12
in directory.directories {
721
12
            let digest: DigestInfo = sub_directory
722
12
                .digest
723
12
                .err_tip(|| "Expected Digest to exist in Directory::directories::digest")
?0
724
12
                .try_into()
725
12
                .err_tip(|| "In Directory::file::digest")
?0
;
726
12
            let new_directory_path = format!("{}/{}", current_directory, sub_directory.name);
727
12
            if let Some(
input_lease0
) = &input_lease {
728
0
                // Reserve queued child directories before their futures are
729
0
                // polled. Without this, a large parent can leave later
730
0
                // directory digests exposed to slow-tier eviction while the
731
0
                // first batch of children is being materialized.
732
0
                input_lease.lease_digest(&digest);
733
12
            }
734
12
            let input_lease = input_lease.clone();
735
12
            futures.push(
736
12
                async move {
737
12
                    let (mut sub_dirs, files, inline) = collect_download_links(
738
12
                        cas_store,
739
12
                        &digest,
740
12
                        &new_directory_path,
741
12
                        input_lease,
742
12
                    )
743
12
                    .await
744
12
                    .err_tip(|| 
format!0
("in download_to_directory : {new_directory_path}"))
?0
;
745
12
                    sub_dirs.push(PathBuf::from(new_directory_path));
746
12
                    Ok::<_, Error>((sub_dirs, files, inline))
747
12
                }
748
12
                .boxed(),
749
            );
750
        }
751
752
        #[cfg(target_family = "unix")]
753
40
        for 
symlink_node3
in directory.symlinks {
754
3
            inline_nodes.push(InlineNode::Symlink {
755
3
                target: symlink_node.target,
756
3
                dst: format!("{}/{}", current_directory, symlink_node.name),
757
3
            });
758
3
        }
759
760
        // Gate concurrency: at most DOWNLOAD_TO_DIRECTORY_CONCURRENCY futures
761
        // polled at once for this directory level. Previously all futures were
762
        // pushed into an unbounded FuturesUnordered, which on macOS produced
763
        // thousands of parallel hardlink(2) calls fighting APFS's per-volume
764
        // metadata lock and regressing throughput vs serial.
765
40
        let collected: Vec<CollectedTree> = futures::stream::iter(futures)
766
40
            .buffer_unordered(DOWNLOAD_TO_DIRECTORY_CONCURRENCY)
767
40
            .try_collect()
768
40
            .await
?0
;
769
770
40
        let mut dirs = Vec::new();
771
40
        for (
sub_dirs12
,
sub_files12
,
sub_inline12
) in collected {
772
12
            dirs.extend(sub_dirs);
773
12
            pending_files.extend(sub_files);
774
12
            inline_nodes.extend(sub_inline);
775
12
        }
776
40
        Ok((dirs, pending_files, inline_nodes))
777
40
    }
778
40
    .boxed()
779
40
}
780
781
/// A node materialized one at a time rather than through a batch, because it
782
/// needs a private inode or is not a hardlink at all.
783
///
784
/// These are a tiny fraction of an input tree, and deferring them alongside the
785
/// batched files keeps one ordering rule for the whole walk: nothing is written
786
/// until every directory exists.
787
enum InlineNode {
788
    /// A zero-digest file, or one carrying metadata that must be stamped onto
789
    /// an inode private to this action.
790
    File {
791
        digest: DigestInfo,
792
        dst: String,
793
        is_executable: bool,
794
        mtime: Option<FileTime>,
795
        custom_unix_mode: Option<u32>,
796
    },
797
    #[cfg(target_family = "unix")]
798
    Symlink { target: String, dst: String },
799
}
800
801
/// Stamps the mode an input file asked for. `dest` must be an inode private to
802
/// this action: the same call on a hardlinked CAS blob would mutate the inode
803
/// every other action shares.
804
#[cfg(target_family = "unix")]
805
6
async fn stamp_unix_mode(
806
6
    dest: &str,
807
6
    is_executable: bool,
808
6
    custom_unix_mode: Option<u32>,
809
6
) -> Result<(), Error> {
810
6
    let 
mode2
= match (custom_unix_mode, is_executable) {
811
1
        (Some(mode), true) => mode | 0o111,
812
1
        (Some(mode), false) => mode,
813
0
        (None, true) => 0o555,
814
4
        (None, false) => return Ok(()),
815
    };
816
2
    fs::set_permissions(dest, Permissions::from_mode(mode))
817
2
        .await
818
2
        .err_tip(|| 
format!0
("Could not set unix mode in download_to_directory {dest}"))
819
6
}
820
821
/// Non-unix has no mode to stamp.
822
#[cfg(not(target_family = "unix"))]
823
async fn stamp_unix_mode(
824
    _dest: &str,
825
    _is_executable: bool,
826
    _custom_unix_mode: Option<u32>,
827
) -> Result<(), Error> {
828
    Ok(())
829
}
830
831
/// Materializes the nodes the batched passes cannot handle.
832
28
async fn materialize_inline_nodes(
833
28
    cas_store: &FastSlowStore,
834
28
    filesystem_store: Pin<&FilesystemStore>,
835
28
    nodes: Vec<InlineNode>,
836
28
) -> Result<(), Error> {
837
28
    let mut futures = Vec::with_capacity(nodes.len());
838
28
    for 
node9
in nodes {
839
9
        futures.push(async move {
840
9
            match node {
841
                #[cfg(target_family = "unix")]
842
3
                InlineNode::Symlink { target, dst } => fs::symlink(&target, &dst)
843
3
                    .await
844
3
                    .err_tip(|| 
format!0
("Could not create symlink {target} -> {dst}")),
845
                InlineNode::File {
846
6
                    digest,
847
6
                    dst: dest,
848
6
                    is_executable,
849
6
                    mtime,
850
6
                    custom_unix_mode,
851
                } => {
852
6
                    cas_store.populate_fast_store(digest.into()).await
?0
;
853
6
                    async move {
854
6
                        if is_zero_digest(digest) {
855
                            // Zero-digest files are never persisted by the
856
                            // FilesystemStore, so materialise them directly in
857
                            // the worker exec dir.
858
4
                            let mut file_slot = fs::create_file(&dest)
859
4
                                .await
860
4
                                .err_tip(|| 
format!0
("Could not create zero-digest file at {dest}"))
?0
;
861
4
                            file_slot
862
4
                                .write_all(&[])
863
4
                                .await
864
4
                                .err_tip(|| 
format!0
("Could not write zero-digest file at {dest}"))
?0
;
865
                        } else {
866
                            // Rare path: per-file metadata (a custom unix_mode or
867
                            // an mtime) must land on a PRIVATE inode. A
868
                            // chmod/utimes on a hardlink mutates the shared CAS
869
                            // inode for every other action that hardlinked it
870
                            // (the #2347 corruption class). Copy the blob into a
871
                            // private inode, then stamp mode/mtime onto it below.
872
2
                            let file_entry = filesystem_store
873
2
                                .get_file_entry_for_digest(&digest)
874
2
                                .await
875
2
                                .err_tip(|| "During private copy")
?0
;
876
2
                            let src_path = file_entry
877
4
                                .
get_file_path_locked2
(|src| async move
{2
Ok(src)2
})
878
2
                                .await
?0
;
879
2
                            let spawned_dest = dest.clone();
880
2
                            spawn_blocking!("download_to_directory_private_copy", move || {
881
2
                                std::fs::copy(&src_path, &spawned_dest).map(|_| ()).map_err(|e| 
{0
882
0
                                    make_err!(
883
0
                                        Code::Internal,
884
                                        "Failed to copy CAS blob into a private inode at {spawned_dest}: {e:?}"
885
                                    )
886
0
                                })
887
2
                            })
888
2
                            .await
889
2
                            .err_tip(|| 
{0
890
0
                                "Failed to launch spawn_blocking private copy in download_to_directory"
891
0
                            })??;
892
                        }
893
894
                        // Private-inode tail (zero-digest or private copy only):
895
                        // stamp the requested mode and mtime. Safe because the
896
                        // inode is private to this action.
897
6
                        stamp_unix_mode(&dest, is_executable, custom_unix_mode).await
?0
;
898
6
                        if let Some(
mtime2
) = mtime {
899
2
                            let spawned_dest = dest.clone();
900
2
                            spawn_blocking!("download_to_directory_set_mtime", move || {
901
2
                                set_file_mtime(&spawned_dest, mtime).err_tip(|| 
{0
902
0
                                    format!("Failed to set mtime in download_to_directory {spawned_dest}")
903
0
                                })
904
2
                            })
905
2
                            .await
906
2
                            .err_tip(
907
                                || "Failed to launch spawn_blocking in download_to_directory",
908
0
                            )??;
909
4
                        }
910
6
                        Ok(())
911
6
                    }
912
6
                    .await
913
6
                    .map_err(|e: Error| 
e0
.
append0
(
format!0
("for digest {digest}")))
914
                }
915
            }
916
9
        });
917
    }
918
28
    futures::stream::iter(futures)
919
28
        .buffer_unordered(DOWNLOAD_TO_DIRECTORY_CONCURRENCY)
920
28
        .try_collect()
921
28
        .await
922
28
}
923
924
/// Prepares action inputs by first trying the directory cache (if available),
925
/// then falling back to traditional `download_to_directory`.
926
///
927
/// This provides a significant performance improvement for repeated builds
928
/// with the same input directories.
929
///
930
/// `work_directory` must already exist and be empty when this is called: the
931
/// caller pre-creates it so that, on the fallback path, `download_to_directory`
932
/// has a destination to write into. The directory cache, however, materializes
933
/// the tree with `hardlink_directory_tree` / APFS `clonefile(2)`, both of which
934
/// require the destination to *not* exist — so this function removes the empty
935
/// directory before invoking the cache and recreates it if the cache fails.
936
0
pub async fn prepare_action_inputs(
937
0
    directory_cache: &Option<Arc<crate::directory_cache::DirectoryCache>>,
938
0
    cas_store: &FastSlowStore,
939
0
    filesystem_store: Pin<&FilesystemStore>,
940
0
    digest: &DigestInfo,
941
0
    work_directory: &str,
942
0
) -> Result<(), Error> {
943
    prepare_action_inputs_with_lease(
944
        directory_cache,
945
        cas_store,
946
        filesystem_store,
947
        digest,
948
        work_directory,
949
        None,
950
    )
951
    .await
952
}
953
954
25
async fn prepare_action_inputs_with_lease(
955
25
    directory_cache: &Option<Arc<crate::directory_cache::DirectoryCache>>,
956
25
    cas_store: &FastSlowStore,
957
25
    filesystem_store: Pin<&FilesystemStore>,
958
25
    digest: &DigestInfo,
959
25
    work_directory: &str,
960
25
    input_lease: Option<Arc<ActionInputLease>>,
961
25
) -> Result<(), Error> {
962
    // Try cache first if available. Cache hits are safe while an action lease
963
    // is active because the directory cache pins its own materialized tree
964
    // across the hardlink operation. On a miss, pass the action lease into
965
    // cache construction so every CAS digest is reserved before it is
966
    // fetched/populated.
967
25
    if let Some(
cache2
) = directory_cache {
968
        // `clonefile(2)` and `hardlink_directory_tree` both require the
969
        // destination to not exist. Remove the empty directory the caller
970
        // pre-created; without this the cache fails its precondition on every
971
        // action and silently falls back to the slow download path.
972
2
        fs::remove_dir(work_directory)
973
2
            .await
974
2
            .err_tip(|| 
format!0
("Failed to clear pre-created work directory {work_directory}"))
?0
;
975
2
        let cache_result = if let Some(
input_lease1
) = &input_lease {
976
1
            cache
977
1
                .get_or_create_with_lease(
978
1
                    *digest,
979
1
                    Path::new(work_directory),
980
1
                    Some(input_lease.as_ref()),
981
1
                )
982
1
                .await
983
        } else {
984
1
            cache
985
1
                .get_or_create(*digest, Path::new(work_directory))
986
1
                .await
987
        };
988
2
        match cache_result {
989
2
            Ok(cache_hit) => {
990
                // The materialized tree is already usable. The directory
991
                // cache locks each entry down with `set_readonly_recursive`,
992
                // which leaves directories writable (0o755) and only makes
993
                // files read-only (0o555). The macOS `clonefile(2)` path
994
                // copies those modes verbatim and the Linux hardlink walk
995
                // creates fresh writable directories, so every directory in
996
                // the materialized tree already accepts the nested output
997
                // files Bazel actions declare — no separate per-materialize
998
                // recursive chmod walk is needed here. Files stay read-only,
999
                // preserving the hermeticity contract and the CAS-hardlink
1000
                // shared-inode invariant.
1001
2
                trace!(
1002
                    ?digest,
1003
                    work_directory, cache_hit, "Successfully prepared inputs via directory cache"
1004
                );
1005
2
                return Ok(());
1006
            }
1007
0
            Err(e) => {
1008
0
                warn!(
1009
                    ?digest,
1010
                    ?e,
1011
                    "Directory cache failed, falling back to traditional download"
1012
                );
1013
                // The cache may have materialized a partial tree before
1014
                // failing. `download_to_directory` needs an existing, empty
1015
                // destination, so discard any partial state and recreate the
1016
                // work directory.
1017
0
                let _cleanup = fs::remove_dir_all(work_directory).await;
1018
0
                fs::create_dir(work_directory)
1019
0
                    .await
1020
0
                    .err_tip(|| format!("Failed to recreate work directory {work_directory}"))?;
1021
            }
1022
        }
1023
23
    }
1024
1025
    // Traditional path (cache disabled or failed)
1026
23
    download_to_directory_with_lease(
1027
23
        cas_store,
1028
23
        filesystem_store,
1029
23
        digest,
1030
23
        work_directory,
1031
23
        input_lease,
1032
23
    )
1033
23
    .await
1034
25
}
1035
1036
#[cfg(target_family = "windows")]
1037
fn is_executable(_metadata: &std::fs::Metadata, full_path: &impl AsRef<Path>) -> bool {
1038
    static EXECUTABLE_EXTENSIONS: &[&str] = &["exe", "bat", "com"];
1039
    EXECUTABLE_EXTENSIONS
1040
        .iter()
1041
        .any(|ext| full_path.as_ref().extension().map_or(false, |v| v == *ext))
1042
}
1043
1044
#[cfg(target_family = "unix")]
1045
16
fn is_executable(metadata: &std::fs::Metadata, _full_path: &impl AsRef<Path>) -> bool {
1046
16
    (metadata.mode() & 0o111) != 0
1047
16
}
1048
1049
type DigestUploader = Arc<tokio::sync::OnceCell<()>>;
1050
1051
16
async fn upload_file(
1052
16
    cas_store: Pin<&impl StoreLike>,
1053
16
    full_path: impl AsRef<Path> + Debug + Send + Sync,
1054
16
    hasher: DigestHasherFunc,
1055
16
    metadata: std::fs::Metadata,
1056
16
    digest_uploaders: Arc<Mutex<HashMap<DigestInfo, DigestUploader>>>,
1057
16
) -> Result<FileInfo, Error> {
1058
16
    let is_executable = is_executable(&metadata, &full_path);
1059
16
    let file_size = metadata.len();
1060
16
    let file = fs::open_file(&full_path, 0, u64::MAX)
1061
16
        .await
1062
16
        .err_tip(|| 
format!0
("Could not open file {full_path:?}"))
?0
;
1063
1064
16
    let (digest, mut file) = hasher
1065
16
        .hasher()
1066
16
        .digest_for_file(&full_path, file.into_inner(), Some(file_size))
1067
16
        .await
1068
16
        .err_tip(|| 
format!0
("Failed to hash file in digest_for_file failed for {full_path:?}"))
?0
;
1069
1070
16
    let digest_uploader = match digest_uploaders.lock().entry(digest) {
1071
1
        std::collections::hash_map::Entry::Occupied(occupied_entry) => occupied_entry.get().clone(),
1072
15
        std::collections::hash_map::Entry::Vacant(vacant_entry) => vacant_entry
1073
15
            .insert(Arc::new(tokio::sync::OnceCell::new()))
1074
15
            .clone(),
1075
    };
1076
1077
    // Only upload a file with a given hash once.  The file may exist multiple
1078
    // times in the output with different names.
1079
16
    digest_uploader
1080
30
        .
get_or_try_init16
(async || {
1081
            // Only upload if the digest doesn't already exist, this should be
1082
            // a much cheaper operation than an upload.
1083
15
            let cas_store = cas_store.as_store_driver_pin();
1084
15
            let store_key: nativelink_util::store_trait::StoreKey<'_> = digest.into();
1085
15
            let has_start = std::time::Instant::now();
1086
15
            if cas_store
1087
15
                .has(store_key.borrow())
1088
15
                .await
1089
15
                .is_ok_and(|result| result.is_some())
1090
            {
1091
2
                trace!(
1092
                    ?digest,
1093
2
                    has_elapsed_ms = has_start.elapsed().as_millis(),
1094
                    "upload_file: digest already exists in CAS, skipping upload",
1095
                );
1096
2
                return Ok(());
1097
13
            }
1098
13
            trace!(
1099
                ?digest,
1100
13
                has_elapsed_ms = has_start.elapsed().as_millis(),
1101
13
                file_size = digest.size_bytes(),
1102
                "upload_file: digest not in CAS, starting upload",
1103
            );
1104
1105
13
            file.rewind().await.err_tip(|| "Could not rewind file")
?0
;
1106
1107
            // Note: For unknown reasons we appear to be hitting:
1108
            // https://github.com/rust-lang/rust/issues/92096
1109
            // or a similar issue if we try to use the non-store driver function, so we
1110
            // are using the store driver function here.
1111
13
            let store_key_for_upload = store_key.clone();
1112
13
            let file_upload_start = std::time::Instant::now();
1113
13
            let upload_result = cas_store
1114
13
                .update_with_whole_file(
1115
13
                    store_key_for_upload,
1116
13
                    full_path.as_ref().into(),
1117
13
                    file,
1118
13
                    UploadSizeInfo::ExactSize(digest.size_bytes()),
1119
13
                )
1120
13
                .await
1121
13
                .map(|_slot| ());
1122
13
            trace!(
1123
                ?digest,
1124
13
                upload_elapsed_ms = file_upload_start.elapsed().as_millis(),
1125
13
                success = upload_result.is_ok(),
1126
                "upload_file: update_with_whole_file completed",
1127
            );
1128
1129
13
            match upload_result {
1130
13
                Ok(()) => Ok(()),
1131
0
                Err(err) => {
1132
                    // Output uploads run concurrently and may overlap (e.g. a file is listed
1133
                    // both as an output file and inside an output directory). When another
1134
                    // upload has already moved the file into CAS, this update can fail with
1135
                    // NotFound even though the digest is now present. Per the RE spec, missing
1136
                    // outputs should be ignored, so treat this as success if the digest exists.
1137
0
                    if err.code == Code::NotFound
1138
0
                        && cas_store
1139
0
                            .has(store_key.borrow())
1140
0
                            .await
1141
0
                            .is_ok_and(|result| result.is_some())
1142
                    {
1143
0
                        Ok(())
1144
                    } else {
1145
0
                        Err(err)
1146
                    }
1147
                }
1148
            }
1149
30
        })
1150
16
        .await
1151
16
        .err_tip(|| 
format!0
("for {full_path:?}"))
?0
;
1152
1153
16
    let name = full_path
1154
16
        .as_ref()
1155
16
        .file_name()
1156
16
        .err_tip(|| 
format!0
("Expected file_name to exist on {full_path:?}"))
?0
1157
16
        .to_str()
1158
16
        .err_tip(|| 
{0
1159
0
            make_err!(
1160
0
                Code::Internal,
1161
                "Could not convert {:?} to string",
1162
                full_path
1163
            )
1164
0
        })?
1165
16
        .to_string();
1166
1167
16
    Ok(FileInfo {
1168
16
        name_or_path: NameOrPath::Name(name),
1169
16
        digest,
1170
16
        is_executable,
1171
16
    })
1172
16
}
1173
1174
2
async fn upload_symlink(
1175
2
    full_path: impl AsRef<Path> + Debug,
1176
2
    full_work_directory_path: impl AsRef<Path>,
1177
2
) -> Result<SymlinkInfo, Error> {
1178
2
    let full_target_path = fs::read_link(full_path.as_ref())
1179
2
        .await
1180
2
        .err_tip(|| 
format!0
("Could not get read_link path of {full_path:?}"))
?0
;
1181
1182
    // Detect if our symlink is inside our work directory, if it is find the
1183
    // relative path otherwise use the absolute path.
1184
2
    let target = if full_target_path.starts_with(full_work_directory_path.as_ref()) {
1185
0
        let full_target_path = RelativePath::from_path(&full_target_path)
1186
0
            .map_err(|v| make_err!(Code::Internal, "Could not convert {} to RelativePath", v))?;
1187
0
        RelativePath::from_path(full_work_directory_path.as_ref())
1188
0
            .map_err(|v| make_err!(Code::Internal, "Could not convert {} to RelativePath", v))?
1189
0
            .relative(full_target_path)
1190
0
            .normalize()
1191
0
            .into_string()
1192
    } else {
1193
2
        full_target_path
1194
2
            .to_str()
1195
2
            .err_tip(|| 
{0
1196
0
                make_err!(
1197
0
                    Code::Internal,
1198
                    "Could not convert '{:?}' to string",
1199
                    full_target_path
1200
                )
1201
0
            })?
1202
2
            .to_string()
1203
    };
1204
1205
2
    let name = full_path
1206
2
        .as_ref()
1207
2
        .file_name()
1208
2
        .err_tip(|| 
format!0
("Expected file_name to exist on {full_path:?}"))
?0
1209
2
        .to_str()
1210
2
        .err_tip(|| 
{0
1211
0
            make_err!(
1212
0
                Code::Internal,
1213
                "Could not convert {:?} to string",
1214
                full_path
1215
            )
1216
0
        })?
1217
2
        .to_string();
1218
1219
2
    Ok(SymlinkInfo {
1220
2
        name_or_path: NameOrPath::Name(name),
1221
2
        target,
1222
2
    })
1223
2
}
1224
1225
7
fn upload_directory<'a, P: AsRef<Path> + Debug + Send + Sync + Clone + 'a>(
1226
7
    cas_store: Pin<&'a impl StoreLike>,
1227
7
    full_dir_path: P,
1228
7
    full_work_directory: &'a str,
1229
7
    hasher: DigestHasherFunc,
1230
7
    digest_uploaders: Arc<Mutex<HashMap<DigestInfo, DigestUploader>>>,
1231
7
) -> BoxFuture<'a, Result<(Directory, VecDeque<ProtoDirectory>), Error>> {
1232
7
    Box::pin(async move {
1233
7
        let file_futures = FuturesUnordered::new();
1234
7
        let dir_futures = FuturesUnordered::new();
1235
7
        let symlink_futures = FuturesUnordered::new();
1236
        {
1237
7
            let (_permit, dir_handle) = fs::read_dir(&full_dir_path)
1238
7
                .await
1239
7
                .err_tip(|| 
format!0
("Error reading dir for reading {full_dir_path:?}"))
?0
1240
7
                .into_inner();
1241
7
            let mut dir_stream = ReadDirStream::new(dir_handle);
1242
            // Note: Try very hard to not leave file descriptors open. Try to keep them as short
1243
            // lived as possible. This is why we iterate the directory and then build a bunch of
1244
            // futures with all the work we are wanting to do then execute it. It allows us to
1245
            // close the directory iterator file descriptor, then open the child files/folders.
1246
18
            while let Some(
entry_result11
) = dir_stream.next().await {
1247
11
                let entry = entry_result.err_tip(|| "Error while iterating directory")
?0
;
1248
11
                let file_type = entry
1249
11
                    .file_type()
1250
11
                    .await
1251
11
                    .err_tip(|| 
format!0
("Error running file_type() on {entry:?}"))
?0
;
1252
11
                let full_path = full_dir_path.as_ref().join(entry.path());
1253
11
                if file_type.is_dir() {
1254
3
                    let full_dir_path = full_dir_path.clone();
1255
3
                    dir_futures.push(
1256
3
                        upload_directory(
1257
3
                            cas_store,
1258
3
                            full_path.clone(),
1259
3
                            full_work_directory,
1260
3
                            hasher,
1261
3
                            digest_uploaders.clone(),
1262
                        )
1263
3
                        .and_then(|(dir, all_dirs)| async move {
1264
3
                            let directory_name = full_path
1265
3
                                .file_name()
1266
3
                                .err_tip(|| 
{0
1267
0
                                    format!("Expected file_name to exist on {full_dir_path:?}")
1268
0
                                })?
1269
3
                                .to_str()
1270
3
                                .err_tip(|| 
{0
1271
0
                                    make_err!(
1272
0
                                        Code::Internal,
1273
                                        "Could not convert {:?} to string",
1274
                                        full_dir_path
1275
                                    )
1276
0
                                })?
1277
3
                                .to_string();
1278
1279
3
                            let digest =
1280
3
                                serialize_and_upload_message(&dir, cas_store, &mut hasher.hasher())
1281
3
                                    .await
1282
3
                                    .err_tip(|| 
format!0
("for {}",
full_path.display()0
))
?0
;
1283
1284
3
                            Result::<(DirectoryNode, VecDeque<Directory>), Error>::Ok((
1285
3
                                DirectoryNode {
1286
3
                                    name: directory_name,
1287
3
                                    digest: Some(digest.into()),
1288
3
                                },
1289
3
                                all_dirs,
1290
3
                            ))
1291
6
                        })
1292
3
                        .boxed(),
1293
                    );
1294
8
                } else if file_type.is_file() {
1295
7
                    let digest_uploaders = digest_uploaders.clone();
1296
7
                    file_futures.push(async move {
1297
7
                        let metadata = fs::metadata(&full_path)
1298
7
                            .await
1299
7
                            .err_tip(|| 
format!0
("Could not open file {}",
full_path.display()0
))
?0
;
1300
7
                        upload_file(cas_store, &full_path, hasher, metadata, digest_uploaders)
1301
7
                            .map_ok(TryInto::try_into)
1302
7
                            .await
?0
1303
7
                    });
1304
1
                } else if file_type.is_symlink() {
1305
1
                    symlink_futures.push(
1306
1
                        upload_symlink(full_path, &full_work_directory)
1307
1
                            .map(|symlink| symlink
?0
.try_into()),
1308
                    );
1309
0
                }
1310
            }
1311
        }
1312
1313
7
        let dir_entries = dir_futures
1314
7
            .try_collect::<Vec<(DirectoryNode, VecDeque<Directory>)>>()
1315
7
            .await
?0
;
1316
7
        let (mut file_nodes, mut symlinks) = try_join(
1317
7
            file_futures.try_collect::<Vec<FileNode>>(),
1318
7
            symlink_futures.try_collect::<Vec<SymlinkNode>>(),
1319
7
        )
1320
7
        .await
?0
;
1321
1322
7
        let mut directory_nodes = Vec::with_capacity(dir_entries.len());
1323
        // For efficiency we use a deque because it allows cheap concat of Vecs.
1324
        // We make the assumption here that when performance is important it is because
1325
        // our directory is quite large. This allows us to cheaply merge large amounts of
1326
        // directories into one VecDeque. Then after we are done we need to collapse it
1327
        // down into a single Vec.
1328
7
        let mut all_child_directories = VecDeque::with_capacity(dir_entries.len());
1329
7
        for (
directory_node3
,
mut recursive_child_directories3
) in dir_entries {
1330
3
            directory_nodes.push(directory_node);
1331
3
            all_child_directories.append(&mut recursive_child_directories);
1332
3
        }
1333
1334
7
        file_nodes.sort_unstable_by(|a, b| 
a.name1
.
cmp1
(
&b.name1
));
1335
7
        directory_nodes.sort_unstable_by(|a, b| 
a.name0
.
cmp0
(
&b.name0
));
1336
7
        symlinks.sort_unstable_by(|a, b| 
a.name0
.
cmp0
(
&b.name0
));
1337
1338
7
        let directory = Directory {
1339
7
            files: file_nodes,
1340
7
            directories: directory_nodes,
1341
7
            symlinks,
1342
7
            node_properties: None, // We don't support file properties.
1343
7
        };
1344
7
        all_child_directories.push_back(directory.clone());
1345
1346
7
        Ok((directory, all_child_directories))
1347
7
    })
1348
7
}
1349
1350
0
async fn process_side_channel_file(
1351
0
    side_channel_file: Cow<'_, OsStr>,
1352
0
    args: &[&OsStr],
1353
0
    timeout: Duration,
1354
0
) -> Result<Option<Error>, Error> {
1355
0
    let mut json_contents = String::new();
1356
    {
1357
        // Note: Scoping `file_slot` allows the file_slot semaphore to be released faster.
1358
0
        let mut file_slot = match fs::open_file(side_channel_file, 0, u64::MAX).await {
1359
0
            Ok(file_slot) => file_slot,
1360
0
            Err(e) => {
1361
0
                if e.code != Code::NotFound {
1362
0
                    return Err(e).err_tip(|| "Error opening side channel file");
1363
0
                }
1364
                // Note: If file does not exist, it's ok. Users are not required to create this file.
1365
0
                return Ok(None);
1366
            }
1367
        };
1368
0
        file_slot
1369
0
            .read_to_string(&mut json_contents)
1370
0
            .await
1371
0
            .err_tip(|| "Error reading side channel file")?;
1372
    }
1373
1374
0
    let side_channel_info: SideChannelInfo = serde_json5::from_str(&json_contents)
1375
0
        .map_err(Error::from)
1376
0
        .err_tip(|| "Could not convert contents of side channel file (json) to SideChannelInfo")?;
1377
0
    Ok(side_channel_info.failure.map(|failure| match failure {
1378
        SideChannelFailureReason::Timeout => {
1379
0
            let join_args = args.join(OsStr::new(" "));
1380
0
            let command = join_args.to_string_lossy();
1381
0
            warn!(%command, timeout=timeout.as_secs_f32(), "Side channel timeout for command");
1382
0
            Error::new(
1383
0
                Code::DeadlineExceeded,
1384
0
                format!(
1385
                    "Command '{}' timed out after {} seconds",
1386
                    command,
1387
0
                    timeout.as_secs_f32()
1388
                ),
1389
            )
1390
        }
1391
0
    }))
1392
0
}
1393
1394
226
async fn do_cleanup(
1395
226
    running_actions_manager: &Arc<RunningActionsManagerImpl>,
1396
226
    operation_id: &OperationId,
1397
226
    action_directory: &str,
1398
226
) -> Result<(), Error> {
1399
    // Mark this operation as being cleaned up
1400
226
    let Some(_cleaning_guard) = running_actions_manager.perform_cleanup(operation_id.clone())
1401
    else {
1402
        // Cleanup is already happening elsewhere.
1403
0
        return Ok(());
1404
    };
1405
1406
226
    debug!("Worker cleaning up");
1407
    // Note: We need to be careful to keep trying to cleanup even if one of the steps fails.
1408
226
    let remove_dir_result = fs::remove_dir_all(action_directory)
1409
226
        .await
1410
226
        .err_tip(|| 
format!0
("Could not remove working directory {action_directory}"));
1411
1412
226
    if let Err(
err0
) = running_actions_manager.cleanup_action(operation_id) {
1413
0
        error!(%operation_id, ?err, "Error cleaning up action");
1414
0
        Result::<(), Error>::Err(err).merge(remove_dir_result)
1415
226
    } else if let Err(
err0
) = remove_dir_result {
1416
0
        error!(%operation_id, ?err, "Error removing working directory");
1417
0
        Err(err)
1418
    } else {
1419
226
        Ok(())
1420
    }
1421
226
}
1422
1423
pub trait RunningAction: Sync + Send + Sized + Unpin + 'static {
1424
    /// Returns the action id of the action.
1425
    fn get_operation_id(&self) -> &OperationId;
1426
1427
    /// Anything that needs to execute before the actions is actually executed should happen here.
1428
    fn prepare_action(self: Arc<Self>) -> impl Future<Output = Result<Arc<Self>, Error>> + Send;
1429
1430
    /// Actually perform the execution of the action.
1431
    fn execute(self: Arc<Self>) -> impl Future<Output = Result<Arc<Self>, Error>> + Send;
1432
1433
    /// Any uploading, processing or analyzing of the results should happen here.
1434
    fn upload_results(self: Arc<Self>) -> impl Future<Output = Result<Arc<Self>, Error>> + Send;
1435
1436
    /// Cleanup any residual files, handles or other junk resulting from running the action.
1437
    fn cleanup(self: Arc<Self>) -> impl Future<Output = Result<Arc<Self>, Error>> + Send;
1438
1439
    /// Returns the final result. As a general rule this action should be thought of as
1440
    /// a consumption of `self`, meaning once a return happens here the lifetime of `Self`
1441
    /// is over and any action performed on it after this call is undefined behavior.
1442
    fn get_finished_result(
1443
        self: Arc<Self>,
1444
    ) -> impl Future<Output = Result<ActionResult, Error>> + Send;
1445
1446
    /// Returns worker-observed resource usage captured while this action ran.
1447
    fn resource_usage(&self) -> Option<ActionResourceUsage>;
1448
1449
    /// Returns the work directory of the action.
1450
    fn get_work_directory(&self) -> &String;
1451
}
1452
1453
#[derive(Debug)]
1454
struct RunningActionImplExecutionResult {
1455
    stdout: Bytes,
1456
    stderr: Bytes,
1457
    exit_code: i32,
1458
    resource_usage: Option<ActionResourceUsage>,
1459
}
1460
1461
#[derive(Debug)]
1462
struct RunningActionImplState {
1463
    command_proto: Option<ProtoCommand>,
1464
    // TODO(palfrey) Kill is not implemented yet, but is instrumented.
1465
    // However, it is used if the worker disconnects to destroy current jobs.
1466
    kill_channel_tx: Option<oneshot::Sender<()>>,
1467
    kill_channel_rx: Option<oneshot::Receiver<()>>,
1468
    execution_result: Option<RunningActionImplExecutionResult>,
1469
    action_result: Option<ActionResult>,
1470
    resource_usage: Option<ActionResourceUsage>,
1471
    execution_metadata: ExecutionMetadata,
1472
    // If there was an internal error, this will be set.
1473
    // This should NOT be set if everything was fine, but the process had a
1474
    // non-zero exit code. Instead this should be used for internal errors
1475
    // that prevented the action from running, upload failures, timeouts, exc...
1476
    // but we have (or could have) the action results (like stderr/stdout).
1477
    error: Option<Error>,
1478
}
1479
1480
#[derive(Debug)]
1481
pub struct RunningActionImpl {
1482
    operation_id: OperationId,
1483
    action_directory: String,
1484
    work_directory: String,
1485
    action_info: ActionInfo,
1486
    /// `Some` only when the manager was configured with
1487
    /// `experimental_active_input_leases`; `None` leaves eviction untouched.
1488
    input_lease: Option<Arc<ActionInputLease>>,
1489
    timeout: Duration,
1490
    running_actions_manager: Arc<RunningActionsManagerImpl>,
1491
    state: Mutex<RunningActionImplState>,
1492
    has_manager_entry: AtomicBool,
1493
    did_cleanup: AtomicBool,
1494
}
1495
1496
impl RunningActionImpl {
1497
229
    pub fn new(
1498
229
        execution_metadata: ExecutionMetadata,
1499
229
        operation_id: OperationId,
1500
229
        action_directory: String,
1501
229
        action_info: ActionInfo,
1502
229
        timeout: Duration,
1503
229
        running_actions_manager: Arc<RunningActionsManagerImpl>,
1504
229
    ) -> Self {
1505
229
        let work_directory = format!("{}/{}", action_directory, "work");
1506
229
        let input_lease = running_actions_manager.active_input_leases.then(|| 
{1
1507
1
            ActionInputLease::new(
1508
1
                running_actions_manager.cas_store.as_ref(),
1509
1
                action_info.command_digest,
1510
1
                action_info.input_root_digest,
1511
            )
1512
1
        });
1513
229
        let (kill_channel_tx, kill_channel_rx) = oneshot::channel();
1514
229
        Self {
1515
229
            operation_id,
1516
229
            action_directory,
1517
229
            work_directory,
1518
229
            action_info,
1519
229
            input_lease,
1520
229
            timeout,
1521
229
            running_actions_manager,
1522
229
            state: Mutex::new(RunningActionImplState {
1523
229
                command_proto: None,
1524
229
                kill_channel_rx: Some(kill_channel_rx),
1525
229
                kill_channel_tx: Some(kill_channel_tx),
1526
229
                execution_result: None,
1527
229
                action_result: None,
1528
229
                resource_usage: None,
1529
229
                execution_metadata,
1530
229
                error: None,
1531
229
            }),
1532
229
            // Set to true only after the action is inserted into the manager.
1533
229
            // The constructor can fail the operation-id uniqueness check
1534
229
            // immediately after this object is created.
1535
229
            has_manager_entry: AtomicBool::new(false),
1536
229
            // Only needs to be cleaned up after a prepare_action call, set there.
1537
229
            did_cleanup: AtomicBool::new(true),
1538
229
        }
1539
229
    }
1540
1541
    #[allow(
1542
        clippy::missing_const_for_fn,
1543
        reason = "False positive on stable, but not on nightly"
1544
    )]
1545
0
    fn metrics(&self) -> &Arc<Metrics> {
1546
0
        &self.running_actions_manager.metrics
1547
0
    }
1548
1549
    /// Prepares any actions needed to execute this action. This action will do the following:
1550
    ///
1551
    /// * Download any files needed to execute the action
1552
    /// * Build a folder with all files needed to execute the action.
1553
    ///
1554
    /// This function will aggressively download and spawn potentially thousands of futures. It is
1555
    /// up to the stores to rate limit if needed.
1556
25
    async fn inner_prepare_action(self: Arc<Self>) -> Result<Arc<Self>, Error> {
1557
25
        {
1558
25
            let mut state = self.state.lock();
1559
25
            state.execution_metadata.input_fetch_start_timestamp =
1560
25
                (self.running_actions_manager.callbacks.now_fn)();
1561
25
        }
1562
25
        let command = {
1563
            // Download and build out our input files/folders. Also fetch and decode our Command.
1564
25
            let command_fut = self.metrics().get_proto_command_from_store.wrap(async {
1565
25
                get_and_decode_digest::<ProtoCommand>(
1566
25
                    self.running_actions_manager.cas_store.as_ref(),
1567
25
                    self.action_info.command_digest.into(),
1568
25
                )
1569
25
                .await
1570
25
                .err_tip(|| "Converting command_digest to Command")
1571
25
            });
1572
25
            let filesystem_store_pin =
1573
25
                Pin::new(self.running_actions_manager.filesystem_store.as_ref());
1574
25
            let (command, ()) = try_join(command_fut, async {
1575
25
                fs::create_dir(&self.work_directory)
1576
25
                    .await
1577
25
                    .err_tip(|| 
format!0
("Error creating work directory {}",
self.work_directory0
))
?0
;
1578
                // Now the work directory has been created, we have to clean up.
1579
25
                self.did_cleanup.store(false, Ordering::Release);
1580
                // Download the input files/folder and place them into the temp directory.
1581
                // Use directory cache if available for better performance.
1582
25
                self.metrics()
1583
25
                    .download_to_directory
1584
25
                    .wrap(prepare_action_inputs_with_lease(
1585
25
                        &self.running_actions_manager.directory_cache,
1586
25
                        &self.running_actions_manager.cas_store,
1587
25
                        filesystem_store_pin,
1588
25
                        &self.action_info.input_root_digest,
1589
25
                        &self.work_directory,
1590
25
                        self.input_lease.clone(),
1591
25
                    ))
1592
25
                    .await
1593
25
            })
1594
25
            .await
?0
;
1595
25
            command
1596
        };
1597
        {
1598
            // Create all directories needed for our output paths. This is required by the bazel spec.
1599
25
            let prepare_output_directories = |output_file| 
{16
1600
16
                let full_output_path = if command.working_directory.is_empty() {
1601
4
                    format!("{}/{}", self.work_directory, output_file)
1602
                } else {
1603
12
                    format!(
1604
                        "{}/{}/{}",
1605
12
                        self.work_directory, command.working_directory, output_file
1606
                    )
1607
                };
1608
16
                async move {
1609
16
                    let full_parent_path = Path::new(&full_output_path)
1610
16
                        .parent()
1611
16
                        .err_tip(|| 
format!0
("Parent path for {full_output_path} has no parent"))
?0
;
1612
16
                    fs::create_dir_all(full_parent_path).await.err_tip(|| 
{0
1613
0
                        format!(
1614
                            "Error creating output directory {} (file)",
1615
0
                            full_parent_path.display()
1616
                        )
1617
0
                    })?;
1618
16
                    Result::<(), Error>::Ok(())
1619
16
                }
1620
16
            };
1621
25
            self.metrics()
1622
25
                .prepare_output_files
1623
25
                .wrap(try_join_all(
1624
25
                    command.output_files.iter().map(prepare_output_directories),
1625
25
                ))
1626
25
                .await
?0
;
1627
25
            self.metrics()
1628
25
                .prepare_output_paths
1629
25
                .wrap(try_join_all(
1630
25
                    command.output_paths.iter().map(prepare_output_directories),
1631
25
                ))
1632
25
                .await
?0
;
1633
        }
1634
25
        debug!(?command, "Worker received command");
1635
25
        {
1636
25
            let mut state = self.state.lock();
1637
25
            state.command_proto = Some(command);
1638
25
            state.execution_metadata.input_fetch_completed_timestamp =
1639
25
                (self.running_actions_manager.callbacks.now_fn)();
1640
25
        }
1641
25
        Ok(self)
1642
25
    }
1643
1644
22
    pub fn canonicalise_path(
1645
22
        self: &Arc<Self>,
1646
22
        arg: &OsStr,
1647
22
        working_directory: &String,
1648
22
    ) -> Result<PathBuf, Error> {
1649
        // If the program contains a slash, we treat it as a path and resolve it relative to the work directory.
1650
22
        Ok(if Path::new(arg).components().count() > 1 {
1651
5
            let canonical_path = PathBuf::from(&self.work_directory)
1652
5
                .join(working_directory)
1653
5
                .join(arg);
1654
5
            if cfg!(target_os = "windows") {
1655
                // Workaround for https://github.com/rust-lang/rust/issues/42869 using a windows-specific crate
1656
0
                dunce::canonicalize(canonical_path)
1657
            } else {
1658
5
                canonical_path.canonicalize()
1659
            }
1660
5
            .err_tip(|| 
{1
1661
1
                format!(
1662
                    "Could not canonicalize path for command root {}.",
1663
1
                    arg.to_string_lossy()
1664
                )
1665
1
            })?
1666
        } else {
1667
17
            PathBuf::from(arg)
1668
        })
1669
22
    }
1670
1671
21
    async fn inner_execute(self: Arc<Self>) -> Result<Arc<Self>, Error> {
1672
21
        let (command_proto, mut kill_channel_rx) = {
1673
21
            let mut state = self.state.lock();
1674
21
            state.execution_metadata.execution_start_timestamp =
1675
21
                (self.running_actions_manager.callbacks.now_fn)();
1676
            (
1677
21
                state
1678
21
                    .command_proto
1679
21
                    .take()
1680
21
                    .err_tip(|| "Expected state to have command_proto in execute()")
?0
,
1681
21
                state
1682
21
                    .kill_channel_rx
1683
21
                    .take()
1684
21
                    .err_tip(|| "Expected state to have kill_channel_rx in execute()")
?0
1685
                    // This is important as we may be killed at any point.
1686
21
                    .fuse(),
1687
            )
1688
        };
1689
21
        if command_proto.arguments.is_empty() {
1690
0
            return Err(make_input_err!("No arguments provided in Command proto"));
1691
21
        }
1692
21
        let args: Vec<&OsStr> = if let Some(
entrypoint0
) = &self
1693
21
            .running_actions_manager
1694
21
            .execution_configuration
1695
21
            .entrypoint
1696
        {
1697
0
            core::iter::once(entrypoint.as_ref())
1698
0
                .chain(command_proto.arguments.iter().map(AsRef::as_ref))
1699
0
                .collect()
1700
        } else {
1701
21
            command_proto.arguments.iter().map(AsRef::as_ref).collect()
1702
        };
1703
        // TODO(palfrey): This should probably be in debug, but currently
1704
        //                    that's too busy and we often rely on this to
1705
        //                    figure out toolchain misconfiguration issues.
1706
        //                    De-bloat the `debug` level by using the `trace`
1707
        //                    level more effectively and adjust this.
1708
21
        info!(?args, "Executing command");
1709
1710
21
        let 
program20
= self
1711
21
            .canonicalise_path(args[0], &command_proto.working_directory)
1712
21
            .err_tip(|| 
format!1
("Canonicalisation failure. Command={args:#?}"))
?1
;
1713
20
        if let Some(
wire_format_result2
) = action_supports_persistent_workers(&self.action_info) {
1714
2
            match wire_format_result {
1715
2
                Ok(wire_format) => {
1716
2
                    let command_argv = os_args_to_strings(&args)
?0
;
1717
2
                    let key = WorkerKey::from_argv(&command_argv, wire_format)
?0
;
1718
2
                    let request = WorkRequest {
1719
2
                        arguments: persistent_worker_request_arguments(&command_argv),
1720
2
                        inputs: Vec::<PersistentWorkerInput>::new(),
1721
                        request_id: 0,
1722
                        cancel: false,
1723
                        verbosity: 0,
1724
2
                        sandbox_dir: if command_proto.working_directory.is_empty() {
1725
2
                            self.work_directory.clone()
1726
                        } else {
1727
0
                            format!(
1728
                                "{}/{}",
1729
0
                                self.work_directory, command_proto.working_directory
1730
                            )
1731
                        },
1732
                    };
1733
2
                    let worker_cwd =
1734
2
                        PathBuf::from(&self.running_actions_manager.root_action_directory);
1735
1736
2
                    match self
1737
2
                        .running_actions_manager
1738
2
                        .persistent_worker_pool
1739
2
                        .acquire(key.clone(), &program, &worker_cwd)
1740
2
                        .await
1741
                    {
1742
2
                        Ok(mut lease) => {
1743
2
                            let timer = self.metrics().child_process.begin_timer();
1744
2
                            let dispatch_result = {
1745
2
                                let dispatch_fut =
1746
2
                                    lease.worker().dispatch_with_timeout(&request, self.timeout);
1747
2
                                tokio::pin!(dispatch_fut);
1748
2
                                tokio::select! {
1749
2
                                    result = &mut dispatch_fut => Some(result),
1750
2
                                    _ = &mut kill_channel_rx => 
None0
,
1751
                                }
1752
                            };
1753
2
                            let response = match dispatch_result {
1754
2
                                Some(Ok(response)) => {
1755
2
                                    lease.release(true).await;
1756
2
                                    response
1757
                                }
1758
0
                                Some(Err(err)) => {
1759
0
                                    lease.release(false).await;
1760
0
                                    return Err(err).err_tip(|| {
1761
0
                                        format!("Dispatching action to persistent worker {key:?}")
1762
0
                                    });
1763
                                }
1764
                                None => {
1765
0
                                    drop(timer);
1766
0
                                    lease.release(false).await;
1767
0
                                    {
1768
0
                                        let mut state = self.state.lock();
1769
0
                                        state.error = Error::merge_option(
1770
0
                                            state.error.take(),
1771
0
                                            Some(Error::new(
1772
0
                                                Code::Cancelled,
1773
0
                                                format!(
1774
0
                                                    "Persistent worker command '{}' was killed by scheduler",
1775
0
                                                    args.join(OsStr::new(" ")).to_string_lossy()
1776
0
                                                ),
1777
0
                                            )),
1778
0
                                        );
1779
0
                                        state.command_proto = Some(command_proto);
1780
0
                                        state.execution_result =
1781
0
                                            Some(RunningActionImplExecutionResult {
1782
0
                                                stdout: Bytes::new(),
1783
0
                                                stderr: Bytes::new(),
1784
0
                                                exit_code: EXIT_CODE_FOR_SIGNAL,
1785
0
                                                resource_usage: None,
1786
0
                                            });
1787
0
                                        state.execution_metadata.execution_completed_timestamp =
1788
0
                                            (self.running_actions_manager.callbacks.now_fn)();
1789
0
                                    }
1790
0
                                    return Ok(self);
1791
                                }
1792
                            };
1793
2
                            timer.measure();
1794
1795
2
                            if response.exit_code == 0 {
1796
2
                                self.metrics().child_process_success_error_code.inc();
1797
2
                            } else {
1798
0
                                self.metrics().child_process_failure_error_code.inc();
1799
0
                            }
1800
2
                            info!(?args, ?key, "Persistent worker command complete");
1801
2
                            {
1802
2
                                let mut state = self.state.lock();
1803
2
                                state.command_proto = Some(command_proto);
1804
2
                                state.execution_result = Some(RunningActionImplExecutionResult {
1805
2
                                    stdout: Bytes::new(),
1806
2
                                    stderr: Bytes::from(response.output),
1807
2
                                    exit_code: response.exit_code,
1808
2
                                    resource_usage: None,
1809
2
                                });
1810
2
                                state.execution_metadata.execution_completed_timestamp =
1811
2
                                    (self.running_actions_manager.callbacks.now_fn)();
1812
2
                            }
1813
2
                            return Ok(self);
1814
                        }
1815
0
                        Err(err) => {
1816
0
                            info!(
1817
                                ?err,
1818
                                ?key,
1819
                                "Falling back to one-shot execution; persistent worker unavailable"
1820
                            );
1821
                        }
1822
                    }
1823
                }
1824
0
                Err(err) => {
1825
0
                    info!(
1826
                        ?err,
1827
                        "Falling back to one-shot execution; unsupported persistent worker protocol"
1828
                    );
1829
                }
1830
            }
1831
18
        }
1832
1833
18
        let mut command_builder = process::Command::new(program);
1834
        #[cfg(target_family = "unix")]
1835
18
        command_builder.arg0(args[0]);
1836
18
        command_builder
1837
18
            .args(&args[1..])
1838
18
            .kill_on_drop(true)
1839
18
            .stdin(Stdio::null())
1840
18
            .stdout(Stdio::piped())
1841
18
            .stderr(Stdio::piped())
1842
18
            .current_dir(format!(
1843
18
                "{}/{}",
1844
18
                self.work_directory, command_proto.working_directory
1845
18
            ))
1846
18
            .env_clear();
1847
1848
18
        let requested_timeout = if self.action_info.timeout.is_zero() {
1849
16
            self.running_actions_manager.max_action_timeout
1850
        } else {
1851
2
            self.action_info.timeout
1852
        };
1853
1854
18
        let mut maybe_side_channel_file: Option<Cow<'_, OsStr>> = None;
1855
18
        if let Some(
additional_environment0
) = &self
1856
18
            .running_actions_manager
1857
18
            .execution_configuration
1858
18
            .additional_environment
1859
        {
1860
0
            for (name, source) in additional_environment {
1861
0
                let value = match source {
1862
0
                    EnvironmentSource::Property(property) => self
1863
0
                        .action_info
1864
0
                        .platform_properties
1865
0
                        .get(property)
1866
0
                        .map_or_else(|| Cow::Borrowed(""), |v| Cow::Borrowed(v.as_str())),
1867
0
                    EnvironmentSource::Value(value) => Cow::Borrowed(value.as_str()),
1868
                    EnvironmentSource::FromEnvironment => {
1869
0
                        Cow::Owned(env::var(name).unwrap_or_default())
1870
                    }
1871
                    EnvironmentSource::TimeoutMillis => {
1872
0
                        Cow::Owned(requested_timeout.as_millis().to_string())
1873
                    }
1874
                    EnvironmentSource::SideChannelFile => {
1875
0
                        let file_cow =
1876
0
                            format!("{}/{}", self.action_directory, Uuid::new_v4().simple());
1877
0
                        maybe_side_channel_file = Some(Cow::Owned(file_cow.clone().into()));
1878
0
                        Cow::Owned(file_cow)
1879
                    }
1880
                    EnvironmentSource::ActionDirectory => {
1881
0
                        Cow::Borrowed(self.action_directory.as_str())
1882
                    }
1883
                };
1884
0
                command_builder.env(name, value.as_ref());
1885
            }
1886
18
        }
1887
1888
        #[cfg(target_family = "unix")]
1889
18
        let envs = &command_proto.environment_variables;
1890
        // If SystemRoot is not set on windows we set it to default. Failing to do
1891
        // this causes all commands to fail.
1892
        #[cfg(target_family = "windows")]
1893
        let envs = {
1894
            let mut envs = command_proto.environment_variables.clone();
1895
            if !envs.iter().any(|v| v.name.to_uppercase() == "SYSTEMROOT") {
1896
                envs.push(
1897
                    nativelink_proto::build::bazel::remote::execution::v2::command::EnvironmentVariable {
1898
                        name: "SystemRoot".to_string(),
1899
                        value: "C:\\Windows".to_string(),
1900
                    },
1901
                );
1902
            }
1903
            if !envs.iter().any(|v| v.name.to_uppercase() == "PATH") {
1904
                envs.push(
1905
                    nativelink_proto::build::bazel::remote::execution::v2::command::EnvironmentVariable {
1906
                        name: "PATH".to_string(),
1907
                        value: "C:\\Windows\\System32".to_string(),
1908
                    },
1909
                );
1910
            }
1911
            envs
1912
        };
1913
18
        for environment_variable in envs {
1914
18
            command_builder.env(&environment_variable.name, &environment_variable.value);
1915
18
        }
1916
1917
        // Sandboxing of the command if we are running on Linux, this resolves issues where
1918
        // children can spawn children and also provides better reproducibility.
1919
        #[cfg(target_os = "linux")]
1920
        {
1921
18
            let use_namespaces = self.running_actions_manager.use_namespaces;
1922
1923
18
            if !
matches!17
(use_namespaces, UseNamespaces::No) {
1924
17
                let root_action_directory = std::ffi::CString::new(
1925
17
                    self.running_actions_manager.root_action_directory.clone(),
1926
                )
1927
17
                .err_tip(|| "In RunningActionImpl::inner_execute()")
?0
;
1928
17
                let action_directory = std::ffi::CString::new(self.action_directory.clone())
1929
17
                    .err_tip(|| "In RunningActionImpl::inner_execute()")
?0
;
1930
1931
                // SAFETY: This function is specifically designed to operate in a async-signal-safe
1932
                // environment.
1933
                unsafe {
1934
17
                    command_builder.pre_exec(move || 
{0
1935
0
                        crate::namespace_utils::configure_namespace(
1936
0
                            matches!(use_namespaces, UseNamespaces::YesAndMount),
1937
0
                            &root_action_directory,
1938
0
                            &action_directory,
1939
                        )
1940
0
                    });
1941
                }
1942
1
            }
1943
1944
            // Run the action as its own process-group leader (pgid == child
1945
            // pid). The resource-usage sampler attributes memory by process
1946
            // group, so this keeps the whole action together — including
1947
            // processes reparented to the worker when an intermediate shell
1948
            // exits — and never conflates it with the worker's own group.
1949
18
            command_builder.process_group(0);
1950
        }
1951
1952
18
        let mut child_process = command_builder
1953
18
            .spawn()
1954
18
            .err_tip(|| 
format!0
("Could not execute command {args:?}"))
?0
;
1955
18
        let mut stdout_reader = child_process
1956
18
            .stdout
1957
18
            .take()
1958
18
            .err_tip(|| "Expected stdout to exist on command this should never happen")
?0
;
1959
18
        let mut stderr_reader = child_process
1960
18
            .stderr
1961
18
            .take()
1962
18
            .err_tip(|| "Expected stderr to exist on command this should never happen")
?0
;
1963
1964
        #[cfg(target_os = "linux")]
1965
        // Wrap the child process to send SIGTERM rather than SIGKILL if namespaced to
1966
        // prevent zombie processes.
1967
18
        let child_process = crate::namespace_utils::MaybeNamespacedChild::new(
1968
17
            !matches!(
1969
18
                self.running_actions_manager.use_namespaces,
1970
                UseNamespaces::No,
1971
            ),
1972
18
            child_process,
1973
        );
1974
1975
        #[cfg(target_os = "linux")]
1976
18
        let mut maybe_resource_usage_sampler =
1977
18
            child_process.id().map(start_action_resource_usage_sampler);
1978
1979
18
        let mut child_process_guard = guard(child_process, |mut child_process| 
{0
1980
0
            let result: Result<Option<std::process::ExitStatus>, std::io::Error> =
1981
0
                child_process.try_wait();
1982
0
            match result {
1983
0
                Ok(res) if res.is_some() => {
1984
0
                    // The child already exited, probably a timeout or kill operation
1985
0
                }
1986
0
                result => {
1987
0
                    error!(
1988
                        ?result,
1989
                        "Child process was not cleaned up before dropping the call to execute(), killing in background spawn."
1990
                    );
1991
0
                    background_spawn!("running_actions_manager_kill_child_process", async move {
1992
0
                        drop(child_process.kill().await);
1993
0
                    });
1994
                }
1995
            }
1996
0
        });
1997
1998
18
        let all_stdout_fut = spawn!("stdout_reader", async move {
1999
18
            let mut all_stdout = BytesMut::new();
2000
            loop {
2001
23
                let sz = stdout_reader
2002
23
                    .read_buf(&mut all_stdout)
2003
23
                    .await
2004
23
                    .err_tip(|| "Error reading stdout stream")
?0
;
2005
23
                if sz == 0 {
2006
18
                    break; // EOF.
2007
5
                }
2008
            }
2009
18
            Result::<Bytes, Error>::Ok(all_stdout.freeze())
2010
18
        });
2011
18
        let all_stderr_fut = spawn!("stderr_reader", async move {
2012
18
            let mut all_stderr = BytesMut::new();
2013
            loop {
2014
22
                let sz = stderr_reader
2015
22
                    .read_buf(&mut all_stderr)
2016
22
                    .await
2017
22
                    .err_tip(|| "Error reading stderr stream")
?0
;
2018
22
                if sz == 0 {
2019
18
                    break; // EOF.
2020
4
                }
2021
            }
2022
18
            Result::<Bytes, Error>::Ok(all_stderr.freeze())
2023
18
        });
2024
18
        let mut killed_action = false;
2025
2026
18
        let timer = self.metrics().child_process.begin_timer();
2027
18
        let mut sleep_fut = (self.running_actions_manager.callbacks.sleep_fn)(self.timeout).fuse();
2028
        loop {
2029
22
            tokio::select! {
2030
22
                () = &mut sleep_fut => {
2031
2
                    self.running_actions_manager.metrics.task_timeouts.inc();
2032
2
                    killed_action = true;
2033
2
                    if let Err(
err0
) = child_process_guard.kill().await {
2034
0
                        error!(
2035
                            ?err,
2036
                            "Could not kill process in RunningActionsManager for action timeout",
2037
                        );
2038
2
                    }
2039
                    {
2040
2
                        let joined_command = args.join(OsStr::new(" "));
2041
2
                        let command = joined_command.to_string_lossy();
2042
2
                        info!(
2043
2
                            seconds = self.action_info.timeout.as_secs_f32(),
2044
                            %command,
2045
                            "Command timed out"
2046
                        );
2047
2
                        let mut state = self.state.lock();
2048
2
                        state.error = Error::merge_option(state.error.take(), Some(Error::new(
2049
2
                            Code::DeadlineExceeded,
2050
2
                            format!(
2051
2
                                "Command '{}' timed out after {} seconds",
2052
2
                                command,
2053
2
                                self.action_info.timeout.as_secs_f32()
2054
2
                            )
2055
2
                        )));
2056
                    }
2057
                },
2058
22
                
maybe_exit_status18
= child_process_guard.wait() => {
2059
                    // Defuse our guard so it does not try to cleanup and make senseless logs.
2060
18
                    drop(ScopeGuard::<_, _>::into_inner(child_process_guard));
2061
18
                    let exit_status = maybe_exit_status.err_tip(|| "Failed to collect exit code of process")
?0
;
2062
                    // TODO(palfrey) We should implement stderr/stdout streaming to client here.
2063
                    // If we get killed before the stream is started, then these will lock up.
2064
                    // TODO(palfrey) There is a significant bug here. If we kill the action and the action creates
2065
                    // child processes, it can create zombies. See: https://github.com/tracemachina/nativelink/issues/225
2066
18
                    let (stdout, stderr) = if killed_action {
2067
4
                        drop(timer);
2068
4
                        (Bytes::new(), Bytes::new())
2069
                    } else {
2070
14
                        timer.measure();
2071
14
                        let (maybe_all_stdout, maybe_all_stderr) = tokio::join!(all_stdout_fut, all_stderr_fut);
2072
                        (
2073
14
                            maybe_all_stdout.err_tip(|| "Internal error reading from stdout of worker task")
?0
?0
,
2074
14
                            maybe_all_stderr.err_tip(|| "Internal error reading from stderr of worker task")
?0
?0
2075
                        )
2076
                    };
2077
2078
18
                    let exit_code = exit_status.code().map_or_else(|| 
{4
2079
                        // No exit code means the runner was terminated by a
2080
                        // signal. SIGKILL on Linux is the kernel OOM killer's
2081
                        // weapon of choice, so flag this for operators trying
2082
                        // to correlate action failures with kubectl-top
2083
                        // memory pressure.
2084
4
                        warn!(
2085
                            ?args,
2086
                            "Runner subprocess terminated by signal (no exit code); likely OOMKilled \
2087
                             or externally killed. If this repeats for the same action, raise \
2088
                             `workers.specs[*].resources.limits.memory` or shrink the action's \
2089
                             concurrency."
2090
                        );
2091
4
                        self.metrics().child_process_failure_error_code.inc();
2092
4
                        EXIT_CODE_FOR_SIGNAL
2093
14
                    
}4
, |exit_code| {
2094
14
                        if exit_code == 0 {
2095
13
                            self.metrics().child_process_success_error_code.inc();
2096
13
                        } else {
2097
1
                            self.metrics().child_process_failure_error_code.inc();
2098
1
                        }
2099
14
                        exit_code
2100
14
                    });
2101
2102
                    #[cfg(target_os = "linux")]
2103
18
                    let resource_usage = match maybe_resource_usage_sampler.take() {
2104
18
                        Some(sampler) => finish_action_resource_usage_sampler(sampler)
2105
18
                            .await
2106
18
                            .and_then(|usage| {
2107
                                // An action too short to catch a sample leaves
2108
                                // both at zero; report nothing rather than a
2109
                                // misleading zero.
2110
18
                                (usage.peak_memory_kb > 0 || 
usage.cpu_time_ms > 02
).then_some(
2111
18
                                    ActionResourceUsage {
2112
18
                                        peak_memory_kb: usage.peak_memory_kb,
2113
18
                                        cpu_time_ms: usage.cpu_time_ms,
2114
18
                                        sampled: true,
2115
18
                                        operation_id: String::new(),
2116
18
                                        worker_id: String::new(),
2117
18
                                    },
2118
                                )
2119
18
                            }),
2120
0
                        None => None,
2121
                    };
2122
                    #[cfg(not(target_os = "linux"))]
2123
                    let resource_usage = None;
2124
2125
                    // log something useful instead of repeating same ?arg
2126
18
                    info!(?exit_code, "Command complete");
2127
2128
18
                    let maybe_error_override = if let Some(
side_channel_file0
) = maybe_side_channel_file {
2129
0
                        process_side_channel_file(side_channel_file.clone(), &args, requested_timeout).await
2130
0
                        .err_tip(|| format!("Error processing side channel file: {}", side_channel_file.display()))?
2131
                    } else {
2132
18
                        None
2133
                    };
2134
18
                    {
2135
18
                        let mut state = self.state.lock();
2136
18
                        state.error = Error::merge_option(state.error.take(), maybe_error_override);
2137
18
2138
18
                        state.command_proto = Some(command_proto);
2139
18
                        state.execution_result = Some(RunningActionImplExecutionResult{
2140
18
                            stdout,
2141
18
                            stderr,
2142
18
                            exit_code,
2143
18
                            resource_usage,
2144
18
                        });
2145
18
                        state.execution_metadata.execution_completed_timestamp = (self.running_actions_manager.callbacks.now_fn)();
2146
18
                    }
2147
18
                    return Ok(self);
2148
                },
2149
22
                _ = &mut kill_channel_rx => {
2150
2
                    killed_action = true;
2151
2
                    if let Err(
err0
) = child_process_guard.kill().await {
2152
0
                        error!(
2153
0
                            operation_id = ?self.operation_id,
2154
                            ?err,
2155
                            "Could not kill process",
2156
                        );
2157
2
                    }
2158
2
                    {
2159
2
                        let mut state = self.state.lock();
2160
2
                        state.error = Error::merge_option(state.error.take(), Some(Error::new(
2161
2
                            Code::Aborted,
2162
2
                            format!(
2163
2
                                "Command '{}' was killed by scheduler",
2164
2
                                args.join(OsStr::new(" ")).to_string_lossy()
2165
2
                            )
2166
2
                        )));
2167
2
                    }
2168
                },
2169
            }
2170
        }
2171
        // Unreachable.
2172
21
    }
2173
2174
18
    
async fn inner_upload_results(self: Arc<Self>) -> Result<Arc<Self>, Error>0
{
2175
        enum OutputType {
2176
            None,
2177
            File(FileInfo),
2178
            Directory(DirectoryInfo),
2179
            FileSymlink(SymlinkInfo),
2180
            DirectorySymlink(SymlinkInfo),
2181
        }
2182
2183
18
        let upload_start = std::time::Instant::now();
2184
18
        debug!(
2185
18
            operation_id = ?self.operation_id,
2186
            "Worker uploading results - starting",
2187
        );
2188
18
        let (mut command_proto, execution_result, mut execution_metadata) = {
2189
18
            let mut state = self.state.lock();
2190
18
            state.execution_metadata.output_upload_start_timestamp =
2191
18
                (self.running_actions_manager.callbacks.now_fn)();
2192
            (
2193
18
                state
2194
18
                    .command_proto
2195
18
                    .take()
2196
18
                    .err_tip(|| "Expected state to have command_proto in execute()")
?0
,
2197
18
                state
2198
18
                    .execution_result
2199
18
                    .take()
2200
18
                    .err_tip(|| "Execution result does not exist at upload_results stage")
?0
,
2201
18
                state.execution_metadata.clone(),
2202
            )
2203
        };
2204
18
        let cas_store = self.running_actions_manager.cas_store.as_ref();
2205
18
        let hasher = self.action_info.unique_qualifier.digest_function();
2206
2207
18
        let mut output_path_futures = FuturesUnordered::new();
2208
18
        let mut output_paths = command_proto.output_paths;
2209
18
        if output_paths.is_empty() {
2210
7
            output_paths
2211
7
                .reserve(command_proto.output_files.len() + command_proto.output_directories.len());
2212
7
            output_paths.append(&mut command_proto.output_files);
2213
7
            output_paths.append(&mut command_proto.output_directories);
2214
11
        }
2215
18
        let digest_uploaders = Arc::new(Mutex::new(HashMap::new()));
2216
18
        for 
entry14
in output_paths {
2217
14
            let full_path = OsString::from(if command_proto.working_directory.is_empty() {
2218
3
                format!("{}/{}", self.work_directory, entry)
2219
            } else {
2220
11
                format!(
2221
                    "{}/{}/{}",
2222
11
                    self.work_directory, command_proto.working_directory, entry
2223
                )
2224
            });
2225
14
            let work_directory = &self.work_directory;
2226
14
            let digest_uploaders = digest_uploaders.clone();
2227
14
            output_path_futures.push(async move {
2228
7
                let metadata = {
2229
14
                    let metadata = match fs::symlink_metadata(&full_path).await {
2230
14
                        Ok(file) => file,
2231
0
                        Err(e) => {
2232
0
                            if e.code == Code::NotFound {
2233
                                // In the event our output does not exist, according to the bazel remote
2234
                                // execution spec, we simply ignore it continue.
2235
0
                                return Result::<OutputType, Error>::Ok(OutputType::None);
2236
0
                            }
2237
0
                            return Err(e).err_tip(|| {
2238
0
                                format!("Could not open file {}", full_path.display())
2239
0
                            });
2240
                        }
2241
                    };
2242
2243
14
                    if metadata.is_file() {
2244
                        return Ok(OutputType::File(
2245
7
                            upload_file(
2246
7
                                cas_store.as_pin(),
2247
7
                                &full_path,
2248
7
                                hasher,
2249
7
                                metadata,
2250
7
                                digest_uploaders,
2251
7
                            )
2252
7
                            .await
2253
7
                            .map(|mut file_info| {
2254
7
                                file_info.name_or_path = NameOrPath::Path(entry);
2255
7
                                file_info
2256
7
                            })
2257
7
                            .err_tip(|| 
format!0
("Uploading file {}",
full_path.display()0
))
?0
,
2258
                        ));
2259
7
                    }
2260
7
                    metadata
2261
                };
2262
7
                if metadata.is_dir() {
2263
                    Ok(OutputType::Directory(
2264
3
                        upload_directory(
2265
3
                            cas_store.as_pin(),
2266
3
                            &full_path,
2267
3
                            work_directory,
2268
3
                            hasher,
2269
3
                            digest_uploaders,
2270
                        )
2271
3
                        .and_then(|(root_dir, children)| async move {
2272
3
                            let tree = ProtoTree {
2273
3
                                root: Some(root_dir),
2274
3
                                children: children.into(),
2275
3
                            };
2276
3
                            let tree_digest = serialize_and_upload_message(
2277
3
                                &tree,
2278
3
                                cas_store.as_pin(),
2279
3
                                &mut hasher.hasher(),
2280
3
                            )
2281
3
                            .await
2282
3
                            .err_tip(|| 
format!0
("While processing {entry}"))
?0
;
2283
3
                            Ok(DirectoryInfo {
2284
3
                                path: entry,
2285
3
                                tree_digest,
2286
3
                            })
2287
6
                        })
2288
3
                        .await
2289
3
                        .err_tip(|| 
format!0
("Uploading directory {}",
full_path.display()0
))
?0
,
2290
                    ))
2291
4
                } else if metadata.is_symlink() {
2292
                    // Resolve the symlink to determine what it points to.
2293
                    // Symlinks created by DirectoryCache (absolute paths into
2294
                    // the cache directory) must NOT be uploaded as symlinks —
2295
                    // the target path is worker-local and meaningless to the
2296
                    // client. Instead, follow the symlink and upload the
2297
                    // resolved content (file or directory).
2298
4
                    let target = fs::read_link(&full_path).await.err_tip(|| 
{0
2299
0
                        format!("Reading symlink target for {}", full_path.display())
2300
0
                    })?;
2301
4
                    let is_absolute_symlink = Path::new(&target).is_absolute();
2302
2303
4
                    if is_absolute_symlink {
2304
                        // Absolute symlink — resolve and upload contents.
2305
3
                        match fs::metadata(&full_path).await {
2306
3
                            Ok(resolved_meta) => {
2307
3
                                if resolved_meta.is_dir() {
2308
                                    // Upload as directory (Tree proto).
2309
                                    Ok(OutputType::Directory(
2310
1
                                        upload_directory(
2311
1
                                            cas_store.as_pin(),
2312
1
                                            &full_path,
2313
1
                                            work_directory,
2314
1
                                            hasher,
2315
1
                                            digest_uploaders,
2316
                                        )
2317
1
                                        .and_then(|(root_dir, children)| async move {
2318
1
                                            let tree = ProtoTree {
2319
1
                                                root: Some(root_dir),
2320
1
                                                children: children.into(),
2321
1
                                            };
2322
1
                                            let tree_digest = serialize_and_upload_message(
2323
1
                                                &tree,
2324
1
                                                cas_store.as_pin(),
2325
1
                                                &mut hasher.hasher(),
2326
1
                                            )
2327
1
                                            .await
2328
1
                                            .err_tip(|| 
format!0
("While processing {entry}"))
?0
;
2329
1
                                            Ok(DirectoryInfo {
2330
1
                                                path: entry,
2331
1
                                                tree_digest,
2332
1
                                            })
2333
2
                                        })
2334
1
                                        .await
2335
1
                                        .err_tip(|| 
{0
2336
0
                                            format!(
2337
                                                "Uploading symlinked directory {}",
2338
0
                                                full_path.display()
2339
                                            )
2340
0
                                        })?,
2341
                                    ))
2342
                                } else {
2343
                                    // Upload as file (follow symlink).
2344
                                    Ok(OutputType::File(
2345
2
                                        upload_file(
2346
2
                                            cas_store.as_pin(),
2347
2
                                            &full_path,
2348
2
                                            hasher,
2349
2
                                            resolved_meta,
2350
2
                                            digest_uploaders,
2351
2
                                        )
2352
2
                                        .await
2353
2
                                        .map(|mut file_info| {
2354
2
                                            file_info.name_or_path = NameOrPath::Path(entry);
2355
2
                                            file_info
2356
2
                                        })
2357
2
                                        .err_tip(|| 
{0
2358
0
                                            format!(
2359
                                                "Uploading symlinked file {}",
2360
0
                                                full_path.display()
2361
                                            )
2362
0
                                        })?,
2363
                                    ))
2364
                                }
2365
                            }
2366
0
                            Err(e) => {
2367
0
                                if e.code != Code::NotFound {
2368
0
                                    return Err(e).err_tip(|| {
2369
0
                                        format!(
2370
                                            "While resolving absolute symlink {}",
2371
0
                                            full_path.display()
2372
                                        )
2373
0
                                    });
2374
0
                                }
2375
0
                                Ok(OutputType::None)
2376
                            }
2377
                        }
2378
                    } else {
2379
                        // Relative symlink — action intentionally created it.
2380
                        // Upload as a proper symlink.
2381
1
                        let output_symlink = upload_symlink(&full_path, work_directory)
2382
1
                            .await
2383
1
                            .map(|mut symlink_info| {
2384
1
                                symlink_info.name_or_path = NameOrPath::Path(entry);
2385
1
                                symlink_info
2386
1
                            })
2387
1
                            .err_tip(|| 
format!0
("Uploading symlink {}",
full_path.display()0
))
?0
;
2388
1
                        match fs::metadata(&full_path).await {
2389
1
                            Ok(metadata) => {
2390
1
                                if metadata.is_dir() {
2391
0
                                    Ok(OutputType::DirectorySymlink(output_symlink))
2392
                                } else {
2393
                                    // Note: If it's anything but directory we put it as a file symlink.
2394
1
                                    Ok(OutputType::FileSymlink(output_symlink))
2395
                                }
2396
                            }
2397
0
                            Err(e) => {
2398
0
                                if e.code != Code::NotFound {
2399
0
                                    return Err(e).err_tip(|| {
2400
0
                                        format!(
2401
                                            "While querying target symlink metadata for {}",
2402
0
                                            full_path.display()
2403
                                        )
2404
0
                                    });
2405
0
                                }
2406
                                // If the file doesn't exist, we consider it a file. Even though the
2407
                                // file doesn't exist we still need to populate an entry.
2408
0
                                Ok(OutputType::FileSymlink(output_symlink))
2409
                            }
2410
                        }
2411
                    }
2412
                } else {
2413
0
                    Err(make_err!(
2414
0
                        Code::Internal,
2415
0
                        "{full_path:?} was not a file, folder or symlink. Must be one.",
2416
0
                    ))
2417
                }
2418
14
            });
2419
        }
2420
18
        let mut output_files = vec![];
2421
18
        let mut output_folders = vec![];
2422
18
        let mut output_directory_symlinks = vec![];
2423
18
        let mut output_file_symlinks = vec![];
2424
2425
18
        if execution_result.exit_code != 0 {
2426
5
            let stdout = core::str::from_utf8(&execution_result.stdout).unwrap_or("<no-utf8>");
2427
5
            let stderr = core::str::from_utf8(&execution_result.stderr).unwrap_or("<no-utf8>");
2428
5
            error!(
2429
                exit_code = ?execution_result.exit_code,
2430
5
                stdout = ?stdout[..min(stdout.len(), 1000)],
2431
5
                stderr = ?stderr[..min(stderr.len(), 1000)],
2432
                command = ?command_proto.arguments,
2433
                "Command returned non-zero exit code",
2434
            );
2435
13
        }
2436
2437
18
        let stdout_digest_fut = self.metrics().upload_stdout.wrap(async {
2438
18
            let start = std::time::Instant::now();
2439
18
            let data = execution_result.stdout;
2440
18
            let data_len = data.len();
2441
18
            let digest = compute_buf_digest(&data, &mut hasher.hasher());
2442
18
            cas_store
2443
18
                .update_oneshot(digest, data)
2444
18
                .await
2445
18
                .err_tip(|| "Uploading stdout")
?0
;
2446
18
            debug!(
2447
                ?digest,
2448
                data_len,
2449
18
                elapsed_ms = start.elapsed().as_millis(),
2450
                "upload_results: stdout upload completed",
2451
            );
2452
18
            Result::<DigestInfo, Error>::Ok(digest)
2453
18
        });
2454
18
        let stderr_digest_fut = self.metrics().upload_stderr.wrap(async {
2455
18
            let start = std::time::Instant::now();
2456
18
            let data = execution_result.stderr;
2457
18
            let data_len = data.len();
2458
18
            let digest = compute_buf_digest(&data, &mut hasher.hasher());
2459
18
            cas_store
2460
18
                .update_oneshot(digest, data)
2461
18
                .await
2462
18
                .err_tip(|| "Uploading  stderr")
?0
;
2463
18
            debug!(
2464
                ?digest,
2465
                data_len,
2466
18
                elapsed_ms = start.elapsed().as_millis(),
2467
                "upload_results: stderr upload completed",
2468
            );
2469
18
            Result::<DigestInfo, Error>::Ok(digest)
2470
18
        });
2471
2472
18
        debug!(
2473
18
            operation_id = ?self.operation_id,
2474
18
            num_output_paths = output_path_futures.len(),
2475
            "upload_results: starting stdout/stderr/output_paths uploads",
2476
        );
2477
18
        let join_start = std::time::Instant::now();
2478
18
        let upload_result = futures::try_join!(stdout_digest_fut, stderr_digest_fut, async {
2479
32
            while let Some(
output_type14
) = output_path_futures.try_next().await
?0
{
2480
14
                match output_type {
2481
9
                    OutputType::File(output_file) => output_files.push(output_file),
2482
4
                    OutputType::Directory(output_folder) => output_folders.push(output_folder),
2483
1
                    OutputType::FileSymlink(output_symlink) => {
2484
1
                        output_file_symlinks.push(output_symlink);
2485
1
                    }
2486
0
                    OutputType::DirectorySymlink(output_symlink) => {
2487
0
                        output_directory_symlinks.push(output_symlink);
2488
0
                    }
2489
0
                    OutputType::None => { /* Safe to ignore */ }
2490
                }
2491
            }
2492
18
            Ok(())
2493
18
        });
2494
18
        drop(output_path_futures);
2495
18
        debug!(
2496
18
            operation_id = ?self.operation_id,
2497
18
            elapsed_ms = join_start.elapsed().as_millis(),
2498
18
            success = upload_result.is_ok(),
2499
            "upload_results: all uploads completed",
2500
        );
2501
18
        let resource_usage = execution_result.resource_usage.clone();
2502
18
        let (stdout_digest, stderr_digest) = match upload_result {
2503
18
            Ok((stdout_digest, stderr_digest, ())) => (stdout_digest, stderr_digest),
2504
0
            Err(e) => return Err(e).err_tip(|| "Error while uploading results"),
2505
        };
2506
2507
18
        execution_metadata.output_upload_completed_timestamp =
2508
18
            (self.running_actions_manager.callbacks.now_fn)();
2509
18
        output_files.sort_unstable_by(|a, b| 
a.name_or_path0
.
cmp0
(
&b.name_or_path0
));
2510
18
        output_folders.sort_unstable_by(|a, b| 
a.path0
.
cmp0
(
&b.path0
));
2511
18
        output_file_symlinks.sort_unstable_by(|a, b| 
a.name_or_path0
.
cmp0
(
&b.name_or_path0
));
2512
18
        output_directory_symlinks.sort_unstable_by(|a, b| 
a.name_or_path0
.
cmp0
(
&b.name_or_path0
));
2513
18
        let num_output_files = output_files.len();
2514
18
        let num_output_folders = output_folders.len();
2515
18
        {
2516
18
            let mut state = self.state.lock();
2517
18
            execution_metadata.worker_completed_timestamp =
2518
18
                (self.running_actions_manager.callbacks.now_fn)();
2519
18
            state.action_result = Some(ActionResult {
2520
18
                output_files,
2521
18
                output_folders,
2522
18
                output_directory_symlinks,
2523
18
                output_file_symlinks,
2524
18
                exit_code: execution_result.exit_code,
2525
18
                stdout_digest,
2526
18
                stderr_digest,
2527
18
                execution_metadata,
2528
18
                server_logs: HashMap::default(), // TODO(palfrey) Not implemented.
2529
18
                error: state.error.clone(),
2530
18
                message: String::new(), // Will be filled in on cache_action_result if needed.
2531
18
            });
2532
18
            state.resource_usage = resource_usage;
2533
18
        }
2534
18
        debug!(
2535
18
            operation_id = ?self.operation_id,
2536
18
            total_elapsed_ms = upload_start.elapsed().as_millis(),
2537
            num_output_files,
2538
            num_output_folders,
2539
            "upload_results: inner_upload_results completed successfully",
2540
        );
2541
18
        Ok(self)
2542
18
    }
2543
2544
18
    async fn inner_get_finished_result(self: Arc<Self>) -> Result<ActionResult, Error> {
2545
18
        let mut state = self.state.lock();
2546
18
        state
2547
18
            .action_result
2548
18
            .take()
2549
18
            .err_tip(|| "Expected action_result to exist in get_finished_result")
2550
18
    }
2551
}
2552
2553
impl Drop for RunningActionImpl {
2554
229
    fn drop(&mut self) {
2555
229
        if self.did_cleanup.load(Ordering::Acquire) {
2556
228
            if self.has_manager_entry.load(Ordering::Acquire) {
2557
2
                drop(
2558
2
                    self.running_actions_manager
2559
2
                        .cleanup_action(&self.operation_id),
2560
2
                );
2561
226
            }
2562
228
            if let Some(
input_lease1
) = self.input_lease.clone() {
2563
1
                background_spawn!(
2564
                    "running_action_impl_release_input_lease",
2565
1
                    input_lease.release()
2566
                );
2567
227
            }
2568
228
            return;
2569
1
        }
2570
1
        let operation_id = self.operation_id.clone();
2571
1
        error!(
2572
            %operation_id,
2573
            "RunningActionImpl did not cleanup. This is a violation of the requirements, will attempt to do it in the background."
2574
        );
2575
1
        let running_actions_manager = self.running_actions_manager.clone();
2576
1
        let action_directory = self.action_directory.clone();
2577
1
        let input_lease = self.input_lease.clone();
2578
1
        background_spawn!("running_action_impl_drop", async move 
{0
2579
0
            let cleanup_result =
2580
0
                do_cleanup(&running_actions_manager, &operation_id, &action_directory).await;
2581
0
            if let Some(input_lease) = input_lease {
2582
0
                input_lease.release().await;
2583
0
            }
2584
0
            if let Err(err) = cleanup_result {
2585
0
                error!(
2586
                    %operation_id,
2587
                    ?action_directory,
2588
                    ?err,
2589
                    "Error cleaning up action"
2590
                );
2591
0
            }
2592
0
        });
2593
229
    }
2594
}
2595
2596
impl RunningAction for RunningActionImpl {
2597
0
    fn get_operation_id(&self) -> &OperationId {
2598
0
        &self.operation_id
2599
0
    }
2600
2601
25
    async fn prepare_action(self: Arc<Self>) -> Result<Arc<Self>, Error> {
2602
25
        let res = self
2603
25
            .metrics()
2604
25
            .clone()
2605
25
            .prepare_action
2606
25
            .wrap(Self::inner_prepare_action(self))
2607
25
            .await;
2608
25
        if let Err(
ref e0
) = res {
2609
0
            warn!(?e, "Error during prepare_action");
2610
25
        }
2611
25
        res
2612
25
    }
2613
2614
21
    async fn execute(self: Arc<Self>) -> Result<Arc<Self>, Error> {
2615
21
        let res = self
2616
21
            .metrics()
2617
21
            .clone()
2618
21
            .execute
2619
21
            .wrap(Self::inner_execute(self))
2620
21
            .await;
2621
21
        if let Err(
ref e1
) = res {
2622
1
            warn!(?e, "Error during prepare_action");
2623
20
        }
2624
21
        res
2625
21
    }
2626
2627
18
    
async fn upload_results(self: Arc<Self>) -> Result<Arc<Self>, Error>0
{
2628
18
        let upload_timeout = self.running_actions_manager.max_upload_timeout;
2629
18
        let operation_id = self.operation_id.clone();
2630
18
        info!(
2631
            ?operation_id,
2632
18
            upload_timeout_s = upload_timeout.as_secs(),
2633
            "upload_results: starting with timeout",
2634
        );
2635
18
        let metrics = self.metrics().clone();
2636
18
        let upload_fut = metrics
2637
18
            .upload_results
2638
18
            .wrap(Self::inner_upload_results(self));
2639
2640
18
        let stall_warn_fut = async 
{16
2641
16
            let mut elapsed_secs = 0u64;
2642
            loop {
2643
16
                tokio::time::sleep(Duration::from_mins(1)).await;
2644
0
                elapsed_secs += 60;
2645
0
                warn!(
2646
                    ?operation_id,
2647
                    elapsed_s = elapsed_secs,
2648
0
                    timeout_s = upload_timeout.as_secs(),
2649
                    "upload_results: still in progress — possible stall",
2650
                );
2651
            }
2652
        };
2653
2654
18
        let res = tokio::time::timeout(upload_timeout, async {
2655
18
            tokio::pin!(upload_fut);
2656
18
            tokio::pin!(stall_warn_fut);
2657
18
            tokio::select! {
2658
18
                result = &mut upload_fut => result,
2659
18
                () = &mut stall_warn_fut => 
unreachable!0
(),
2660
            }
2661
18
        })
2662
18
        .await
2663
18
        .map_err(|err| 
{0
2664
0
            warn!(%operation_id, timeout=upload_timeout.as_secs(), "Upload results timeout");
2665
0
            Error::from_std_err(Code::DeadlineExceeded, &err).append(format!(
2666
                "Upload results timed out after {}s for operation {:?}",
2667
0
                upload_timeout.as_secs(),
2668
                operation_id,
2669
            ))
2670
0
        })?;
2671
18
        if let Err(
ref e0
) = res {
2672
0
            warn!(?operation_id, ?e, "Error during upload_results");
2673
18
        }
2674
18
        res
2675
18
    }
2676
2677
226
    async fn cleanup(self: Arc<Self>) -> Result<Arc<Self>, Error> {
2678
226
        let res = self
2679
226
            .metrics()
2680
226
            .clone()
2681
226
            .cleanup
2682
226
            .wrap(async move {
2683
226
                let result = do_cleanup(
2684
226
                    &self.running_actions_manager,
2685
226
                    &self.operation_id,
2686
226
                    &self.action_directory,
2687
226
                )
2688
226
                .await;
2689
226
                self.has_manager_entry.store(false, Ordering::Release);
2690
226
                self.did_cleanup.store(true, Ordering::Release);
2691
                // The work directory and manager entry are gone before the
2692
                // lease is released. If this future is cancelled while the
2693
                // release task is finishing, Drop still observes a completed
2694
                // cleanup and cannot strand the action in the manager.
2695
226
                if let Some(
input_lease1
) = self.input_lease.clone() {
2696
1
                    input_lease.release().await;
2697
225
                }
2698
226
                result.map(move |()| self)
2699
226
            })
2700
226
            .await;
2701
226
        if let Err(
ref e0
) = res {
2702
0
            warn!(?e, "Error during cleanup");
2703
226
        }
2704
226
        res
2705
226
    }
2706
2707
18
    
async fn get_finished_result(self: Arc<Self>) -> Result<ActionResult, Error>0
{
2708
18
        self.metrics()
2709
18
            .clone()
2710
18
            .get_finished_result
2711
18
            .wrap(Self::inner_get_finished_result(self))
2712
18
            .await
2713
18
    }
2714
2715
0
    fn resource_usage(&self) -> Option<ActionResourceUsage> {
2716
0
        self.state.lock().resource_usage.clone()
2717
0
    }
2718
2719
0
    fn get_work_directory(&self) -> &String {
2720
0
        &self.work_directory
2721
0
    }
2722
}
2723
2724
pub trait RunningActionsManager: Sync + Send + Sized + Unpin + 'static {
2725
    type RunningAction: RunningAction;
2726
2727
    fn create_and_add_action(
2728
        self: &Arc<Self>,
2729
        worker_id: String,
2730
        start_execute: StartExecute,
2731
    ) -> impl Future<Output = Result<Arc<Self::RunningAction>, Error>> + Send;
2732
2733
    fn cache_action_result(
2734
        &self,
2735
        action_digest: DigestInfo,
2736
        action_result: &mut ActionResult,
2737
        hasher: DigestHasherFunc,
2738
    ) -> impl Future<Output = Result<(), Error>> + Send;
2739
2740
    fn kill_all(&self) -> impl Future<Output = ()> + Send;
2741
2742
    fn kill_operation(
2743
        &self,
2744
        operation_id: &OperationId,
2745
    ) -> impl Future<Output = Result<(), Error>> + Send;
2746
2747
    fn metrics(&self) -> &Arc<Metrics>;
2748
}
2749
2750
/// A function to get the current system time, used to allow mocking for tests
2751
type NowFn = fn() -> SystemTime;
2752
type SleepFn = fn(Duration) -> BoxFuture<'static, ()>;
2753
2754
/// Functions that may be injected for testing purposes, during standard control
2755
/// flows these are specified by the new function.
2756
#[derive(Clone, Copy)]
2757
pub struct Callbacks {
2758
    /// A function that gets the current time.
2759
    pub now_fn: NowFn,
2760
    /// A function that sleeps for a given Duration.
2761
    pub sleep_fn: SleepFn,
2762
}
2763
2764
impl Debug for Callbacks {
2765
0
    fn fmt(&self, f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
2766
0
        f.debug_struct("Callbacks").finish_non_exhaustive()
2767
0
    }
2768
}
2769
2770
/// The set of additional information for executing an action over and above
2771
/// those given in the `ActionInfo` passed to the worker.  This allows
2772
/// modification of the action for execution on this particular worker.  This
2773
/// may be used to run the action with a particular set of additional
2774
/// environment variables, or perhaps configure it to execute within a
2775
/// container.
2776
#[derive(Debug, Default)]
2777
pub struct ExecutionConfiguration {
2778
    /// If set, will be executed instead of the first argument passed in the
2779
    /// `ActionInfo` with all of the arguments in the `ActionInfo` passed as
2780
    /// arguments to this command.
2781
    pub entrypoint: Option<String>,
2782
    /// The only environment variables that will be specified when the command
2783
    /// executes other than those in the `ActionInfo`.  On Windows, `SystemRoot`
2784
    /// and PATH are also assigned (see `inner_execute`).
2785
    pub additional_environment: Option<HashMap<String, EnvironmentSource>>,
2786
}
2787
2788
#[derive(Debug)]
2789
struct UploadActionResults {
2790
    upload_ac_results_strategy: UploadCacheResultsStrategy,
2791
    upload_historical_results_strategy: UploadCacheResultsStrategy,
2792
    ac_store: Option<Store>,
2793
    historical_store: Store,
2794
    success_message_template: Template,
2795
    failure_message_template: Template,
2796
}
2797
2798
impl UploadActionResults {
2799
37
    fn new(
2800
37
        config: &UploadActionResultConfig,
2801
37
        ac_store: Option<Store>,
2802
37
        historical_store: Store,
2803
37
    ) -> Result<Self, Error> {
2804
37
        let upload_historical_results_strategy = config
2805
37
            .upload_historical_results_strategy
2806
37
            .unwrap_or(DEFAULT_HISTORICAL_RESULTS_STRATEGY);
2807
8
        if !matches!(
2808
37
            config.upload_ac_results_strategy,
2809
            UploadCacheResultsStrategy::Never
2810
8
        ) && ac_store.is_none()
2811
        {
2812
0
            return Err(make_input_err!(
2813
0
                "upload_ac_results_strategy is set, but no ac_store is configured"
2814
0
            ));
2815
37
        }
2816
        Ok(Self {
2817
37
            upload_ac_results_strategy: config.upload_ac_results_strategy,
2818
37
            upload_historical_results_strategy,
2819
37
            ac_store,
2820
37
            historical_store,
2821
37
            success_message_template: Template::new(&config.success_message_template).map_err(
2822
0
                |e| {
2823
0
                    Error::from_std_err(Code::InvalidArgument, &e).append(format!(
2824
                        "Could not convert success_message_template to rust template: {}",
2825
                        config.success_message_template
2826
                    ))
2827
0
                },
2828
0
            )?,
2829
37
            failure_message_template: Template::new(&config.failure_message_template).map_err(
2830
0
                |e| {
2831
0
                    Error::from_std_err(Code::InvalidArgument, &e).append(format!(
2832
                        "Could not convert failure_message_template to rust template: {}",
2833
                        config.success_message_template
2834
                    ))
2835
0
                },
2836
0
            )?,
2837
        })
2838
37
    }
2839
2840
0
    const fn should_cache_result(
2841
0
        strategy: UploadCacheResultsStrategy,
2842
0
        action_result: &ActionResult,
2843
0
        treat_infra_error_as_failure: bool,
2844
0
    ) -> bool {
2845
0
        let did_fail = action_result.exit_code != 0
2846
0
            || (treat_infra_error_as_failure && action_result.error.is_some());
2847
0
        match strategy {
2848
0
            UploadCacheResultsStrategy::SuccessOnly => !did_fail,
2849
0
            UploadCacheResultsStrategy::Never => false,
2850
            // Never cache internal errors or timeouts.
2851
            UploadCacheResultsStrategy::Everything => {
2852
0
                treat_infra_error_as_failure || action_result.error.is_none()
2853
            }
2854
0
            UploadCacheResultsStrategy::FailuresOnly => did_fail,
2855
        }
2856
0
    }
2857
2858
    /// Formats the message field in `ExecuteResponse` from the `success_message_template`
2859
    /// or `failure_message_template` config templates.
2860
5
    fn format_execute_response_message(
2861
5
        mut template_str: Template,
2862
5
        action_digest_info: DigestInfo,
2863
5
        maybe_historical_digest_info: Option<DigestInfo>,
2864
5
        hasher: DigestHasherFunc,
2865
5
    ) -> Result<String, Error> {
2866
5
        template_str.replace(
2867
            "digest_function",
2868
5
            hasher.proto_digest_func().as_str_name().to_lowercase(),
2869
        );
2870
5
        template_str.replace(
2871
            "action_digest_hash",
2872
5
            action_digest_info.packed_hash().to_string(),
2873
        );
2874
5
        template_str.replace("action_digest_size", action_digest_info.size_bytes());
2875
5
        if let Some(
historical_digest_info3
) = maybe_historical_digest_info {
2876
3
            template_str.replace(
2877
3
                "historical_results_hash",
2878
3
                format!("{}", historical_digest_info.packed_hash()),
2879
3
            );
2880
3
            template_str.replace(
2881
3
                "historical_results_size",
2882
3
                historical_digest_info.size_bytes(),
2883
3
            );
2884
3
        } else {
2885
2
            template_str.replace("historical_results_hash", "");
2886
2
            template_str.replace("historical_results_size", "");
2887
2
        }
2888
5
        template_str.text().map_err(|e| 
{0
2889
0
            Error::from_std_err(Code::InvalidArgument, &e)
2890
0
                .append("Could not convert template to text")
2891
0
        })
2892
5
    }
2893
2894
0
    async fn upload_ac_results(
2895
0
        &self,
2896
0
        action_digest: DigestInfo,
2897
0
        action_result: ProtoActionResult,
2898
0
        hasher: DigestHasherFunc,
2899
5
    ) -> Result<(), Error> {
2900
5
        let Some(ac_store) = self.ac_store.as_ref() else {
2901
0
            return Ok(());
2902
        };
2903
        // If we are a GrpcStore we shortcut here, as this is a special store.
2904
5
        if let Some(
grpc_store0
) = ac_store.downcast_ref::<GrpcStore>(Some(action_digest.into())) {
2905
0
            let update_action_request = UpdateActionResultRequest {
2906
0
                // This is populated by `update_action_result`.
2907
0
                instance_name: String::new(),
2908
0
                action_digest: Some(action_digest.into()),
2909
0
                action_result: Some(action_result),
2910
0
                results_cache_policy: None,
2911
0
                digest_function: hasher.proto_digest_func().into(),
2912
0
            };
2913
0
            return grpc_store
2914
0
                .update_action_result(Request::new(update_action_request))
2915
0
                .await
2916
0
                .map(|_| ())
2917
0
                .err_tip(|| "Caching ActionResult");
2918
5
        }
2919
2920
5
        let mut store_data = BytesMut::with_capacity(ESTIMATED_DIGEST_SIZE);
2921
5
        action_result
2922
5
            .encode(&mut store_data)
2923
5
            .err_tip(|| "Encoding ActionResult for caching")
?0
;
2924
2925
5
        ac_store
2926
5
            .update_oneshot(action_digest, store_data.split().freeze())
2927
5
            .await
2928
5
            .err_tip(|| "Caching ActionResult")
2929
5
    }
2930
2931
3
    async fn upload_historical_results_with_message(
2932
3
        &self,
2933
3
        action_digest: DigestInfo,
2934
3
        execute_response: ExecuteResponse,
2935
3
        message_template: Template,
2936
3
        hasher: DigestHasherFunc,
2937
3
    ) -> Result<String, Error> {
2938
3
        let historical_digest_info = serialize_and_upload_message(
2939
3
            &HistoricalExecuteResponse {
2940
3
                action_digest: Some(action_digest.into()),
2941
3
                execute_response: Some(execute_response.clone()),
2942
3
            },
2943
3
            self.historical_store.as_pin(),
2944
3
            &mut hasher.hasher(),
2945
3
        )
2946
3
        .await
2947
3
        .err_tip(|| 
format!0
("Caching HistoricalExecuteResponse for digest: {action_digest}"))
?0
;
2948
2949
3
        Self::format_execute_response_message(
2950
3
            message_template,
2951
3
            action_digest,
2952
3
            Some(historical_digest_info),
2953
3
            hasher,
2954
        )
2955
3
        .err_tip(|| "Could not format message in upload_historical_results_with_message")
2956
3
    }
2957
2958
0
    async fn cache_action_result(
2959
0
        &self,
2960
0
        action_info: DigestInfo,
2961
0
        action_result: &mut ActionResult,
2962
0
        hasher: DigestHasherFunc,
2963
6
    ) -> Result<(), Error> {
2964
6
        let should_upload_historical_results =
2965
6
            Self::should_cache_result(self.upload_historical_results_strategy, action_result, true);
2966
6
        let should_upload_ac_results =
2967
6
            Self::should_cache_result(self.upload_ac_results_strategy, action_result, false);
2968
        // Shortcut so we don't need to convert to proto if not needed.
2969
6
        if !should_upload_ac_results && 
!should_upload_historical_results1
{
2970
1
            return Ok(());
2971
5
        }
2972
2973
5
        let mut execute_response = to_execute_response(action_result.clone());
2974
2975
        // In theory exit code should always be != 0 if there's an error, but for safety we
2976
        // catch both.
2977
5
        let message_template = if action_result.exit_code == 0 && 
action_result.error4
.
is_none4
() {
2978
3
            self.success_message_template.clone()
2979
        } else {
2980
2
            self.failure_message_template.clone()
2981
        };
2982
2983
5
        let upload_historical_results_with_message_result = if should_upload_historical_results {
2984
3
            let maybe_message = self
2985
3
                .upload_historical_results_with_message(
2986
3
                    action_info,
2987
3
                    execute_response.clone(),
2988
3
                    message_template,
2989
3
                    hasher,
2990
3
                )
2991
3
                .await;
2992
3
            match maybe_message {
2993
3
                Ok(message) => {
2994
3
                    action_result.message.clone_from(&message);
2995
3
                    execute_response.message = message;
2996
3
                    Ok(())
2997
                }
2998
0
                Err(e) => Result::<(), Error>::Err(e),
2999
            }
3000
        } else {
3001
2
            match Self::format_execute_response_message(message_template, action_info, None, hasher)
3002
            {
3003
2
                Ok(message) => {
3004
2
                    action_result.message.clone_from(&message);
3005
2
                    execute_response.message = message;
3006
2
                    Ok(())
3007
                }
3008
0
                Err(e) => Err(e).err_tip(|| "Could not format message in cache_action_result"),
3009
            }
3010
        };
3011
3012
        // Note: Done in this order because we assume most results will succeed and most configs will
3013
        // either always upload upload historical results or only upload on failure. In which case
3014
        // we can avoid an extra clone of the protos by doing this last with the above assumption.
3015
5
        let ac_upload_results = if should_upload_ac_results {
3016
5
            self.upload_ac_results(
3017
5
                action_info,
3018
5
                execute_response
3019
5
                    .result
3020
5
                    .err_tip(|| "No result set in cache_action_result")
?0
,
3021
5
                hasher,
3022
            )
3023
5
            .await
3024
        } else {
3025
0
            Ok(())
3026
        };
3027
5
        upload_historical_results_with_message_result.merge(ac_upload_results)
3028
6
    }
3029
}
3030
3031
#[cfg(target_os = "linux")]
3032
#[derive(Copy, Clone, Debug)]
3033
pub enum UseNamespaces {
3034
    No,
3035
    Yes,
3036
    YesAndMount,
3037
}
3038
3039
#[derive(Debug)]
3040
pub struct RunningActionsManagerArgs<'a> {
3041
    pub root_action_directory: String,
3042
    pub execution_configuration: ExecutionConfiguration,
3043
    pub cas_store: Arc<FastSlowStore>,
3044
    pub ac_store: Option<Store>,
3045
    pub historical_store: Store,
3046
    pub upload_action_result_config: &'a UploadActionResultConfig,
3047
    pub max_action_timeout: Duration,
3048
    pub max_upload_timeout: Duration,
3049
    pub max_cleanup_wait: Duration,
3050
    pub max_cleanup_backoff: Duration,
3051
    pub timeout_handled_externally: bool,
3052
    pub directory_cache: Option<Arc<crate::directory_cache::DirectoryCache>>,
3053
    /// When true, every digest in an active action's input Merkle closure is
3054
    /// leased in the locally eviction-managed CAS tiers until the action's
3055
    /// cleanup completes. While leases are held, those tiers may temporarily
3056
    /// exceed their configured `max_bytes` / `max_count` eviction limits.
3057
    pub active_input_leases: bool,
3058
    #[cfg(target_os = "linux")]
3059
    pub use_namespaces: UseNamespaces,
3060
}
3061
3062
struct CleanupGuard {
3063
    manager: Weak<RunningActionsManagerImpl>,
3064
    operation_id: OperationId,
3065
}
3066
3067
impl Drop for CleanupGuard {
3068
226
    fn drop(&mut self) {
3069
226
        let Some(manager) = self.manager.upgrade() else {
3070
0
            return;
3071
        };
3072
226
        let mut cleaning = manager.cleaning_up_operations.lock();
3073
226
        cleaning.remove(&self.operation_id);
3074
226
        manager.cleanup_complete_notify.notify_waiters();
3075
226
    }
3076
}
3077
3078
/// Holds state info about what is being executed and the interface for interacting
3079
/// with actions while they are running.
3080
#[derive(Debug)]
3081
pub struct RunningActionsManagerImpl {
3082
    root_action_directory: String,
3083
    execution_configuration: ExecutionConfiguration,
3084
    cas_store: Arc<FastSlowStore>,
3085
    filesystem_store: Arc<FilesystemStore>,
3086
    upload_action_results: UploadActionResults,
3087
    max_action_timeout: Duration,
3088
    max_upload_timeout: Duration,
3089
    timeout_handled_externally: bool,
3090
    #[cfg(target_os = "linux")]
3091
    use_namespaces: UseNamespaces,
3092
    running_actions: Mutex<HashMap<OperationId, Weak<RunningActionImpl>>>,
3093
    // Note: We don't use Notify because we need to support a .wait_for()-like function, which
3094
    // Notify does not support.
3095
    action_done_tx: watch::Sender<()>,
3096
    callbacks: Callbacks,
3097
    metrics: Arc<Metrics>,
3098
    /// Track operations being cleaned up to avoid directory collisions during action retries.
3099
    /// When an action fails and is retried on the same worker, we need to ensure the previous
3100
    /// attempt's directory is fully cleaned up before creating a new one.
3101
    /// See: <https://github.com/TraceMachina/nativelink/issues/1859>
3102
    cleaning_up_operations: Mutex<HashSet<OperationId>>,
3103
    max_cleanup_wait: Duration,
3104
    max_cleanup_backoff: Duration,
3105
    /// Notify waiters when a cleanup operation completes. This is used in conjunction with
3106
    /// `cleaning_up_operations` to coordinate directory cleanup and creation.
3107
    cleanup_complete_notify: Arc<Notify>,
3108
    /// Optional directory cache for improving performance by caching reconstructed
3109
    /// input directories and using hardlinks.
3110
    directory_cache: Option<Arc<crate::directory_cache::DirectoryCache>>,
3111
    /// Whether active action inputs are leased against eviction in the local
3112
    /// CAS tiers (opt-in via `experimental_active_input_leases`).
3113
    active_input_leases: bool,
3114
    persistent_worker_pool: PersistentWorkerPool,
3115
}
3116
3117
impl RunningActionsManagerImpl {
3118
37
    pub fn new_with_callbacks(
3119
37
        args: RunningActionsManagerArgs<'_>,
3120
37
        callbacks: Callbacks,
3121
37
    ) -> Result<Self, Error> {
3122
        // Sadly because of some limitations of how Any works we need to clone more times than optimal.
3123
37
        let filesystem_store = args
3124
37
            .cas_store
3125
37
            .fast_store()
3126
37
            .downcast_ref::<FilesystemStore>(None)
3127
37
            .err_tip(
3128
                || "Expected FilesystemStore store for .fast_store() in RunningActionsManagerImpl",
3129
0
            )?
3130
37
            .get_arc()
3131
37
            .err_tip(|| "FilesystemStore's internal Arc was lost")
?0
;
3132
37
        let (action_done_tx, _) = watch::channel(());
3133
        Ok(Self {
3134
37
            root_action_directory: args.root_action_directory,
3135
37
            execution_configuration: args.execution_configuration,
3136
37
            cas_store: args.cas_store,
3137
37
            filesystem_store,
3138
37
            upload_action_results: UploadActionResults::new(
3139
37
                args.upload_action_result_config,
3140
37
                args.ac_store,
3141
37
                args.historical_store,
3142
            )
3143
37
            .err_tip(|| "During RunningActionsManagerImpl construction")
?0
,
3144
37
            max_action_timeout: args.max_action_timeout,
3145
37
            max_upload_timeout: args.max_upload_timeout,
3146
37
            timeout_handled_externally: args.timeout_handled_externally,
3147
37
            running_actions: Mutex::new(HashMap::new()),
3148
37
            action_done_tx,
3149
37
            callbacks,
3150
37
            metrics: Arc::new(Metrics {
3151
37
                directory_cache: args.directory_cache.as_ref().map(Arc::downgrade),
3152
37
                ..Default::default()
3153
37
            }),
3154
37
            cleaning_up_operations: Mutex::new(HashSet::new()),
3155
37
            max_cleanup_wait: args.max_cleanup_wait,
3156
37
            max_cleanup_backoff: args.max_cleanup_backoff,
3157
37
            cleanup_complete_notify: Arc::new(Notify::new()),
3158
37
            directory_cache: args.directory_cache,
3159
37
            active_input_leases: args.active_input_leases,
3160
37
            persistent_worker_pool: PersistentWorkerPool::default(),
3161
            #[cfg(target_os = "linux")]
3162
37
            use_namespaces: args.use_namespaces,
3163
        })
3164
37
    }
3165
3166
15
    pub fn new(args: RunningActionsManagerArgs<'_>) -> Result<Self, Error> {
3167
15
        Self::new_with_callbacks(
3168
15
            args,
3169
            Callbacks {
3170
15
                now_fn: SystemTime::now,
3171
2
                sleep_fn: |duration| Box::pin(tokio::time::sleep(duration)),
3172
            },
3173
        )
3174
15
    }
3175
3176
    /// Fixes a race condition that occurs when an action fails to execute on a worker, and the same worker
3177
    /// attempts to re-execute the same action before the physical cleanup (file is removed) completes.
3178
    /// See this issue for additional details: <https://github.com/TraceMachina/nativelink/issues/1859>
3179
231
    
async fn wait_for_cleanup_if_needed(&self, operation_id: &OperationId) -> Result<(), Error>0
{
3180
231
        let start = Instant::now();
3181
231
        let mut backoff = Duration::from_millis(10);
3182
231
        let mut has_waited = false;
3183
3184
        loop {
3185
231
            let should_wait = {
3186
231
                let cleaning = self.cleaning_up_operations.lock();
3187
231
                cleaning.contains(operation_id)
3188
            };
3189
3190
231
            if !should_wait {
3191
231
                let action_is_running = self
3192
231
                    .running_actions
3193
231
                    .lock()
3194
231
                    .get(operation_id)
3195
231
                    .and_then(Weak::upgrade)
3196
231
                    .is_some();
3197
231
                if action_is_running {
3198
1
                    return Err(make_err!(
3199
1
                        Code::AlreadyExists,
3200
1
                        "Action with operation_id {} is already running",
3201
1
                        operation_id
3202
1
                    ));
3203
230
                }
3204
3205
230
                let dir_path =
3206
230
                    PathBuf::from(&self.root_action_directory).join(operation_id.to_string());
3207
3208
230
                if !dir_path.exists() {
3209
229
                    return Ok(());
3210
1
                }
3211
3212
                // Safety check: ensure we're only removing directories under root_action_directory
3213
1
                let root_path = Path::new(&self.root_action_directory);
3214
1
                let canonical_root = root_path.canonicalize().err_tip(|| 
{0
3215
0
                    format!(
3216
                        "Failed to canonicalize root directory: {}",
3217
                        self.root_action_directory
3218
                    )
3219
0
                })?;
3220
1
                let canonical_dir = dir_path.canonicalize().err_tip(|| 
{0
3221
0
                    format!("Failed to canonicalize directory: {}", dir_path.display())
3222
0
                })?;
3223
3224
1
                if !canonical_dir.starts_with(&canonical_root) {
3225
0
                    return Err(make_err!(
3226
0
                        Code::Internal,
3227
0
                        "Attempted to remove directory outside of root_action_directory: {}",
3228
0
                        dir_path.display()
3229
0
                    ));
3230
1
                }
3231
3232
                // Directory exists but not being cleaned - remove it
3233
1
                warn!(
3234
                    "Removing stale directory for {}: {}",
3235
                    operation_id,
3236
1
                    dir_path.display()
3237
                );
3238
1
                self.metrics.stale_removals.inc();
3239
3240
                // Try to remove the directory, with one retry on failure
3241
1
                let remove_result = fs::remove_dir_all(&dir_path).await;
3242
1
                if let Err(
e0
) = remove_result {
3243
                    // Retry once after a short delay in case the directory is temporarily locked
3244
0
                    tokio::time::sleep(Duration::from_millis(100)).await;
3245
0
                    fs::remove_dir_all(&dir_path).await.err_tip(|| {
3246
0
                        format!(
3247
                            "Failed to remove stale directory {} for retry of {} after retry (original error: {})",
3248
0
                            dir_path.display(),
3249
                            operation_id,
3250
                            e
3251
                        )
3252
0
                    })?;
3253
1
                }
3254
1
                return Ok(());
3255
0
            }
3256
3257
0
            if start.elapsed() > self.max_cleanup_wait {
3258
0
                self.metrics.cleanup_wait_timeouts.inc();
3259
0
                warn!(%operation_id, waited=?start.elapsed(), "Timeout waiting for previous operation cleanup");
3260
0
                return Err(make_err!(
3261
0
                    Code::DeadlineExceeded,
3262
0
                    "Timeout waiting for previous operation cleanup: {} (waited {:?})",
3263
0
                    operation_id,
3264
0
                    start.elapsed()
3265
0
                ));
3266
0
            }
3267
3268
0
            if !has_waited {
3269
0
                self.metrics.cleanup_waits.inc();
3270
0
                has_waited = true;
3271
0
            }
3272
3273
0
            trace!(
3274
                "Waiting for cleanup of {} (elapsed: {:?}, backoff: {:?})",
3275
                operation_id,
3276
0
                start.elapsed(),
3277
                backoff
3278
            );
3279
3280
0
            tokio::select! {
3281
0
                () = self.cleanup_complete_notify.notified() => {},
3282
0
                () = tokio::time::sleep(backoff) => {
3283
0
                    // Exponential backoff
3284
0
                    backoff = (backoff * 2).min(self.max_cleanup_backoff);
3285
0
                },
3286
            }
3287
        }
3288
231
    }
3289
3290
0
    fn make_action_directory<'a>(
3291
0
        &'a self,
3292
0
        operation_id: &'a OperationId,
3293
0
    ) -> impl Future<Output = Result<String, Error>> + 'a {
3294
230
        
self.metrics.make_action_directory0
.
wrap0
(async move {
3295
230
            let action_directory = format!("{}/{}", self.root_action_directory, operation_id);
3296
230
            fs::create_dir(&action_directory)
3297
230
                .await
3298
230
                .err_tip(|| 
format!0
("Error creating action directory {action_directory}"))
?0
;
3299
230
            Ok(action_directory)
3300
230
        })
3301
0
    }
3302
3303
231
    fn create_action_info(
3304
231
        &self,
3305
231
        start_execute: StartExecute,
3306
231
        queued_timestamp: SystemTime,
3307
231
    ) -> impl Future<Output = Result<ActionInfo, Error>> + '_ {
3308
231
        self.metrics.create_action_info.wrap(async move {
3309
231
            let execute_request = start_execute
3310
231
                .execute_request
3311
231
                .err_tip(|| "Expected execute_request to exist in StartExecute")
?0
;
3312
231
            let action_digest: DigestInfo = execute_request
3313
231
                .action_digest
3314
231
                .clone()
3315
231
                .err_tip(|| "Expected action_digest to exist on StartExecute")
?0
3316
231
                .try_into()
?0
;
3317
231
            let load_start_timestamp = (self.callbacks.now_fn)();
3318
231
            let action =
3319
231
                get_and_decode_digest::<Action>(self.cas_store.as_ref(), action_digest.into())
3320
231
                    .await
3321
231
                    .err_tip(|| "During start_action")
?0
;
3322
231
            let action_info = ActionInfo::try_from_action_and_execute_request(
3323
231
                execute_request,
3324
231
                action,
3325
231
                load_start_timestamp,
3326
231
                queued_timestamp,
3327
            )
3328
231
            .err_tip(|| "Could not create ActionInfo in create_and_add_action()")
?0
;
3329
231
            Ok(action_info)
3330
231
        })
3331
231
    }
3332
3333
228
    fn cleanup_action(&self, operation_id: &OperationId) -> Result<(), Error> {
3334
        // The guard must be dropped before notifying: `send_modify` takes
3335
        // the watch channel's internal lock, and a `wait_for` closure that
3336
        // takes `running_actions` runs while holding that same lock, so
3337
        // notifying while holding `running_actions` is an ABBA deadlock
3338
        // (issue #2672). There is no lost wakeup in the gap: the removal
3339
        // happens-before the notify.
3340
228
        let result = {
3341
228
            let mut running_actions = self.running_actions.lock();
3342
228
            running_actions.remove(operation_id).err_tip(|| 
{0
3343
0
                format!(
3344
                    "Expected operation id '{operation_id}' to exist in RunningActionsManagerImpl"
3345
                )
3346
0
            })
3347
        };
3348
        // No need to copy anything, we just are telling the receivers an event happened.
3349
228
        self.action_done_tx.send_modify(|()| {});
3350
228
        result.map(|_| ())
3351
228
    }
3352
3353
    // Note: We do not capture metrics on this call, only `.kill_all()`.
3354
    // Important: When the future returns the process may still be running.
3355
202
    async fn kill_operation(action: Arc<RunningActionImpl>) {
3356
202
        warn!(
3357
202
            operation_id = ?action.operation_id,
3358
            "Sending kill to running operation",
3359
        );
3360
202
        let kill_channel_tx = {
3361
202
            let mut action_state = action.state.lock();
3362
202
            action_state.kill_channel_tx.take()
3363
        };
3364
202
        if let Some(kill_channel_tx) = kill_channel_tx
3365
202
            && kill_channel_tx.send(()).is_err()
3366
        {
3367
0
            error!(
3368
0
                operation_id = ?action.operation_id,
3369
                "Error sending kill to running operation",
3370
            );
3371
202
        }
3372
202
    }
3373
3374
226
    fn perform_cleanup(self: &Arc<Self>, operation_id: OperationId) -> Option<CleanupGuard> {
3375
226
        let mut cleaning = self.cleaning_up_operations.lock();
3376
226
        cleaning
3377
226
            .insert(operation_id.clone())
3378
226
            .then_some(CleanupGuard {
3379
226
                manager: Arc::downgrade(self),
3380
226
                operation_id,
3381
226
            })
3382
226
    }
3383
}
3384
3385
impl RunningActionsManager for RunningActionsManagerImpl {
3386
    type RunningAction = RunningActionImpl;
3387
3388
0
    async fn create_and_add_action(
3389
0
        self: &Arc<Self>,
3390
0
        worker_id: String,
3391
0
        start_execute: StartExecute,
3392
231
    ) -> Result<Arc<RunningActionImpl>, Error> {
3393
231
        self.metrics
3394
231
            .create_and_add_action
3395
231
            .wrap(async move {
3396
231
                let queued_timestamp = start_execute
3397
231
                    .queued_timestamp
3398
231
                    .and_then(|time| 
time216
.
try_into216
().
ok216
())
3399
231
                    .unwrap_or(SystemTime::UNIX_EPOCH);
3400
231
                let operation_id = start_execute
3401
231
                    .operation_id.as_str().into();
3402
231
                let action_info = self.create_action_info(start_execute, queued_timestamp).await
?0
;
3403
231
                debug!(
3404
                    ?action_info,
3405
                    "Worker received action",
3406
                );
3407
                // Wait for any previous cleanup to complete before creating directory
3408
231
                self.wait_for_cleanup_if_needed(&operation_id).await
?1
;
3409
230
                let action_directory = self.make_action_directory(&operation_id).await
?0
;
3410
230
                let execution_metadata = ExecutionMetadata {
3411
230
                    worker: worker_id,
3412
230
                    queued_timestamp: action_info.insert_timestamp,
3413
230
                    worker_start_timestamp: action_info.load_timestamp,
3414
230
                    worker_completed_timestamp: SystemTime::UNIX_EPOCH,
3415
230
                    input_fetch_start_timestamp: SystemTime::UNIX_EPOCH,
3416
230
                    input_fetch_completed_timestamp: SystemTime::UNIX_EPOCH,
3417
230
                    execution_start_timestamp: SystemTime::UNIX_EPOCH,
3418
230
                    execution_completed_timestamp: SystemTime::UNIX_EPOCH,
3419
230
                    output_upload_start_timestamp: SystemTime::UNIX_EPOCH,
3420
230
                    output_upload_completed_timestamp: SystemTime::UNIX_EPOCH,
3421
230
                };
3422
230
                let timeout = if action_info.timeout.is_zero() || 
self.timeout_handled_externally3
{
3423
227
                    self.max_action_timeout
3424
                } else {
3425
3
                    action_info.timeout
3426
                };
3427
230
                if timeout > self.max_action_timeout {
3428
1
                    return Err(make_err!(
3429
1
                        Code::InvalidArgument,
3430
1
                        "Action timeout of {} seconds is greater than the maximum allowed timeout of {} seconds",
3431
1
                        timeout.as_secs_f32(),
3432
1
                        self.max_action_timeout.as_secs_f32()
3433
1
                    ));
3434
229
                }
3435
229
                let running_action = Arc::new(RunningActionImpl::new(
3436
229
                    execution_metadata,
3437
229
                    operation_id.clone(),
3438
229
                    action_directory,
3439
229
                    action_info,
3440
229
                    timeout,
3441
229
                    self.clone(),
3442
                ));
3443
                {
3444
229
                    let mut running_actions = self.running_actions.lock();
3445
                    // Check if action already exists and is still alive
3446
229
                    if let Some(
existing_weak0
) = running_actions.get(&operation_id)
3447
0
                        && let Some(_existing_action) = existing_weak.upgrade() {
3448
0
                            return Err(make_err!(
3449
0
                                Code::AlreadyExists,
3450
0
                                "Action with operation_id {} is already running",
3451
0
                                operation_id
3452
0
                            ));
3453
229
                    }
3454
229
                    running_actions.insert(operation_id, Arc::downgrade(&running_action));
3455
229
                    running_action
3456
229
                        .has_manager_entry
3457
229
                        .store(true, Ordering::Release);
3458
                }
3459
229
                Ok(running_action)
3460
231
            })
3461
231
            .await
3462
231
    }
3463
3464
0
    async fn cache_action_result(
3465
0
        &self,
3466
0
        action_info: DigestInfo,
3467
0
        action_result: &mut ActionResult,
3468
0
        hasher: DigestHasherFunc,
3469
6
    ) -> Result<(), Error> {
3470
6
        self.metrics
3471
6
            .cache_action_result
3472
6
            .wrap(self.upload_action_results.cache_action_result(
3473
6
                action_info,
3474
6
                action_result,
3475
6
                hasher,
3476
6
            ))
3477
6
            .await
3478
6
    }
3479
3480
0
    async fn kill_operation(&self, operation_id: &OperationId) -> Result<(), Error> {
3481
0
        let running_action = {
3482
0
            let running_actions = self.running_actions.lock();
3483
0
            running_actions
3484
0
                .get(operation_id)
3485
0
                .and_then(Weak::upgrade)
3486
0
                .ok_or_else(|| make_input_err!("Failed to get running action {operation_id}"))?
3487
        };
3488
0
        Self::kill_operation(running_action).await;
3489
0
        Ok(())
3490
0
    }
3491
3492
    // Note: When the future returns the process should be fully killed and cleaned up.
3493
52
    async fn kill_all(&self) {
3494
52
        self.metrics
3495
52
            .kill_all
3496
52
            .wrap_no_capture_result(async move {
3497
52
                let kill_operations: Vec<Arc<RunningActionImpl>> = {
3498
52
                    let running_actions = self.running_actions.lock();
3499
52
                    running_actions.values().filter_map(Weak::upgrade).collect()
3500
                };
3501
52
                let mut kill_futures: FuturesUnordered<_> = kill_operations
3502
52
                    .into_iter()
3503
52
                    .map(Self::kill_operation)
3504
52
                    .collect();
3505
254
                while kill_futures.next().await.is_some() 
{}202
3506
52
            })
3507
52
            .await;
3508
        // Wait for the running actions to drain. Deliberately NOT
3509
        // `wait_for(|()| ...)`: that closure runs while the watch channel's
3510
        // internal lock is held, so taking `running_actions` inside it
3511
        // deadlocks with anyone notifying the channel while holding
3512
        // `running_actions` (issue #2672). Checking outside the channel's
3513
        // lock loses no wakeup: `changed()` reports any version bump since
3514
        // the last check, and `cleanup_action` removes before it notifies.
3515
52
        let mut action_done_rx = self.action_done_tx.subscribe();
3516
        loop {
3517
177
            if self.running_actions.lock().is_empty() {
3518
52
                break;
3519
125
            }
3520
            // The only sender lives on `self`, so this cannot error; if it
3521
            // ever did, giving up the wait is still the safe answer.
3522
125
            if action_done_rx.changed().await.is_err() {
3523
0
                break;
3524
125
            }
3525
        }
3526
52
    }
3527
3528
    #[inline]
3529
2
    fn metrics(&self) -> &Arc<Metrics> {
3530
2
        &self.metrics
3531
2
    }
3532
}
3533
3534
#[derive(Debug, Default, MetricsComponent)]
3535
pub struct Metrics {
3536
    #[metric(help = "Stats about the create_and_add_action command.")]
3537
    create_and_add_action: AsyncCounterWrapper,
3538
    #[metric(help = "Stats about the cache_action_result command.")]
3539
    cache_action_result: AsyncCounterWrapper,
3540
    #[metric(help = "Stats about the kill_all command.")]
3541
    kill_all: AsyncCounterWrapper,
3542
    #[metric(help = "Stats about the create_action_info command.")]
3543
    create_action_info: AsyncCounterWrapper,
3544
    #[metric(help = "Stats about the make_work_directory command.")]
3545
    make_action_directory: AsyncCounterWrapper,
3546
    #[metric(help = "Stats about the prepare_action command.")]
3547
    prepare_action: AsyncCounterWrapper,
3548
    #[metric(help = "Stats about the execute command.")]
3549
    execute: AsyncCounterWrapper,
3550
    #[metric(help = "Stats about the upload_results command.")]
3551
    upload_results: AsyncCounterWrapper,
3552
    #[metric(help = "Stats about the cleanup command.")]
3553
    cleanup: AsyncCounterWrapper,
3554
    #[metric(help = "Stats about the get_finished_result command.")]
3555
    get_finished_result: AsyncCounterWrapper,
3556
    #[metric(help = "Number of times an action waited for cleanup to complete.")]
3557
    cleanup_waits: CounterWithTime,
3558
    #[metric(help = "Number of stale directories removed during action retries.")]
3559
    stale_removals: CounterWithTime,
3560
    #[metric(help = "Number of timeouts while waiting for cleanup to complete.")]
3561
    cleanup_wait_timeouts: CounterWithTime,
3562
    #[metric(help = "Stats about the get_proto_command_from_store command.")]
3563
    get_proto_command_from_store: AsyncCounterWrapper,
3564
    #[metric(help = "Stats about the download_to_directory command.")]
3565
    download_to_directory: AsyncCounterWrapper,
3566
    #[metric(help = "Stats about the prepare_output_files command.")]
3567
    prepare_output_files: AsyncCounterWrapper,
3568
    #[metric(help = "Stats about the prepare_output_paths command.")]
3569
    prepare_output_paths: AsyncCounterWrapper,
3570
    #[metric(help = "Stats about the child_process command.")]
3571
    child_process: AsyncCounterWrapper,
3572
    #[metric(help = "Stats about the child_process_success_error_code command.")]
3573
    child_process_success_error_code: CounterWithTime,
3574
    #[metric(help = "Stats about the child_process_failure_error_code command.")]
3575
    child_process_failure_error_code: CounterWithTime,
3576
    #[metric(help = "Total time spent uploading stdout.")]
3577
    upload_stdout: AsyncCounterWrapper,
3578
    #[metric(help = "Total time spent uploading stderr.")]
3579
    upload_stderr: AsyncCounterWrapper,
3580
    #[metric(help = "Total number of task timeouts.")]
3581
    task_timeouts: CounterWithTime,
3582
    #[metric(
3583
        help = "Stats about the input-directory cache (hits, misses, subtree reuse, evictions, size)."
3584
    )]
3585
    directory_cache: Option<Weak<crate::directory_cache::DirectoryCache>>,
3586
}