Coverage Report

Created: 2026-07-21 15:28

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