Coverage Report

Created: 2025-04-19 16:54

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 Apache License, Version 2.0 (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
//    http://www.apache.org/licenses/LICENSE-2.0
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 std::borrow::Cow;
16
use std::cmp::min;
17
use std::collections::HashMap;
18
use std::collections::vec_deque::VecDeque;
19
use std::convert::Into;
20
use std::ffi::{OsStr, OsString};
21
use std::fmt::Debug;
22
#[cfg(target_family = "unix")]
23
use std::fs::Permissions;
24
#[cfg(target_family = "unix")]
25
use std::os::unix::fs::{MetadataExt, PermissionsExt};
26
use std::path::Path;
27
use std::pin::Pin;
28
use std::process::Stdio;
29
use std::sync::atomic::{AtomicBool, Ordering};
30
use std::sync::{Arc, Weak};
31
use std::time::{Duration, SystemTime};
32
33
use bytes::{Bytes, BytesMut};
34
use filetime::{FileTime, set_file_mtime};
35
use formatx::Template;
36
use futures::future::{
37
    BoxFuture, Future, FutureExt, TryFutureExt, try_join, try_join_all, try_join3,
38
};
39
use futures::stream::{FuturesUnordered, StreamExt, TryStreamExt};
40
use nativelink_config::cas_server::{
41
    EnvironmentSource, UploadActionResultConfig, UploadCacheResultsStrategy,
42
};
43
use nativelink_error::{Code, Error, ResultExt, make_err, make_input_err};
44
use nativelink_metric::MetricsComponent;
45
use nativelink_proto::build::bazel::remote::execution::v2::{
46
    Action, ActionResult as ProtoActionResult, Command as ProtoCommand,
47
    Directory as ProtoDirectory, Directory, DirectoryNode, ExecuteResponse, FileNode, SymlinkNode,
48
    Tree as ProtoTree, UpdateActionResultRequest,
49
};
50
use nativelink_proto::com::github::trace_machina::nativelink::remote_execution::{
51
    HistoricalExecuteResponse, StartExecute,
52
};
53
use nativelink_store::ac_utils::{
54
    ESTIMATED_DIGEST_SIZE, compute_buf_digest, get_and_decode_digest, serialize_and_upload_message,
55
};
56
use nativelink_store::fast_slow_store::FastSlowStore;
57
use nativelink_store::filesystem_store::{FileEntry, FilesystemStore};
58
use nativelink_store::grpc_store::GrpcStore;
59
use nativelink_util::action_messages::{
60
    ActionInfo, ActionResult, DirectoryInfo, ExecutionMetadata, FileInfo, NameOrPath, OperationId,
61
    SymlinkInfo, to_execute_response,
62
};
63
use nativelink_util::common::{DigestInfo, fs};
64
use nativelink_util::digest_hasher::{DigestHasher, DigestHasherFunc};
65
use nativelink_util::metrics_utils::{AsyncCounterWrapper, CounterWithTime};
66
use nativelink_util::shutdown_guard::ShutdownGuard;
67
use nativelink_util::store_trait::{Store, StoreLike, UploadSizeInfo};
68
use nativelink_util::{background_spawn, spawn, spawn_blocking};
69
use parking_lot::Mutex;
70
use prost::Message;
71
use relative_path::RelativePath;
72
use scopeguard::{ScopeGuard, guard};
73
use serde::Deserialize;
74
use tokio::io::{AsyncReadExt, AsyncSeekExt};
75
use tokio::process;
76
use tokio::sync::{oneshot, watch};
77
use tokio_stream::wrappers::ReadDirStream;
78
use tonic::Request;
79
use tracing::{Level, enabled, event};
80
use uuid::Uuid;
81
82
/// For simplicity we use a fixed exit code for cases when our program is terminated
83
/// due to a signal.
84
const EXIT_CODE_FOR_SIGNAL: i32 = 9;
85
86
/// Default strategy for uploading historical results.
87
/// Note: If this value changes the config documentation
88
/// should reflect it.
89
const DEFAULT_HISTORICAL_RESULTS_STRATEGY: UploadCacheResultsStrategy =
90
    UploadCacheResultsStrategy::FailuresOnly;
91
92
/// Valid string reasons for a failure.
93
/// Note: If these change, the documentation should be updated.
94
#[derive(Debug, Deserialize)]
95
#[serde(rename_all = "snake_case")]
96
enum SideChannelFailureReason {
97
    /// Task should be considered timed out.
98
    Timeout,
99
}
100
101
/// This represents the json data that can be passed from the running process
102
/// to the parent via the `SideChannelFile`. See:
103
/// `config::EnvironmentSource::sidechannelfile` for more details.
104
/// Note: Any fields added here must be added to the documentation.
105
#[derive(Debug, Deserialize, Default)]
106
struct SideChannelInfo {
107
    /// If the task should be considered a failure and why.
108
    failure: Option<SideChannelFailureReason>,
109
}
110
111
/// Aggressively download the digests of files and make a local folder from it. This function
112
/// will spawn unbounded number of futures to try and get these downloaded. The store itself
113
/// should be rate limited if spawning too many requests at once is an issue.
114
/// We require the `FilesystemStore` to be the `fast` store of `FastSlowStore`. This is for
115
/// efficiency reasons. We will request the `FastSlowStore` to populate the entry then we will
116
/// assume the `FilesystemStore` has the file available immediately after and hardlink the file
117
/// to a new location.
118
// Sadly we cannot use `async fn` here because the rust compiler cannot determine the auto traits
119
// of the future. So we need to force this function to return a dynamic future instead.
120
// see: https://github.com/rust-lang/rust/issues/78649
121
25
pub fn download_to_directory<'a>(
122
25
    cas_store: &'a FastSlowStore,
123
25
    filesystem_store: Pin<&'a FilesystemStore>,
124
25
    digest: &'a DigestInfo,
125
25
    current_directory: &'a str,
126
25
) -> BoxFuture<'a, Result<(), Error>> {
127
25
    async move {
128
25
        let directory = get_and_decode_digest::<ProtoDirectory>(cas_store, digest.into())
129
25
            .await
130
25
            .err_tip(|| 
"Converting digest to Directory"0
)
?0
;
131
25
        let mut futures = FuturesUnordered::new();
132
133
29
        for 
file4
in directory.files {
134
4
            let digest: DigestInfo = file
135
4
                .digest
136
4
                .err_tip(|| 
"Expected Digest to exist in Directory::file::digest"0
)
?0
137
4
                .try_into()
138
4
                .err_tip(|| 
"In Directory::file::digest"0
)
?0
;
139
4
            let dest = format!("{}/{}", current_directory, file.name);
140
4
            let (mtime, mut unix_mode) = match file.node_properties {
141
1
                Some(properties) => (properties.mtime, properties.unix_mode),
142
3
                None => (None, None),
143
            };
144
            #[cfg_attr(target_family = "windows", allow(unused_assignments))]
145
4
            if file.is_executable {
  Branch (145:16): [True: 1, False: 3]
  Branch (145:16): [Folded - Ignored]
146
1
                unix_mode = Some(unix_mode.unwrap_or(0o444) | 0o111);
147
3
            }
148
4
            futures.push(
149
4
                cas_store
150
4
                    .populate_fast_store(digest.into())
151
4
                    .and_then(move |()| async move {
152
4
                        let file_entry = filesystem_store
153
4
                            .get_file_entry_for_digest(&digest)
154
4
                            .await
155
4
                            .err_tip(|| 
"During hard link"0
)
?0
;
156
4
                        file_entry
157
4
                            .get_file_path_locked(|src| fs::hard_link(src, &dest))
158
4
                            .await
159
4
                            .map_err(|e| {
160
0
                                make_err!(Code::Internal, "Could not make hardlink, {e:?} : {dest}")
161
0
                            })?;
162
                        #[cfg(target_family = "unix")]
163
4
                        if let Some(
unix_mode1
) = unix_mode {
  Branch (163:32): [True: 1, False: 3]
  Branch (163:32): [Folded - Ignored]
164
1
                            fs::set_permissions(&dest, Permissions::from_mode(unix_mode))
165
1
                                .await
166
1
                                .err_tip(|| {
167
0
                                    format!(
168
0
                                        "Could not set unix mode in download_to_directory {dest}"
169
0
                                    )
170
0
                                })?;
171
3
                        }
172
4
                        if let Some(
mtime1
) = mtime {
  Branch (172:32): [True: 1, False: 3]
  Branch (172:32): [Folded - Ignored]
173
1
                            spawn_blocking!("download_to_directory_set_mtime", move || {
174
1
                                set_file_mtime(
175
1
                                    &dest,
176
1
                                    FileTime::from_unix_time(mtime.seconds, mtime.nanos as u32),
177
1
                                )
178
1
                                .err_tip(|| {
179
0
                                    format!("Failed to set mtime in download_to_directory {dest}")
180
0
                                })
181
1
                            })
182
1
                            .await
183
1
                            .err_tip(
184
0
                                || "Failed to launch spawn_blocking in download_to_directory",
185
0
                            )??;
186
3
                        }
187
4
                        Ok(())
188
8
                    })
189
4
                    .map_err(move |e| 
e.append(format!("for digest {digest}"))0
)
190
4
                    .boxed(),
191
            );
192
        }
193
194
32
        for 
directory7
in directory.directories {
195
7
            let digest: DigestInfo = directory
196
7
                .digest
197
7
                .err_tip(|| 
"Expected Digest to exist in Directory::directories::digest"0
)
?0
198
7
                .try_into()
199
7
                .err_tip(|| 
"In Directory::file::digest"0
)
?0
;
200
7
            let new_directory_path = format!("{}/{}", current_directory, directory.name);
201
7
            futures.push(
202
7
                async move {
203
7
                    fs::create_dir(&new_directory_path)
204
7
                        .await
205
7
                        .err_tip(|| 
format!("Could not create directory {new_directory_path}")0
)
?0
;
206
7
                    download_to_directory(
207
7
                        cas_store,
208
7
                        filesystem_store,
209
7
                        &digest,
210
7
                        &new_directory_path,
211
7
                    )
212
7
                    .await
213
7
                    .err_tip(|| 
format!("in download_to_directory : {new_directory_path}")0
)
?0
;
214
7
                    Ok(())
215
7
                }
216
7
                .boxed(),
217
            );
218
        }
219
220
        #[cfg(target_family = "unix")]
221
26
        for 
symlink_node1
in directory.symlinks {
222
1
            let dest = format!("{}/{}", current_directory, symlink_node.name);
223
1
            futures.push(
224
1
                async move {
225
1
                    fs::symlink(&symlink_node.target, &dest).await.err_tip(|| {
226
0
                        format!(
227
0
                            "Could not create symlink {} -> {}",
228
0
                            symlink_node.target, dest
229
0
                        )
230
0
                    })?;
231
1
                    Ok(())
232
1
                }
233
1
                .boxed(),
234
            );
235
        }
236
237
37
        while futures.try_next().await
?0
.is_some()
{}12
  Branch (237:15): [True: 12, False: 25]
  Branch (237:15): [Folded - Ignored]
238
25
        Ok(())
239
25
    }
240
25
    .boxed()
241
25
}
242
243
#[cfg(target_family = "windows")]
244
fn is_executable(_metadata: &std::fs::Metadata, full_path: &impl AsRef<Path>) -> bool {
245
    static EXECUTABLE_EXTENSIONS: &[&str] = &["exe", "bat", "com"];
246
    EXECUTABLE_EXTENSIONS
247
        .iter()
248
        .any(|ext| full_path.as_ref().extension().map_or(false, |v| v == *ext))
249
}
250
251
#[cfg(target_family = "unix")]
252
7
fn is_executable(metadata: &std::fs::Metadata, _full_path: &impl AsRef<Path>) -> bool {
253
7
    (metadata.mode() & 0o111) != 0
254
7
}
255
256
7
async fn upload_file(
257
7
    cas_store: Pin<&impl StoreLike>,
258
7
    full_path: impl AsRef<Path> + Debug,
259
7
    hasher: DigestHasherFunc,
260
7
    metadata: std::fs::Metadata,
261
7
) -> Result<FileInfo, Error> {
262
7
    let is_executable = is_executable(&metadata, &full_path);
263
7
    let file_size = metadata.len();
264
7
    let file = fs::open_file(&full_path, 0, u64::MAX)
265
7
        .await
266
7
        .err_tip(|| 
format!("Could not open file {full_path:?}")0
)
?0
;
267
268
7
    let (digest, mut file) = hasher
269
7
        .hasher()
270
7
        .digest_for_file(&full_path, file.into_inner(), Some(file_size))
271
7
        .await
272
7
        .err_tip(|| 
format!("Failed to hash file in digest_for_file failed for {full_path:?}")0
)
?0
;
273
274
7
    file.rewind().await.err_tip(|| 
"Could not rewind file"0
)
?0
;
275
276
    // Note: For unknown reasons we appear to be hitting:
277
    // https://github.com/rust-lang/rust/issues/92096
278
    // or a smiliar issue if we try to use the non-store driver function, so we
279
    // are using the store driver function here.
280
7
    cas_store
281
7
        .as_store_driver_pin()
282
7
        .update_with_whole_file(
283
7
            digest.into(),
284
7
            full_path.as_ref().into(),
285
7
            file,
286
7
            UploadSizeInfo::ExactSize(digest.size_bytes()),
287
7
        )
288
7
        .await
289
7
        .err_tip(|| 
format!("for {full_path:?}")0
)
?0
;
290
291
7
    let name = full_path
292
7
        .as_ref()
293
7
        .file_name()
294
7
        .err_tip(|| 
format!("Expected file_name to exist on {full_path:?}")0
)
?0
295
7
        .to_str()
296
7
        .err_tip(|| {
297
0
            make_err!(
298
0
                Code::Internal,
299
0
                "Could not convert {:?} to string",
300
0
                full_path
301
0
            )
302
0
        })?
303
7
        .to_string();
304
7
305
7
    Ok(FileInfo {
306
7
        name_or_path: NameOrPath::Name(name),
307
7
        digest,
308
7
        is_executable,
309
7
    })
310
7
}
311
312
2
async fn upload_symlink(
313
2
    full_path: impl AsRef<Path> + Debug,
314
2
    full_work_directory_path: impl AsRef<Path>,
315
2
) -> Result<SymlinkInfo, Error> {
316
2
    let full_target_path = fs::read_link(full_path.as_ref())
317
2
        .await
318
2
        .err_tip(|| 
format!("Could not get read_link path of {full_path:?}")0
)
?0
;
319
320
    // Detect if our symlink is inside our work directory, if it is find the
321
    // relative path otherwise use the absolute path.
322
2
    let target = if full_target_path.starts_with(full_work_directory_path.as_ref()) {
  Branch (322:21): [Folded - Ignored]
  Branch (322:21): [Folded - Ignored]
  Branch (322:21): [True: 0, False: 1]
  Branch (322:21): [True: 0, False: 1]
323
0
        let full_target_path = RelativePath::from_path(&full_target_path)
324
0
            .map_err(|v| make_err!(Code::Internal, "Could not convert {} to RelativePath", v))?;
325
0
        RelativePath::from_path(full_work_directory_path.as_ref())
326
0
            .map_err(|v| make_err!(Code::Internal, "Could not convert {} to RelativePath", v))?
327
0
            .relative(full_target_path)
328
0
            .normalize()
329
0
            .into_string()
330
    } else {
331
2
        full_target_path
332
2
            .to_str()
333
2
            .err_tip(|| {
334
0
                make_err!(
335
0
                    Code::Internal,
336
0
                    "Could not convert '{:?}' to string",
337
0
                    full_target_path
338
0
                )
339
0
            })?
340
2
            .to_string()
341
    };
342
343
2
    let name = full_path
344
2
        .as_ref()
345
2
        .file_name()
346
2
        .err_tip(|| 
format!("Expected file_name to exist on {full_path:?}")0
)
?0
347
2
        .to_str()
348
2
        .err_tip(|| {
349
0
            make_err!(
350
0
                Code::Internal,
351
0
                "Could not convert {:?} to string",
352
0
                full_path
353
0
            )
354
0
        })?
355
2
        .to_string();
356
2
357
2
    Ok(SymlinkInfo {
358
2
        name_or_path: NameOrPath::Name(name),
359
2
        target,
360
2
    })
361
2
}
362
363
3
fn upload_directory<'a, P: AsRef<Path> + Debug + Send + Sync + Clone + 'a>(
364
3
    cas_store: Pin<&'a impl StoreLike>,
365
3
    full_dir_path: P,
366
3
    full_work_directory: &'a str,
367
3
    hasher: DigestHasherFunc,
368
3
) -> BoxFuture<'a, Result<(Directory, VecDeque<ProtoDirectory>), Error>> {
369
3
    Box::pin(async move {
370
3
        let file_futures = FuturesUnordered::new();
371
3
        let dir_futures = FuturesUnordered::new();
372
3
        let symlink_futures = FuturesUnordered::new();
373
        {
374
3
            let (_permit, dir_handle) = fs::read_dir(&full_dir_path)
375
3
                .await
376
3
                .err_tip(|| 
format!("Error reading dir for reading {full_dir_path:?}")0
)
?0
377
3
                .into_inner();
378
3
            let mut dir_stream = ReadDirStream::new(dir_handle);
379
            // Note: Try very hard to not leave file descriptors open. Try to keep them as short
380
            // lived as possible. This is why we iterate the directory and then build a bunch of
381
            // futures with all the work we are wanting to do then execute it. It allows us to
382
            // close the directory iterator file descriptor, then open the child files/folders.
383
8
            while let Some(
entry_result5
) = dir_stream.next().await {
  Branch (383:23): [Folded - Ignored]
  Branch (383:23): [Folded - Ignored]
  Branch (383:23): [True: 1, False: 1]
  Branch (383:23): [True: 4, False: 2]
384
5
                let entry = entry_result.err_tip(|| 
"Error while iterating directory"0
)
?0
;
385
5
                let file_type = entry
386
5
                    .file_type()
387
5
                    .await
388
5
                    .err_tip(|| 
format!("Error running file_type() on {entry:?}")0
)
?0
;
389
5
                let full_path = full_dir_path.as_ref().join(entry.path());
390
5
                if file_type.is_dir() {
  Branch (390:20): [Folded - Ignored]
  Branch (390:20): [Folded - Ignored]
  Branch (390:20): [True: 0, False: 1]
  Branch (390:20): [True: 1, False: 3]
391
1
                    let full_dir_path = full_dir_path.clone();
392
1
                    dir_futures.push(
393
1
                        upload_directory(cas_store, full_path.clone(), full_work_directory, hasher)
394
1
                            .and_then(|(dir, all_dirs)| async move {
395
1
                                let directory_name = full_path
396
1
                                    .file_name()
397
1
                                    .err_tip(|| {
398
0
                                        format!("Expected file_name to exist on {full_dir_path:?}")
399
0
                                    })?
400
1
                                    .to_str()
401
1
                                    .err_tip(|| {
402
0
                                        make_err!(
403
0
                                            Code::Internal,
404
0
                                            "Could not convert {:?} to string",
405
0
                                            full_dir_path
406
0
                                        )
407
0
                                    })?
408
1
                                    .to_string();
409
410
1
                                let digest = serialize_and_upload_message(
411
1
                                    &dir,
412
1
                                    cas_store,
413
1
                                    &mut hasher.hasher(),
414
1
                                )
415
1
                                .await
416
1
                                .err_tip(|| 
format!("for {full_path:?}")0
)
?0
;
417
418
1
                                Result::<(DirectoryNode, VecDeque<Directory>), Error>::Ok((
419
1
                                    DirectoryNode {
420
1
                                        name: directory_name,
421
1
                                        digest: Some(digest.into()),
422
1
                                    },
423
1
                                    all_dirs,
424
1
                                ))
425
2
                            })
426
1
                            .boxed(),
427
                    );
428
4
                } else if file_type.is_file() {
  Branch (428:27): [Folded - Ignored]
  Branch (428:27): [Folded - Ignored]
  Branch (428:27): [True: 0, False: 1]
  Branch (428:27): [True: 3, False: 0]
429
3
                    file_futures.push(async move {
430
3
                        let metadata = fs::metadata(&full_path)
431
3
                            .await
432
3
                            .err_tip(|| 
format!("Could not open file {full_path:?}")0
)
?0
;
433
3
                        upload_file(cas_store, &full_path, hasher, metadata)
434
3
                            .map_ok(Into::into)
435
3
                            .await
436
3
                    });
437
1
                } else if file_type.is_symlink() {
  Branch (437:27): [Folded - Ignored]
  Branch (437:27): [Folded - Ignored]
  Branch (437:27): [True: 1, False: 0]
  Branch (437:27): [True: 0, False: 0]
438
1
                    symlink_futures
439
1
                        .push(upload_symlink(full_path, &full_work_directory).map_ok(Into::into));
440
1
                
}0
441
            }
442
        }
443
444
3
        let (mut file_nodes, dir_entries, mut symlinks) = try_join3(
445
3
            file_futures.try_collect::<Vec<FileNode>>(),
446
3
            dir_futures.try_collect::<Vec<(DirectoryNode, VecDeque<Directory>)>>(),
447
3
            symlink_futures.try_collect::<Vec<SymlinkNode>>(),
448
3
        )
449
3
        .await
?0
;
450
451
3
        let mut directory_nodes = Vec::with_capacity(dir_entries.len());
452
3
        // For efficiency we use a deque because it allows cheap concat of Vecs.
453
3
        // We make the assumption here that when performance is important it is because
454
3
        // our directory is quite large. This allows us to cheaply merge large amounts of
455
3
        // directories into one VecDeque. Then after we are done we need to collapse it
456
3
        // down into a single Vec.
457
3
        let mut all_child_directories = VecDeque::with_capacity(dir_entries.len());
458
4
        for (
directory_node, mut recursive_child_directories1
) in dir_entries {
459
1
            directory_nodes.push(directory_node);
460
1
            all_child_directories.append(&mut recursive_child_directories);
461
1
        }
462
463
3
        file_nodes.sort_unstable_by(|a, b| 
a.name.cmp(&b.name)1
);
464
3
        directory_nodes.sort_unstable_by(|a, b| 
a.name.cmp(&b.name)0
);
465
3
        symlinks.sort_unstable_by(|a, b| 
a.name.cmp(&b.name)0
);
466
467
3
        let directory = Directory {
468
3
            files: file_nodes,
469
3
            directories: directory_nodes,
470
3
            symlinks,
471
3
            node_properties: None, // We don't support file properties.
472
3
        };
473
3
        all_child_directories.push_back(directory.clone());
474
3
475
3
        Ok((directory, all_child_directories))
476
3
    })
477
3
}
478
479
0
async fn process_side_channel_file(
480
0
    side_channel_file: Cow<'_, OsStr>,
481
0
    args: &[&OsStr],
482
0
    timeout: Duration,
483
0
) -> Result<Option<Error>, Error> {
484
0
    let mut json_contents = String::new();
485
    {
486
        // Note: Scoping `file_slot` allows the file_slot semaphore to be released faster.
487
0
        let mut file_slot = match fs::open_file(side_channel_file, 0, u64::MAX).await {
488
0
            Ok(file_slot) => file_slot,
489
0
            Err(e) => {
490
0
                if e.code != Code::NotFound {
  Branch (490:20): [Folded - Ignored]
  Branch (490:20): [Folded - Ignored]
  Branch (490:20): [True: 0, False: 0]
491
0
                    return Err(e).err_tip(|| "Error opening side channel file");
492
0
                }
493
0
                // Note: If file does not exist, it's ok. Users are not required to create this file.
494
0
                return Ok(None);
495
            }
496
        };
497
0
        file_slot
498
0
            .read_to_string(&mut json_contents)
499
0
            .await
500
0
            .err_tip(|| "Error reading side channel file")?;
501
    }
502
503
0
    let side_channel_info: SideChannelInfo =
504
0
        serde_json5::from_str(&json_contents).map_err(|e| {
505
0
            make_input_err!(
506
0
                "Could not convert contents of side channel file (json) to SideChannelInfo : {e:?}"
507
0
            )
508
0
        })?;
509
0
    Ok(side_channel_info.failure.map(|failure| match failure {
510
0
        SideChannelFailureReason::Timeout => Error::new(
511
0
            Code::DeadlineExceeded,
512
0
            format!(
513
0
                "Command '{}' timed out after {} seconds",
514
0
                args.join(OsStr::new(" ")).to_string_lossy(),
515
0
                timeout.as_secs_f32()
516
0
            ),
517
0
        ),
518
0
    }))
519
0
}
520
521
15
async fn do_cleanup(
522
15
    running_actions_manager: &RunningActionsManagerImpl,
523
15
    operation_id: &OperationId,
524
15
    action_directory: &str,
525
15
) -> Result<(), Error> {
526
15
    event!(Level::INFO, 
"Worker cleaning up"0
);
527
    // Note: We need to be careful to keep trying to cleanup even if one of the steps fails.
528
15
    let remove_dir_result = fs::remove_dir_all(action_directory)
529
15
        .await
530
15
        .err_tip(|| 
format!("Could not remove working directory {action_directory}")0
);
531
15
    if let Err(
err0
) = running_actions_manager.cleanup_action(operation_id) {
  Branch (531:12): [True: 0, False: 0]
  Branch (531:12): [Folded - Ignored]
  Branch (531:12): [True: 0, False: 15]
532
0
        event!(
533
0
            Level::ERROR,
534
            ?operation_id,
535
            ?err,
536
0
            "Error cleaning up action"
537
        );
538
0
        return Result::<(), Error>::Err(err).merge(remove_dir_result);
539
15
    }
540
15
    if let Err(
err0
) = remove_dir_result {
  Branch (540:12): [True: 0, False: 0]
  Branch (540:12): [Folded - Ignored]
  Branch (540:12): [True: 0, False: 15]
541
0
        event!(
542
0
            Level::ERROR,
543
            ?operation_id,
544
            ?err,
545
0
            "Error removing working directory"
546
        );
547
0
        return Err(err);
548
15
    }
549
15
    Ok(())
550
15
}
551
552
pub trait RunningAction: Sync + Send + Sized + Unpin + 'static {
553
    /// Returns the action id of the action.
554
    fn get_operation_id(&self) -> &OperationId;
555
556
    /// Anything that needs to execute before the actions is actually executed should happen here.
557
    fn prepare_action(self: Arc<Self>) -> impl Future<Output = Result<Arc<Self>, Error>> + Send;
558
559
    /// Actually perform the execution of the action.
560
    fn execute(self: Arc<Self>) -> impl Future<Output = Result<Arc<Self>, Error>> + Send;
561
562
    /// Any uploading, processing or analyzing of the results should happen here.
563
    fn upload_results(self: Arc<Self>) -> impl Future<Output = Result<Arc<Self>, Error>> + Send;
564
565
    /// Cleanup any residual files, handles or other junk resulting from running the action.
566
    fn cleanup(self: Arc<Self>) -> impl Future<Output = Result<Arc<Self>, Error>> + Send;
567
568
    /// Returns the final result. As a general rule this action should be thought of as
569
    /// a consumption of `self`, meaning once a return happens here the lifetime of `Self`
570
    /// is over and any action performed on it after this call is undefined behavior.
571
    fn get_finished_result(
572
        self: Arc<Self>,
573
    ) -> impl Future<Output = Result<ActionResult, Error>> + Send;
574
575
    /// Returns the work directory of the action.
576
    fn get_work_directory(&self) -> &String;
577
}
578
579
#[derive(Debug)]
580
struct RunningActionImplExecutionResult {
581
    stdout: Bytes,
582
    stderr: Bytes,
583
    exit_code: i32,
584
}
585
586
#[derive(Debug)]
587
struct RunningActionImplState {
588
    command_proto: Option<ProtoCommand>,
589
    // TODO(allada) Kill is not implemented yet, but is instrumented.
590
    // However, it is used if the worker disconnects to destroy current jobs.
591
    kill_channel_tx: Option<oneshot::Sender<()>>,
592
    kill_channel_rx: Option<oneshot::Receiver<()>>,
593
    execution_result: Option<RunningActionImplExecutionResult>,
594
    action_result: Option<ActionResult>,
595
    execution_metadata: ExecutionMetadata,
596
    // If there was an internal error, this will be set.
597
    // This should NOT be set if everything was fine, but the process had a
598
    // non-zero exit code. Instead this should be used for internal errors
599
    // that prevented the action from running, upload failures, timeouts, exc...
600
    // but we have (or could have) the action results (like stderr/stdout).
601
    error: Option<Error>,
602
}
603
604
#[derive(Debug)]
605
pub struct RunningActionImpl {
606
    operation_id: OperationId,
607
    action_directory: String,
608
    work_directory: String,
609
    action_info: ActionInfo,
610
    timeout: Duration,
611
    running_actions_manager: Arc<RunningActionsManagerImpl>,
612
    state: Mutex<RunningActionImplState>,
613
    did_cleanup: AtomicBool,
614
}
615
616
impl RunningActionImpl {
617
15
    fn new(
618
15
        execution_metadata: ExecutionMetadata,
619
15
        operation_id: OperationId,
620
15
        action_directory: String,
621
15
        action_info: ActionInfo,
622
15
        timeout: Duration,
623
15
        running_actions_manager: Arc<RunningActionsManagerImpl>,
624
15
    ) -> Self {
625
15
        let work_directory = format!("{}/{}", action_directory, "work");
626
15
        let (kill_channel_tx, kill_channel_rx) = oneshot::channel();
627
15
        Self {
628
15
            operation_id,
629
15
            action_directory,
630
15
            work_directory,
631
15
            action_info,
632
15
            timeout,
633
15
            running_actions_manager,
634
15
            state: Mutex::new(RunningActionImplState {
635
15
                command_proto: None,
636
15
                kill_channel_rx: Some(kill_channel_rx),
637
15
                kill_channel_tx: Some(kill_channel_tx),
638
15
                execution_result: None,
639
15
                action_result: None,
640
15
                execution_metadata,
641
15
                error: None,
642
15
            }),
643
15
            did_cleanup: AtomicBool::new(false),
644
15
        }
645
15
    }
646
647
    #[allow(
648
        clippy::missing_const_for_fn,
649
        reason = "False positive on stable, but not on nightly"
650
    )]
651
169
    fn metrics(&self) -> &Arc<Metrics> {
652
169
        &self.running_actions_manager.metrics
653
169
    }
654
655
    /// Prepares any actions needed to execution this action. This action will do the following:
656
    ///
657
    /// * Download any files needed to execute the action
658
    /// * Build a folder with all files needed to execute the action.
659
    ///
660
    /// This function will aggressively download and spawn potentially thousands of futures. It is
661
    /// up to the stores to rate limit if needed.
662
15
    
async fn inner_prepare_action(self: Arc<Self>) -> Result<Arc<Self>, Error> 0
{
663
15
        {
664
15
            let mut state = self.state.lock();
665
15
            state.execution_metadata.input_fetch_start_timestamp =
666
15
                (self.running_actions_manager.callbacks.now_fn)();
667
15
        }
668
15
        let command = {
669
            // Download and build out our input files/folders. Also fetch and decode our Command.
670
15
            let command_fut = self.metrics().get_proto_command_from_store.wrap(async {
671
15
                get_and_decode_digest::<ProtoCommand>(
672
15
                    self.running_actions_manager.cas_store.as_ref(),
673
15
                    self.action_info.command_digest.into(),
674
15
                )
675
15
                .await
676
15
                .err_tip(|| 
"Converting command_digest to Command"0
)
677
15
            });
678
15
            let filesystem_store_pin =
679
15
                Pin::new(self.running_actions_manager.filesystem_store.as_ref());
680
15
            let (command, ()) = try_join(command_fut, async {
681
15
                fs::create_dir(&self.work_directory)
682
15
                    .await
683
15
                    .err_tip(|| 
format!("Error creating work directory {}", self.work_directory)0
)
?0
;
684
                // Download the input files/folder and place them into the temp directory.
685
15
                self.metrics()
686
15
                    .download_to_directory
687
15
                    .wrap(download_to_directory(
688
15
                        &self.running_actions_manager.cas_store,
689
15
                        filesystem_store_pin,
690
15
                        &self.action_info.input_root_digest,
691
15
                        &self.work_directory,
692
15
                    ))
693
15
                    .await
694
15
            })
695
15
            .await
?0
;
696
15
            command
697
15
        };
698
15
        {
699
15
            // Create all directories needed for our output paths. This is required by the bazel spec.
700
15
            let prepare_output_directories = |output_file| 
{9
701
9
                let full_output_path = if command.working_directory.is_empty() {
  Branch (701:43): [Folded - Ignored]
  Branch (701:43): [Folded - Ignored]
  Branch (701:43): [True: 1, False: 8]
702
1
                    format!("{}/{}", self.work_directory, output_file)
703
                } else {
704
8
                    format!(
705
8
                        "{}/{}/{}",
706
8
                        self.work_directory, command.working_directory, output_file
707
                    )
708
                };
709
9
                async move {
710
9
                    let full_parent_path = Path::new(&full_output_path)
711
9
                        .parent()
712
9
                        .err_tip(|| 
format!("Parent path for {full_output_path} has no parent")0
)
?0
;
713
9
                    fs::create_dir_all(full_parent_path).await.err_tip(|| {
714
0
                        format!(
715
0
                            "Error creating output directory {} (file)",
716
0
                            full_parent_path.display()
717
0
                        )
718
0
                    })?;
719
9
                    Result::<(), Error>::Ok(())
720
9
                }
721
9
            };
722
15
            self.metrics()
723
15
                .prepare_output_files
724
15
                .wrap(try_join_all(
725
15
                    command.output_files.iter().map(prepare_output_directories),
726
15
                ))
727
15
                .await
?0
;
728
15
            self.metrics()
729
15
                .prepare_output_paths
730
15
                .wrap(try_join_all(
731
15
                    command.output_paths.iter().map(prepare_output_directories),
732
15
                ))
733
15
                .await
?0
;
734
        }
735
15
        event!(Level::INFO, ?command, 
"Worker received command"0
,);
736
15
        {
737
15
            let mut state = self.state.lock();
738
15
            state.command_proto = Some(command);
739
15
            state.execution_metadata.input_fetch_completed_timestamp =
740
15
                (self.running_actions_manager.callbacks.now_fn)();
741
15
        }
742
15
        Ok(self)
743
15
    }
744
745
13
    
async fn inner_execute(self: Arc<Self>) -> Result<Arc<Self>, Error> 0
{
746
13
        let (command_proto, mut kill_channel_rx) = {
747
13
            let mut state = self.state.lock();
748
13
            state.execution_metadata.execution_start_timestamp =
749
13
                (self.running_actions_manager.callbacks.now_fn)();
750
13
            (
751
13
                state
752
13
                    .command_proto
753
13
                    .take()
754
13
                    .err_tip(|| 
"Expected state to have command_proto in execute()"0
)
?0
,
755
13
                state
756
13
                    .kill_channel_rx
757
13
                    .take()
758
13
                    .err_tip(|| 
"Expected state to have kill_channel_rx in execute()"0
)
?0
759
                    // This is important as we may be killed at any point.
760
13
                    .fuse(),
761
13
            )
762
13
        };
763
13
        if command_proto.arguments.is_empty() {
  Branch (763:12): [Folded - Ignored]
  Branch (763:12): [Folded - Ignored]
  Branch (763:12): [True: 0, False: 13]
764
0
            return Err(make_input_err!("No arguments provided in Command proto"));
765
13
        }
766
13
        let args: Vec<&OsStr> = if let Some(
entrypoint0
) = &self
  Branch (766:40): [Folded - Ignored]
  Branch (766:40): [Folded - Ignored]
  Branch (766:40): [True: 0, False: 13]
767
13
            .running_actions_manager
768
13
            .execution_configuration
769
13
            .entrypoint
770
        {
771
0
            std::iter::once(entrypoint.as_ref())
772
0
                .chain(command_proto.arguments.iter().map(AsRef::as_ref))
773
0
                .collect()
774
        } else {
775
13
            command_proto.arguments.iter().map(AsRef::as_ref).collect()
776
        };
777
13
        event!(Level::INFO, ?args, 
"Executing command"0
,);
778
13
        let mut command_builder = process::Command::new(args[0]);
779
13
        command_builder
780
13
            .args(&args[1..])
781
13
            .kill_on_drop(true)
782
13
            .stdin(Stdio::null())
783
13
            .stdout(Stdio::piped())
784
13
            .stderr(Stdio::piped())
785
13
            .current_dir(format!(
786
13
                "{}/{}",
787
13
                self.work_directory, command_proto.working_directory
788
13
            ))
789
13
            .env_clear();
790
791
13
        let requested_timeout = if self.action_info.timeout.is_zero() {
  Branch (791:36): [Folded - Ignored]
  Branch (791:36): [Folded - Ignored]
  Branch (791:36): [True: 11, False: 2]
792
11
            self.running_actions_manager.max_action_timeout
793
        } else {
794
2
            self.action_info.timeout
795
        };
796
797
13
        let mut maybe_side_channel_file: Option<Cow<'_, OsStr>> = None;
798
13
        if let Some(
additional_environment0
) = &self
  Branch (798:16): [Folded - Ignored]
  Branch (798:16): [Folded - Ignored]
  Branch (798:16): [True: 0, False: 13]
799
13
            .running_actions_manager
800
13
            .execution_configuration
801
13
            .additional_environment
802
        {
803
0
            for (name, source) in additional_environment {
804
0
                let value = match source {
805
0
                    EnvironmentSource::Property(property) => self
806
0
                        .action_info
807
0
                        .platform_properties
808
0
                        .get(property)
809
0
                        .map_or_else(|| Cow::Borrowed(""), |v| Cow::Borrowed(v.as_str())),
810
0
                    EnvironmentSource::Value(value) => Cow::Borrowed(value.as_str()),
811
                    EnvironmentSource::TimeoutMillis => {
812
0
                        Cow::Owned(requested_timeout.as_millis().to_string())
813
                    }
814
                    EnvironmentSource::SideChannelFile => {
815
0
                        let file_cow =
816
0
                            format!("{}/{}", self.action_directory, Uuid::new_v4().simple());
817
0
                        maybe_side_channel_file = Some(Cow::Owned(file_cow.clone().into()));
818
0
                        Cow::Owned(file_cow)
819
                    }
820
                    EnvironmentSource::ActionDirectory => {
821
0
                        Cow::Borrowed(self.action_directory.as_str())
822
                    }
823
                };
824
0
                command_builder.env(name, value.as_ref());
825
            }
826
13
        }
827
828
        #[cfg(target_family = "unix")]
829
13
        let envs = &command_proto.environment_variables;
830
        // If SystemRoot is not set on windows we set it to default. Failing to do
831
        // this causes all commands to fail.
832
        #[cfg(target_family = "windows")]
833
        let envs = {
834
            let mut envs = command_proto.environment_variables.clone();
835
            if !envs.iter().any(|v| v.name.to_uppercase() == "SYSTEMROOT") {
836
                envs.push(
837
                    nativelink_proto::build::bazel::remote::execution::v2::command::EnvironmentVariable {
838
                        name: "SystemRoot".to_string(),
839
                        value: "C:\\Windows".to_string(),
840
                    },
841
                );
842
            }
843
            if !envs.iter().any(|v| v.name.to_uppercase() == "PATH") {
844
                envs.push(
845
                    nativelink_proto::build::bazel::remote::execution::v2::command::EnvironmentVariable {
846
                        name: "PATH".to_string(),
847
                        value: "C:\\Windows\\System32".to_string(),
848
                    },
849
                );
850
            }
851
            envs
852
        };
853
26
        for 
environment_variable13
in envs {
854
13
            command_builder.env(&environment_variable.name, &environment_variable.value);
855
13
        }
856
857
13
        let mut child_process = command_builder
858
13
            .spawn()
859
13
            .err_tip(|| 
format!("Could not execute command {args:?}")0
)
?0
;
860
13
        let mut stdout_reader = child_process
861
13
            .stdout
862
13
            .take()
863
13
            .err_tip(|| 
"Expected stdout to exist on command this should never happen"0
)
?0
;
864
13
        let mut stderr_reader = child_process
865
13
            .stderr
866
13
            .take()
867
13
            .err_tip(|| 
"Expected stderr to exist on command this should never happen"0
)
?0
;
868
869
13
        let mut child_process_guard = guard(child_process, |mut child_process| {
870
0
            event!(
871
0
                Level::ERROR,
872
0
                "Child process was not cleaned up before dropping the call to execute(), killing in background spawn."
873
            );
874
0
            background_spawn!("running_actions_manager_kill_child_process", async move {
875
0
                child_process.kill().await
876
0
            });
877
0
        });
878
879
13
        let all_stdout_fut = spawn!("stdout_reader", async move {
880
13
            let mut all_stdout = BytesMut::new();
881
            loop {
882
16
                let 
sz14
= stdout_reader
883
16
                    .read_buf(&mut all_stdout)
884
16
                    .await
885
14
                    .err_tip(|| 
"Error reading stdout stream"0
)
?0
;
886
14
                if sz == 0 {
  Branch (886:20): [Folded - Ignored]
  Branch (886:20): [Folded - Ignored]
  Branch (886:20): [True: 11, False: 3]
887
11
                    break; // EOF.
888
3
                }
889
            }
890
11
            Result::<Bytes, Error>::Ok(all_stdout.freeze())
891
11
        });
892
13
        let all_stderr_fut = spawn!("stderr_reader", async move {
893
13
            let mut all_stderr = BytesMut::new();
894
            loop {
895
16
                let 
sz14
= stderr_reader
896
16
                    .read_buf(&mut all_stderr)
897
16
                    .await
898
14
                    .err_tip(|| 
"Error reading stderr stream"0
)
?0
;
899
14
                if sz == 0 {
  Branch (899:20): [Folded - Ignored]
  Branch (899:20): [Folded - Ignored]
  Branch (899:20): [True: 11, False: 3]
900
11
                    break; // EOF.
901
3
                }
902
            }
903
11
            Result::<Bytes, Error>::Ok(all_stderr.freeze())
904
11
        });
905
13
        let mut killed_action = false;
906
13
907
13
        let timer = self.metrics().child_process.begin_timer();
908
13
        let mut sleep_fut = (self.running_actions_manager.callbacks.sleep_fn)(self.timeout).fuse();
909
        loop {
910
17
            tokio::select! {
911
17
                () = &mut sleep_fut => {
912
2
                    self.running_actions_manager.metrics.task_timeouts.inc();
913
2
                    killed_action = true;
914
2
                    if let Err(
err0
) = child_process_guard.start_kill() {
  Branch (914:28): [Folded - Ignored]
  Branch (914:28): [Folded - Ignored]
  Branch (914:28): [True: 0, False: 2]
915
0
                        event!(
916
0
                            Level::ERROR,
917
                            ?err,
918
0
                            "Could not kill process in RunningActionsManager for action timeout",
919
                        );
920
2
                    }
921
2
                    {
922
2
                        let mut state = self.state.lock();
923
2
                        state.error = Error::merge_option(state.error.take(), Some(Error::new(
924
2
                            Code::DeadlineExceeded,
925
2
                            format!(
926
2
                                "Command '{}' timed out after {} seconds",
927
2
                                args.join(OsStr::new(" ")).to_string_lossy(),
928
2
                                self.action_info.timeout.as_secs_f32()
929
2
                            )
930
2
                        )));
931
2
                    }
932
                },
933
17
                
maybe_exit_status13
= child_process_guard.wait() => {
934
                    // Defuse our guard so it does not try to cleanup and make nessless logs.
935
13
                    drop(ScopeGuard::<_, _>::into_inner(child_process_guard));
936
13
                    let exit_status = maybe_exit_status.err_tip(|| 
"Failed to collect exit code of process"0
)
?0
;
937
                    // TODO(allada) We should implement stderr/stdout streaming to client here.
938
                    // If we get killed before the stream is started, then these will lock up.
939
                    // TODO(allada) There is a significant bug here. If we kill the action and the action creates
940
                    // child processes, it can create zombies. See: https://github.com/tracemachina/nativelink/issues/225
941
13
                    let (stdout, stderr) = if killed_action {
  Branch (941:47): [Folded - Ignored]
  Branch (941:47): [Folded - Ignored]
  Branch (941:47): [True: 4, False: 9]
942
4
                        drop(timer);
943
4
                        (Bytes::new(), Bytes::new())
944
                    } else {
945
9
                        timer.measure();
946
9
                        let (maybe_all_stdout, maybe_all_stderr) = tokio::join!(all_stdout_fut, all_stderr_fut);
947
                        (
948
9
                            maybe_all_stdout.err_tip(|| 
"Internal error reading from stdout of worker task"0
)
?0
?0
,
949
9
                            maybe_all_stderr.err_tip(|| 
"Internal error reading from stderr of worker task"0
)
?0
?0
950
                        )
951
                    };
952
13
                    let exit_code = if let Some(
exit_code9
) = exit_status.code() {
  Branch (952:44): [Folded - Ignored]
  Branch (952:44): [Folded - Ignored]
  Branch (952:44): [True: 9, False: 4]
953
9
                        if exit_code == 0 {
  Branch (953:28): [Folded - Ignored]
  Branch (953:28): [Folded - Ignored]
  Branch (953:28): [True: 8, False: 1]
954
8
                            self.metrics().child_process_success_error_code.inc();
955
8
                        } else {
956
1
                            self.metrics().child_process_failure_error_code.inc();
957
1
                        }
958
9
                        exit_code
959
                    } else {
960
4
                        EXIT_CODE_FOR_SIGNAL
961
                    };
962
963
13
                    let maybe_error_override = if let Some(
side_channel_file0
) = maybe_side_channel_file {
  Branch (963:55): [Folded - Ignored]
  Branch (963:55): [Folded - Ignored]
  Branch (963:55): [True: 0, False: 13]
964
0
                        process_side_channel_file(side_channel_file.clone(), &args, requested_timeout).await
965
0
                        .err_tip(|| format!("Error processing side channel file: {side_channel_file:?}"))?
966
                    } else {
967
13
                        None
968
                    };
969
13
                    {
970
13
                        let mut state = self.state.lock();
971
13
                        state.error = Error::merge_option(state.error.take(), maybe_error_override);
972
13
973
13
                        state.command_proto = Some(command_proto);
974
13
                        state.execution_result = Some(RunningActionImplExecutionResult{
975
13
                            stdout,
976
13
                            stderr,
977
13
                            exit_code,
978
13
                        });
979
13
                        state.execution_metadata.execution_completed_timestamp = (self.running_actions_manager.callbacks.now_fn)();
980
13
                    }
981
13
                    return Ok(self);
982
                },
983
17
                _ = &mut kill_channel_rx => {
984
2
                    killed_action = true;
985
2
                    if let Err(
err0
) = child_process_guard.start_kill() {
  Branch (985:28): [Folded - Ignored]
  Branch (985:28): [Folded - Ignored]
  Branch (985:28): [True: 0, False: 2]
986
0
                        event!(
987
0
                            Level::ERROR,
988
0
                            operation_id = ?self.operation_id,
989
0
                            ?err,
990
0
                            "Could not kill process",
991
                        );
992
2
                    }
993
2
                    {
994
2
                        let mut state = self.state.lock();
995
2
                        state.error = Error::merge_option(state.error.take(), Some(Error::new(
996
2
                            Code::Aborted,
997
2
                            format!(
998
2
                                "Command '{}' was killed by scheduler",
999
2
                                args.join(OsStr::new(" ")).to_string_lossy()
1000
2
                            )
1001
2
                        )));
1002
2
                    }
1003
                },
1004
            }
1005
        }
1006
        // Unreachable.
1007
13
    }
1008
1009
11
    async fn inner_upload_results(self: Arc<Self>) -> Result<Arc<Self>, Error> {
1010
        enum OutputType {
1011
            None,
1012
            File(FileInfo),
1013
            Directory(DirectoryInfo),
1014
            FileSymlink(SymlinkInfo),
1015
            DirectorySymlink(SymlinkInfo),
1016
        }
1017
1018
11
        event!(Level::INFO, 
"Worker uploading results"0
,);
1019
11
        let (mut command_proto, execution_result, mut execution_metadata) = {
1020
11
            let mut state = self.state.lock();
1021
11
            state.execution_metadata.output_upload_start_timestamp =
1022
11
                (self.running_actions_manager.callbacks.now_fn)();
1023
11
            (
1024
11
                state
1025
11
                    .command_proto
1026
11
                    .take()
1027
11
                    .err_tip(|| 
"Expected state to have command_proto in execute()"0
)
?0
,
1028
11
                state
1029
11
                    .execution_result
1030
11
                    .take()
1031
11
                    .err_tip(|| 
"Execution result does not exist at upload_results stage"0
)
?0
,
1032
11
                state.execution_metadata.clone(),
1033
11
            )
1034
11
        };
1035
11
        let cas_store = self.running_actions_manager.cas_store.as_ref();
1036
11
        let hasher = self.action_info.unique_qualifier.digest_function();
1037
11
1038
11
        let mut output_path_futures = FuturesUnordered::new();
1039
11
        let mut output_paths = command_proto.output_paths;
1040
11
        if output_paths.is_empty() {
  Branch (1040:12): [Folded - Ignored]
  Branch (1040:12): [Folded - Ignored]
  Branch (1040:12): [True: 6, False: 5]
1041
6
            output_paths
1042
6
                .reserve(command_proto.output_files.len() + command_proto.output_directories.len());
1043
6
            output_paths.append(&mut command_proto.output_files);
1044
6
            output_paths.append(&mut command_proto.output_directories);
1045
6
        
}5
1046
18
        for 
entry7
in output_paths {
1047
7
            let full_path = OsString::from(if command_proto.working_directory.is_empty() {
  Branch (1047:47): [Folded - Ignored]
  Branch (1047:47): [Folded - Ignored]
  Branch (1047:47): [True: 0, False: 7]
1048
0
                format!("{}/{}", self.work_directory, entry)
1049
            } else {
1050
7
                format!(
1051
7
                    "{}/{}/{}",
1052
7
                    self.work_directory, command_proto.working_directory, entry
1053
                )
1054
            });
1055
7
            let work_directory = &self.work_directory;
1056
7
            output_path_futures.push(async move {
1057
3
                let metadata = {
1058
7
                    let metadata = match fs::symlink_metadata(&full_path).await {
1059
7
                        Ok(file) => file,
1060
0
                        Err(e) => {
1061
0
                            if e.code == Code::NotFound {
  Branch (1061:32): [Folded - Ignored]
  Branch (1061:32): [Folded - Ignored]
  Branch (1061:32): [True: 0, False: 0]
1062
                                // In the event our output does not exist, according to the bazel remote
1063
                                // execution spec, we simply ignore it continue.
1064
0
                                return Result::<OutputType, Error>::Ok(OutputType::None);
1065
0
                            }
1066
0
                            return Err(e).err_tip(|| format!("Could not open file {full_path:?}"));
1067
                        }
1068
                    };
1069
1070
7
                    if metadata.is_file() {
  Branch (1070:24): [Folded - Ignored]
  Branch (1070:24): [Folded - Ignored]
  Branch (1070:24): [True: 4, False: 3]
1071
                        return Ok(OutputType::File(
1072
4
                            upload_file(cas_store.as_pin(), &full_path, hasher, metadata)
1073
4
                                .await
1074
4
                                .map(|mut file_info| {
1075
4
                                    file_info.name_or_path = NameOrPath::Path(entry);
1076
4
                                    file_info
1077
4
                                })
1078
4
                                .err_tip(|| 
format!("Uploading file {full_path:?}")0
)
?0
,
1079
                        ));
1080
3
                    }
1081
3
                    metadata
1082
3
                };
1083
3
                if metadata.is_dir() {
  Branch (1083:20): [Folded - Ignored]
  Branch (1083:20): [Folded - Ignored]
  Branch (1083:20): [True: 2, False: 1]
1084
                    Ok(OutputType::Directory(
1085
2
                        upload_directory(cas_store.as_pin(), &full_path, work_directory, hasher)
1086
2
                            .and_then(|(root_dir, children)| async move {
1087
2
                                let tree = ProtoTree {
1088
2
                                    root: Some(root_dir),
1089
2
                                    children: children.into(),
1090
2
                                };
1091
2
                                let tree_digest = serialize_and_upload_message(
1092
2
                                    &tree,
1093
2
                                    cas_store.as_pin(),
1094
2
                                    &mut hasher.hasher(),
1095
2
                                )
1096
2
                                .await
1097
2
                                .err_tip(|| 
format!("While processing {entry}")0
)
?0
;
1098
2
                                Ok(DirectoryInfo {
1099
2
                                    path: entry,
1100
2
                                    tree_digest,
1101
2
                                })
1102
4
                            })
1103
2
                            .await
1104
2
                            .err_tip(|| 
format!("Uploading directory {full_path:?}")0
)
?0
,
1105
                    ))
1106
1
                } else if metadata.is_symlink() {
  Branch (1106:27): [Folded - Ignored]
  Branch (1106:27): [Folded - Ignored]
  Branch (1106:27): [True: 1, False: 0]
1107
1
                    let output_symlink = upload_symlink(&full_path, work_directory)
1108
1
                        .await
1109
1
                        .map(|mut symlink_info| {
1110
1
                            symlink_info.name_or_path = NameOrPath::Path(entry);
1111
1
                            symlink_info
1112
1
                        })
1113
1
                        .err_tip(|| 
format!("Uploading symlink {full_path:?}")0
)
?0
;
1114
1
                    match fs::metadata(&full_path).await {
1115
1
                        Ok(metadata) => {
1116
1
                            if metadata.is_dir() {
  Branch (1116:32): [Folded - Ignored]
  Branch (1116:32): [Folded - Ignored]
  Branch (1116:32): [True: 0, False: 1]
1117
0
                                return Ok(OutputType::DirectorySymlink(output_symlink));
1118
1
                            }
1119
1
                            // Note: If it's anything but directory we put it as a file symlink.
1120
1
                            return Ok(OutputType::FileSymlink(output_symlink));
1121
                        }
1122
0
                        Err(e) => {
1123
0
                            if e.code != Code::NotFound {
  Branch (1123:32): [Folded - Ignored]
  Branch (1123:32): [Folded - Ignored]
  Branch (1123:32): [True: 0, False: 0]
1124
0
                                return Err(e).err_tip(|| {
1125
0
                                    format!(
1126
0
                                        "While querying target symlink metadata for {full_path:?}"
1127
0
                                    )
1128
0
                                });
1129
0
                            }
1130
0
                            // If the file doesn't exist, we consider it a file. Even though the
1131
0
                            // file doesn't exist we still need to populate an entry.
1132
0
                            return Ok(OutputType::FileSymlink(output_symlink));
1133
                        }
1134
                    }
1135
                } else {
1136
0
                    Err(make_err!(
1137
0
                        Code::Internal,
1138
0
                        "{full_path:?} was not a file, folder or symlink. Must be one.",
1139
0
                    ))
1140
                }
1141
7
            });
1142
        }
1143
11
        let mut output_files = vec![];
1144
11
        let mut output_folders = vec![];
1145
11
        let mut output_directory_symlinks = vec![];
1146
11
        let mut output_file_symlinks = vec![];
1147
11
1148
11
        if execution_result.exit_code != 0 {
  Branch (1148:12): [Folded - Ignored]
  Branch (1148:12): [Folded - Ignored]
  Branch (1148:12): [True: 5, False: 6]
1149
            // Don't convert our stdout/stderr to strings unless we are need too.
1150
5
            if enabled!(Level::ERROR) {
1151
5
                let stdout = std::str::from_utf8(&execution_result.stdout).unwrap_or("<no-utf8>");
1152
5
                let stderr = std::str::from_utf8(&execution_result.stderr).unwrap_or("<no-utf8>");
1153
5
                event!(
1154
5
                    Level::ERROR,
1155
                    exit_code = ?execution_result.exit_code,
1156
5
                    stdout = ?stdout[..min(stdout.len(), 1000)],
1157
5
                    stderr = ?stderr[..min(stderr.len(), 1000)],
1158
5
                    "Command returned non-zero exit code",
1159
                );
1160
0
            }
1161
6
        }
1162
1163
11
        let stdout_digest_fut = self.metrics().upload_stdout.wrap(async {
1164
11
            let data = execution_result.stdout;
1165
11
            let digest = compute_buf_digest(&data, &mut hasher.hasher());
1166
11
            cas_store
1167
11
                .update_oneshot(digest, data)
1168
11
                .await
1169
11
                .err_tip(|| 
"Uploading stdout"0
)
?0
;
1170
11
            Result::<DigestInfo, Error>::Ok(digest)
1171
11
        });
1172
11
        let stderr_digest_fut = self.metrics().upload_stderr.wrap(async {
1173
11
            let data = execution_result.stderr;
1174
11
            let digest = compute_buf_digest(&data, &mut hasher.hasher());
1175
11
            cas_store
1176
11
                .update_oneshot(digest, data)
1177
11
                .await
1178
11
                .err_tip(|| 
"Uploading stdout"0
)
?0
;
1179
11
            Result::<DigestInfo, Error>::Ok(digest)
1180
11
        });
1181
1182
11
        let upload_result = futures::try_join!(stdout_digest_fut, stderr_digest_fut, async {
1183
18
            while let Some(
output_type7
) = output_path_futures.try_next().await
?0
{
  Branch (1183:23): [Folded - Ignored]
  Branch (1183:23): [Folded - Ignored]
  Branch (1183:23): [True: 7, False: 11]
1184
7
                match output_type {
1185
4
                    OutputType::File(output_file) => output_files.push(output_file),
1186
2
                    OutputType::Directory(output_folder) => output_folders.push(output_folder),
1187
1
                    OutputType::FileSymlink(output_symlink) => {
1188
1
                        output_file_symlinks.push(output_symlink);
1189
1
                    }
1190
0
                    OutputType::DirectorySymlink(output_symlink) => {
1191
0
                        output_directory_symlinks.push(output_symlink);
1192
0
                    }
1193
0
                    OutputType::None => { /* Safe to ignore */ }
1194
                }
1195
            }
1196
11
            Ok(())
1197
11
        });
1198
11
        drop(output_path_futures);
1199
11
        let (stdout_digest, stderr_digest) = match upload_result {
1200
11
            Ok((stdout_digest, stderr_digest, ())) => (stdout_digest, stderr_digest),
1201
0
            Err(e) => return Err(e).err_tip(|| "Error while uploading results"),
1202
        };
1203
1204
11
        execution_metadata.output_upload_completed_timestamp =
1205
11
            (self.running_actions_manager.callbacks.now_fn)();
1206
11
        output_files.sort_unstable_by(|a, b| 
a.name_or_path.cmp(&b.name_or_path)0
);
1207
11
        output_folders.sort_unstable_by(|a, b| 
a.path.cmp(&b.path)0
);
1208
11
        output_file_symlinks.sort_unstable_by(|a, b| 
a.name_or_path.cmp(&b.name_or_path)0
);
1209
11
        output_directory_symlinks.sort_unstable_by(|a, b| 
a.name_or_path.cmp(&b.name_or_path)0
);
1210
11
        {
1211
11
            let mut state = self.state.lock();
1212
11
            execution_metadata.worker_completed_timestamp =
1213
11
                (self.running_actions_manager.callbacks.now_fn)();
1214
11
            state.action_result = Some(ActionResult {
1215
11
                output_files,
1216
11
                output_folders,
1217
11
                output_directory_symlinks,
1218
11
                output_file_symlinks,
1219
11
                exit_code: execution_result.exit_code,
1220
11
                stdout_digest,
1221
11
                stderr_digest,
1222
11
                execution_metadata,
1223
11
                server_logs: HashMap::default(), // TODO(allada) Not implemented.
1224
11
                error: state.error.clone(),
1225
11
                message: String::new(), // Will be filled in on cache_action_result if needed.
1226
11
            });
1227
11
        }
1228
11
        Ok(self)
1229
11
    }
1230
1231
11
    async fn inner_get_finished_result(self: Arc<Self>) -> Result<ActionResult, Error> {
1232
11
        let mut state = self.state.lock();
1233
11
        state
1234
11
            .action_result
1235
11
            .take()
1236
11
            .err_tip(|| 
"Expected action_result to exist in get_finished_result"0
)
1237
11
    }
1238
}
1239
1240
impl Drop for RunningActionImpl {
1241
15
    fn drop(&mut self) {
1242
15
        if self.did_cleanup.load(Ordering::Acquire) {
  Branch (1242:12): [True: 15, False: 0]
  Branch (1242:12): [Folded - Ignored]
1243
15
            return;
1244
0
        }
1245
0
        let operation_id = self.operation_id.clone();
1246
0
        event!(
1247
0
            Level::ERROR,
1248
            ?operation_id,
1249
0
            "RunningActionImpl did not cleanup. This is a violation of the requirements, will attempt to do it in the background."
1250
        );
1251
0
        let running_actions_manager = self.running_actions_manager.clone();
1252
0
        let action_directory = self.action_directory.clone();
1253
0
        background_spawn!("running_action_impl_drop", async move {
1254
0
            let Err(err) =
  Branch (1254:17): [True: 0, False: 0]
  Branch (1254:17): [Folded - Ignored]
1255
0
                do_cleanup(&running_actions_manager, &operation_id, &action_directory).await
1256
            else {
1257
0
                return;
1258
            };
1259
0
            event!(
1260
0
                Level::ERROR,
1261
                ?operation_id,
1262
                ?action_directory,
1263
                ?err,
1264
0
                "Error cleaning up action"
1265
            );
1266
0
        });
1267
15
    }
1268
}
1269
1270
impl RunningAction for RunningActionImpl {
1271
0
    fn get_operation_id(&self) -> &OperationId {
1272
0
        &self.operation_id
1273
0
    }
1274
1275
15
    
async fn prepare_action(self: Arc<Self>) -> Result<Arc<Self>, Error> 0
{
1276
15
        self.metrics()
1277
15
            .clone()
1278
15
            .prepare_action
1279
15
            .wrap(Self::inner_prepare_action(self))
1280
15
            .await
1281
15
    }
1282
1283
13
    async fn execute(self: Arc<Self>) -> Result<Arc<Self>, Error> {
1284
13
        self.metrics()
1285
13
            .clone()
1286
13
            .execute
1287
13
            .wrap(Self::inner_execute(self))
1288
13
            .await
1289
13
    }
1290
1291
11
    async fn upload_results(self: Arc<Self>) -> Result<Arc<Self>, Error> {
1292
11
        self.metrics()
1293
11
            .clone()
1294
11
            .upload_results
1295
11
            .wrap(Self::inner_upload_results(self))
1296
11
            .await
1297
11
    }
1298
1299
15
    
async fn cleanup(self: Arc<Self>) -> Result<Arc<Self>, Error> 0
{
1300
15
        self.metrics()
1301
15
            .clone()
1302
15
            .cleanup
1303
15
            .wrap(async move {
1304
15
                let result = do_cleanup(
1305
15
                    &self.running_actions_manager,
1306
15
                    &self.operation_id,
1307
15
                    &self.action_directory,
1308
15
                )
1309
15
                .await;
1310
15
                self.did_cleanup.store(true, Ordering::Release);
1311
15
                result.map(move |()| self)
1312
15
            })
1313
15
            .await
1314
15
    }
1315
1316
11
    
async fn get_finished_result(self: Arc<Self>) -> Result<ActionResult, Error> 0
{
1317
11
        self.metrics()
1318
11
            .clone()
1319
11
            .get_finished_result
1320
11
            .wrap(Self::inner_get_finished_result(self))
1321
11
            .await
1322
11
    }
1323
1324
2
    fn get_work_directory(&self) -> &String {
1325
2
        &self.work_directory
1326
2
    }
1327
}
1328
1329
pub trait RunningActionsManager: Sync + Send + Sized + Unpin + 'static {
1330
    type RunningAction: RunningAction;
1331
1332
    fn create_and_add_action(
1333
        self: &Arc<Self>,
1334
        worker_id: String,
1335
        start_execute: StartExecute,
1336
    ) -> impl Future<Output = Result<Arc<Self::RunningAction>, Error>> + Send;
1337
1338
    fn cache_action_result(
1339
        &self,
1340
        action_digest: DigestInfo,
1341
        action_result: &mut ActionResult,
1342
        hasher: DigestHasherFunc,
1343
    ) -> impl Future<Output = Result<(), Error>> + Send;
1344
1345
    fn complete_actions(&self, complete_msg: ShutdownGuard) -> impl Future<Output = ()> + Send;
1346
1347
    fn kill_all(&self) -> impl Future<Output = ()> + Send;
1348
1349
    fn kill_operation(
1350
        &self,
1351
        operation_id: &OperationId,
1352
    ) -> impl Future<Output = Result<(), Error>> + Send;
1353
1354
    fn metrics(&self) -> &Arc<Metrics>;
1355
}
1356
1357
/// A function to get the current system time, used to allow mocking for tests
1358
type NowFn = fn() -> SystemTime;
1359
type SleepFn = fn(Duration) -> BoxFuture<'static, ()>;
1360
1361
/// Functions that may be injected for testing purposes, during standard control
1362
/// flows these are specified by the new function.
1363
#[derive(Clone, Copy)]
1364
pub struct Callbacks {
1365
    /// A function that gets the current time.
1366
    pub now_fn: NowFn,
1367
    /// A function that sleeps for a given Duration.
1368
    pub sleep_fn: SleepFn,
1369
}
1370
1371
impl Debug for Callbacks {
1372
0
    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
1373
0
        f.debug_struct("Callbacks").finish_non_exhaustive()
1374
0
    }
1375
}
1376
1377
/// The set of additional information for executing an action over and above
1378
/// those given in the `ActionInfo` passed to the worker.  This allows
1379
/// modification of the action for execution on this particular worker.  This
1380
/// may be used to run the action with a particular set of additional
1381
/// environment variables, or perhaps configure it to execute within a
1382
/// container.
1383
#[derive(Debug, Default)]
1384
pub struct ExecutionConfiguration {
1385
    /// If set, will be executed instead of the first argument passed in the
1386
    /// `ActionInfo` with all of the arguments in the `ActionInfo` passed as
1387
    /// arguments to this command.
1388
    pub entrypoint: Option<String>,
1389
    /// The only environment variables that will be specified when the command
1390
    /// executes other than those in the `ActionInfo`.  On Windows, `SystemRoot`
1391
    /// and PATH are also assigned (see `inner_execute`).
1392
    pub additional_environment: Option<HashMap<String, EnvironmentSource>>,
1393
}
1394
1395
#[derive(Debug)]
1396
struct UploadActionResults {
1397
    upload_ac_results_strategy: UploadCacheResultsStrategy,
1398
    upload_historical_results_strategy: UploadCacheResultsStrategy,
1399
    ac_store: Option<Store>,
1400
    historical_store: Store,
1401
    success_message_template: Template,
1402
    failure_message_template: Template,
1403
}
1404
1405
impl UploadActionResults {
1406
24
    fn new(
1407
24
        config: &UploadActionResultConfig,
1408
24
        ac_store: Option<Store>,
1409
24
        historical_store: Store,
1410
24
    ) -> Result<Self, Error> {
1411
24
        let upload_historical_results_strategy = config
1412
24
            .upload_historical_results_strategy
1413
24
            .unwrap_or(DEFAULT_HISTORICAL_RESULTS_STRATEGY);
1414
8
        if !matches!(
  Branch (1414:12): [True: 8, False: 16]
  Branch (1414:12): [Folded - Ignored]
1415
24
            config.upload_ac_results_strategy,
1416
            UploadCacheResultsStrategy::Never
1417
8
        ) && ac_store.is_none()
  Branch (1417:14): [True: 0, False: 8]
  Branch (1417:14): [Folded - Ignored]
1418
        {
1419
0
            return Err(make_input_err!(
1420
0
                "upload_ac_results_strategy is set, but no ac_store is configured"
1421
0
            ));
1422
24
        }
1423
24
        Ok(Self {
1424
24
            upload_ac_results_strategy: config.upload_ac_results_strategy,
1425
24
            upload_historical_results_strategy,
1426
24
            ac_store,
1427
24
            historical_store,
1428
24
            success_message_template: Template::new(&config.success_message_template).map_err(
1429
0
                |e| {
1430
0
                    make_input_err!(
1431
0
                        "Could not convert success_message_template to rust template: {} : {e:?}",
1432
0
                        config.success_message_template
1433
0
                    )
1434
0
                },
1435
0
            )?,
1436
24
            failure_message_template: Template::new(&config.failure_message_template).map_err(
1437
0
                |e| {
1438
0
                    make_input_err!(
1439
0
                        "Could not convert failure_message_template to rust template: {} : {e:?}",
1440
0
                        config.success_message_template
1441
0
                    )
1442
0
                },
1443
0
            )?,
1444
        })
1445
24
    }
1446
1447
0
    const fn should_cache_result(
1448
0
        strategy: UploadCacheResultsStrategy,
1449
0
        action_result: &ActionResult,
1450
0
        treat_infra_error_as_failure: bool,
1451
0
    ) -> bool {
1452
0
        let mut did_fail = action_result.exit_code != 0;
1453
0
        if treat_infra_error_as_failure && action_result.error.is_some() {
  Branch (1453:12): [Folded - Ignored]
  Branch (1453:44): [Folded - Ignored]
1454
0
            did_fail = true;
1455
0
        }
1456
0
        match strategy {
1457
0
            UploadCacheResultsStrategy::SuccessOnly => !did_fail,
1458
0
            UploadCacheResultsStrategy::Never => false,
1459
            // Never cache internal errors or timeouts.
1460
            UploadCacheResultsStrategy::Everything => {
1461
0
                treat_infra_error_as_failure || action_result.error.is_none()
  Branch (1461:17): [Folded - Ignored]
1462
            }
1463
0
            UploadCacheResultsStrategy::FailuresOnly => did_fail,
1464
        }
1465
0
    }
1466
1467
    /// Formats the message field in `ExecuteResponse` from the `success_message_template`
1468
    /// or `failure_message_template` config templates.
1469
5
    fn format_execute_response_message(
1470
5
        mut template_str: Template,
1471
5
        action_digest_info: DigestInfo,
1472
5
        maybe_historical_digest_info: Option<DigestInfo>,
1473
5
        hasher: DigestHasherFunc,
1474
5
    ) -> Result<String, Error> {
1475
5
        template_str.replace(
1476
5
            "digest_function",
1477
5
            hasher.proto_digest_func().as_str_name().to_lowercase(),
1478
5
        );
1479
5
        template_str.replace(
1480
5
            "action_digest_hash",
1481
5
            action_digest_info.packed_hash().to_string(),
1482
5
        );
1483
5
        template_str.replace("action_digest_size", action_digest_info.size_bytes());
1484
5
        if let Some(
historical_digest_info3
) = maybe_historical_digest_info {
  Branch (1484:16): [True: 3, False: 2]
  Branch (1484:16): [Folded - Ignored]
1485
3
            template_str.replace(
1486
3
                "historical_results_hash",
1487
3
                format!("{}", historical_digest_info.packed_hash()),
1488
3
            );
1489
3
            template_str.replace(
1490
3
                "historical_results_size",
1491
3
                historical_digest_info.size_bytes(),
1492
3
            );
1493
3
        } else {
1494
2
            template_str.replace("historical_results_hash", "");
1495
2
            template_str.replace("historical_results_size", "");
1496
2
        }
1497
5
        template_str
1498
5
            .text()
1499
5
            .map_err(|e| 
make_input_err!("Could not convert template to text: {e:?}")0
)
1500
5
    }
1501
1502
5
    async fn upload_ac_results(
1503
5
        &self,
1504
5
        action_digest: DigestInfo,
1505
5
        action_result: ProtoActionResult,
1506
5
        hasher: DigestHasherFunc,
1507
5
    ) -> Result<(), Error> {
1508
5
        let Some(ac_store) = self.ac_store.as_ref() else {
  Branch (1508:13): [Folded - Ignored]
  Branch (1508:13): [Folded - Ignored]
  Branch (1508:13): [True: 5, False: 0]
1509
0
            return Ok(());
1510
        };
1511
        // If we are a GrpcStore we shortcut here, as this is a special store.
1512
5
        if let Some(
grpc_store0
) = ac_store.downcast_ref::<GrpcStore>(Some(action_digest.into())) {
  Branch (1512:16): [Folded - Ignored]
  Branch (1512:16): [Folded - Ignored]
  Branch (1512:16): [True: 0, False: 5]
1513
0
            let update_action_request = UpdateActionResultRequest {
1514
0
                // This is populated by `update_action_result`.
1515
0
                instance_name: String::new(),
1516
0
                action_digest: Some(action_digest.into()),
1517
0
                action_result: Some(action_result),
1518
0
                results_cache_policy: None,
1519
0
                digest_function: hasher.proto_digest_func().into(),
1520
0
            };
1521
0
            return grpc_store
1522
0
                .update_action_result(Request::new(update_action_request))
1523
0
                .await
1524
0
                .map(|_| ())
1525
0
                .err_tip(|| "Caching ActionResult");
1526
5
        }
1527
5
1528
5
        let mut store_data = BytesMut::with_capacity(ESTIMATED_DIGEST_SIZE);
1529
5
        action_result
1530
5
            .encode(&mut store_data)
1531
5
            .err_tip(|| 
"Encoding ActionResult for caching"0
)
?0
;
1532
1533
5
        ac_store
1534
5
            .update_oneshot(action_digest, store_data.split().freeze())
1535
5
            .await
1536
5
            .err_tip(|| 
"Caching ActionResult"0
)
1537
5
    }
1538
1539
0
    async fn upload_historical_results_with_message(
1540
0
        &self,
1541
0
        action_digest: DigestInfo,
1542
0
        execute_response: ExecuteResponse,
1543
0
        message_template: Template,
1544
0
        hasher: DigestHasherFunc,
1545
3
    ) -> Result<String, Error> {
1546
3
        let historical_digest_info = serialize_and_upload_message(
1547
3
            &HistoricalExecuteResponse {
1548
3
                action_digest: Some(action_digest.into()),
1549
3
                execute_response: Some(execute_response.clone()),
1550
3
            },
1551
3
            self.historical_store.as_pin(),
1552
3
            &mut hasher.hasher(),
1553
3
        )
1554
3
        .await
1555
3
        .err_tip(|| 
format!("Caching HistoricalExecuteResponse for digest: {action_digest}")0
)
?0
;
1556
1557
3
        Self::format_execute_response_message(
1558
3
            message_template,
1559
3
            action_digest,
1560
3
            Some(historical_digest_info),
1561
3
            hasher,
1562
3
        )
1563
3
        .err_tip(|| 
"Could not format message in upload_historical_results_with_message"0
)
1564
3
    }
1565
1566
0
    async fn cache_action_result(
1567
0
        &self,
1568
0
        action_info: DigestInfo,
1569
0
        action_result: &mut ActionResult,
1570
0
        hasher: DigestHasherFunc,
1571
6
    ) -> Result<(), Error> {
1572
6
        let should_upload_historical_results =
1573
6
            Self::should_cache_result(self.upload_historical_results_strategy, action_result, true);
1574
6
        let should_upload_ac_results =
1575
6
            Self::should_cache_result(self.upload_ac_results_strategy, action_result, false);
1576
6
        // Shortcut so we don't need to convert to proto if not needed.
1577
6
        if !should_upload_ac_results && 
!should_upload_historical_results1
{
  Branch (1577:12): [Folded - Ignored]
  Branch (1577:41): [Folded - Ignored]
  Branch (1577:12): [Folded - Ignored]
  Branch (1577:41): [Folded - Ignored]
  Branch (1577:12): [True: 1, False: 5]
  Branch (1577:41): [True: 1, False: 0]
1578
1
            return Ok(());
1579
5
        }
1580
5
1581
5
        let mut execute_response = to_execute_response(action_result.clone());
1582
1583
        // In theory exit code should always be != 0 if there's an error, but for safety we
1584
        // catch both.
1585
5
        let message_template = if action_result.exit_code == 0 && 
action_result.error.is_none4
() {
  Branch (1585:35): [Folded - Ignored]
  Branch (1585:67): [Folded - Ignored]
  Branch (1585:35): [Folded - Ignored]
  Branch (1585:67): [Folded - Ignored]
  Branch (1585:35): [True: 4, False: 1]
  Branch (1585:67): [True: 3, False: 1]
1586
3
            self.success_message_template.clone()
1587
        } else {
1588
2
            self.failure_message_template.clone()
1589
        };
1590
1591
5
        let upload_historical_results_with_message_result = if should_upload_historical_results {
  Branch (1591:64): [Folded - Ignored]
  Branch (1591:64): [Folded - Ignored]
  Branch (1591:64): [True: 3, False: 2]
1592
3
            let maybe_message = self
1593
3
                .upload_historical_results_with_message(
1594
3
                    action_info,
1595
3
                    execute_response.clone(),
1596
3
                    message_template,
1597
3
                    hasher,
1598
3
                )
1599
3
                .await;
1600
3
            match maybe_message {
1601
3
                Ok(message) => {
1602
3
                    action_result.message.clone_from(&message);
1603
3
                    execute_response.message = message;
1604
3
                    Ok(())
1605
                }
1606
0
                Err(e) => Result::<(), Error>::Err(e),
1607
            }
1608
        } else {
1609
2
            match Self::format_execute_response_message(message_template, action_info, None, hasher)
1610
            {
1611
2
                Ok(message) => {
1612
2
                    action_result.message.clone_from(&message);
1613
2
                    execute_response.message = message;
1614
2
                    Ok(())
1615
                }
1616
0
                Err(e) => Err(e).err_tip(|| "Could not format message in cache_action_result"),
1617
            }
1618
        };
1619
1620
        // Note: Done in this order because we assume most results will succed and most configs will
1621
        // either always upload upload historical results or only upload on filure. In which case
1622
        // we can avoid an extra clone of the protos by doing this last with the above assumption.
1623
5
        let ac_upload_results = if should_upload_ac_results {
  Branch (1623:36): [Folded - Ignored]
  Branch (1623:36): [Folded - Ignored]
  Branch (1623:36): [True: 5, False: 0]
1624
5
            self.upload_ac_results(
1625
5
                action_info,
1626
5
                execute_response
1627
5
                    .result
1628
5
                    .err_tip(|| 
"No result set in cache_action_result"0
)
?0
,
1629
5
                hasher,
1630
5
            )
1631
5
            .await
1632
        } else {
1633
0
            Ok(())
1634
        };
1635
5
        upload_historical_results_with_message_result.merge(ac_upload_results)
1636
6
    }
1637
}
1638
1639
#[derive(Debug)]
1640
pub struct RunningActionsManagerArgs<'a> {
1641
    pub root_action_directory: String,
1642
    pub execution_configuration: ExecutionConfiguration,
1643
    pub cas_store: Arc<FastSlowStore>,
1644
    pub ac_store: Option<Store>,
1645
    pub historical_store: Store,
1646
    pub upload_action_result_config: &'a UploadActionResultConfig,
1647
    pub max_action_timeout: Duration,
1648
    pub timeout_handled_externally: bool,
1649
}
1650
1651
/// Holds state info about what is being executed and the interface for interacting
1652
/// with actions while they are running.
1653
#[derive(Debug)]
1654
pub struct RunningActionsManagerImpl {
1655
    root_action_directory: String,
1656
    execution_configuration: ExecutionConfiguration,
1657
    cas_store: Arc<FastSlowStore>,
1658
    filesystem_store: Arc<FilesystemStore>,
1659
    upload_action_results: UploadActionResults,
1660
    max_action_timeout: Duration,
1661
    timeout_handled_externally: bool,
1662
    running_actions: Mutex<HashMap<OperationId, Weak<RunningActionImpl>>>,
1663
    // Note: We don't use Notify because we need to support a .wait_for()-like function, which
1664
    // Notify does not support.
1665
    action_done_tx: watch::Sender<()>,
1666
    callbacks: Callbacks,
1667
    metrics: Arc<Metrics>,
1668
}
1669
1670
impl RunningActionsManagerImpl {
1671
24
    pub fn new_with_callbacks(
1672
24
        args: RunningActionsManagerArgs<'_>,
1673
24
        callbacks: Callbacks,
1674
24
    ) -> Result<Self, Error> {
1675
        // Sadly because of some limitations of how Any works we need to clone more times than optimal.
1676
24
        let filesystem_store = args
1677
24
            .cas_store
1678
24
            .fast_store()
1679
24
            .downcast_ref::<FilesystemStore>(None)
1680
24
            .err_tip(
1681
0
                || "Expected FilesystemStore store for .fast_store() in RunningActionsManagerImpl",
1682
0
            )?
1683
24
            .get_arc()
1684
24
            .err_tip(|| 
"FilesystemStore's internal Arc was lost"0
)
?0
;
1685
24
        let (action_done_tx, _) = watch::channel(());
1686
24
        Ok(Self {
1687
24
            root_action_directory: args.root_action_directory,
1688
24
            execution_configuration: args.execution_configuration,
1689
24
            cas_store: args.cas_store,
1690
24
            filesystem_store,
1691
24
            upload_action_results: UploadActionResults::new(
1692
24
                args.upload_action_result_config,
1693
24
                args.ac_store,
1694
24
                args.historical_store,
1695
24
            )
1696
24
            .err_tip(|| 
"During RunningActionsManagerImpl construction"0
)
?0
,
1697
24
            max_action_timeout: args.max_action_timeout,
1698
24
            timeout_handled_externally: args.timeout_handled_externally,
1699
24
            running_actions: Mutex::new(HashMap::new()),
1700
24
            action_done_tx,
1701
24
            callbacks,
1702
24
            metrics: Arc::new(Metrics::default()),
1703
        })
1704
24
    }
1705
1706
10
    pub fn new(args: RunningActionsManagerArgs<'_>) -> Result<Self, Error> {
1707
10
        Self::new_with_callbacks(
1708
10
            args,
1709
10
            Callbacks {
1710
10
                now_fn: SystemTime::now,
1711
2
                sleep_fn: |duration| Box::pin(tokio::time::sleep(duration)),
1712
            },
1713
        )
1714
10
    }
1715
1716
0
    fn make_action_directory<'a>(
1717
0
        &'a self,
1718
0
        operation_id: &'a OperationId,
1719
0
    ) -> impl Future<Output = Result<String, Error>> + 'a {
1720
16
        self.metrics.make_action_directory.wrap(async move {
1721
16
            let action_directory = format!("{}/{}", self.root_action_directory, operation_id);
1722
16
            fs::create_dir(&action_directory)
1723
16
                .await
1724
16
                .err_tip(|| 
format!("Error creating action directory {action_directory}")0
)
?0
;
1725
16
            Ok(action_directory)
1726
16
        })
1727
0
    }
1728
1729
16
    fn create_action_info(
1730
16
        &self,
1731
16
        start_execute: StartExecute,
1732
16
        queued_timestamp: SystemTime,
1733
16
    ) -> impl Future<Output = Result<ActionInfo, Error>> + '_ {
1734
16
        self.metrics.create_action_info.wrap(async move {
1735
16
            let execute_request = start_execute
1736
16
                .execute_request
1737
16
                .err_tip(|| 
"Expected execute_request to exist in StartExecute"0
)
?0
;
1738
16
            let action_digest: DigestInfo = execute_request
1739
16
                .action_digest
1740
16
                .clone()
1741
16
                .err_tip(|| 
"Expected action_digest to exist on StartExecute"0
)
?0
1742
16
                .try_into()
?0
;
1743
16
            let load_start_timestamp = (self.callbacks.now_fn)();
1744
16
            let action =
1745
16
                get_and_decode_digest::<Action>(self.cas_store.as_ref(), action_digest.into())
1746
16
                    .await
1747
16
                    .err_tip(|| 
"During start_action"0
)
?0
;
1748
16
            let action_info = ActionInfo::try_from_action_and_execute_request(
1749
16
                execute_request,
1750
16
                action,
1751
16
                load_start_timestamp,
1752
16
                queued_timestamp,
1753
16
            )
1754
16
            .err_tip(|| 
"Could not create ActionInfo in create_and_add_action()"0
)
?0
;
1755
16
            Ok(action_info)
1756
16
        })
1757
16
    }
1758
1759
15
    fn cleanup_action(&self, operation_id: &OperationId) -> Result<(), Error> {
1760
15
        let mut running_actions = self.running_actions.lock();
1761
15
        let result = running_actions.remove(operation_id).err_tip(|| {
1762
0
            format!("Expected action id '{operation_id:?}' to exist in RunningActionsManagerImpl")
1763
0
        });
1764
        // No need to copy anything, we just are telling the receivers an event happened.
1765
15
        self.action_done_tx.send_modify(|()| {});
1766
15
        result.map(|_| ())
1767
15
    }
1768
1769
    // Note: We do not capture metrics on this call, only `.kill_all()`.
1770
    // Important: When the future returns the process may still be running.
1771
2
    
async fn kill_operation(action: Arc<RunningActionImpl>) 0
{
1772
2
        event!(
1773
2
            Level::WARN,
1774
2
            operation_id = ?action.operation_id,
1775
2
            "Sending kill to running operation",
1776
        );
1777
2
        let kill_channel_tx = {
1778
2
            let mut action_state = action.state.lock();
1779
2
            action_state.kill_channel_tx.take()
1780
        };
1781
2
        if let Some(kill_channel_tx) = kill_channel_tx {
  Branch (1781:16): [Folded - Ignored]
  Branch (1781:16): [Folded - Ignored]
  Branch (1781:16): [True: 2, False: 0]
1782
2
            if kill_channel_tx.send(()).is_err() {
  Branch (1782:16): [Folded - Ignored]
  Branch (1782:16): [Folded - Ignored]
  Branch (1782:16): [True: 0, False: 2]
1783
0
                event!(
1784
0
                    Level::ERROR,
1785
0
                    operation_id = ?action.operation_id,
1786
0
                    "Error sending kill to running operation",
1787
                );
1788
2
            }
1789
0
        }
1790
2
    }
1791
}
1792
1793
impl RunningActionsManager for RunningActionsManagerImpl {
1794
    type RunningAction = RunningActionImpl;
1795
1796
0
    async fn create_and_add_action(
1797
0
        self: &Arc<Self>,
1798
0
        worker_id: String,
1799
0
        start_execute: StartExecute,
1800
16
    ) -> Result<Arc<RunningActionImpl>, Error> {
1801
16
        self.metrics
1802
16
            .create_and_add_action
1803
16
            .wrap(async move {
1804
16
                let queued_timestamp = start_execute
1805
16
                    .queued_timestamp
1806
16
                    .and_then(|time| 
time.try_into().ok()10
)
1807
16
                    .unwrap_or(SystemTime::UNIX_EPOCH);
1808
16
                let operation_id = start_execute
1809
16
                    .operation_id.as_str().into();
1810
16
                let action_info = self.create_action_info(start_execute, queued_timestamp).await
?0
;
1811
16
                event!(
1812
16
                    Level::INFO,
1813
                    ?action_info,
1814
0
                    "Worker received action",
1815
                );
1816
16
                let action_directory = self.make_action_directory(&operation_id).await
?0
;
1817
16
                let execution_metadata = ExecutionMetadata {
1818
16
                    worker: worker_id,
1819
16
                    queued_timestamp: action_info.insert_timestamp,
1820
16
                    worker_start_timestamp: action_info.load_timestamp,
1821
16
                    worker_completed_timestamp: SystemTime::UNIX_EPOCH,
1822
16
                    input_fetch_start_timestamp: SystemTime::UNIX_EPOCH,
1823
16
                    input_fetch_completed_timestamp: SystemTime::UNIX_EPOCH,
1824
16
                    execution_start_timestamp: SystemTime::UNIX_EPOCH,
1825
16
                    execution_completed_timestamp: SystemTime::UNIX_EPOCH,
1826
16
                    output_upload_start_timestamp: SystemTime::UNIX_EPOCH,
1827
16
                    output_upload_completed_timestamp: SystemTime::UNIX_EPOCH,
1828
16
                };
1829
16
                let timeout = if action_info.timeout.is_zero() || 
self.timeout_handled_externally3
{
  Branch (1829:34): [Folded - Ignored]
  Branch (1829:67): [Folded - Ignored]
  Branch (1829:34): [Folded - Ignored]
  Branch (1829:67): [Folded - Ignored]
  Branch (1829:34): [True: 13, False: 3]
  Branch (1829:67): [True: 0, False: 3]
1830
13
                    self.max_action_timeout
1831
                } else {
1832
3
                    action_info.timeout
1833
                };
1834
16
                if timeout > self.max_action_timeout {
  Branch (1834:20): [Folded - Ignored]
  Branch (1834:20): [Folded - Ignored]
  Branch (1834:20): [True: 1, False: 15]
1835
1
                    return Err(make_err!(
1836
1
                        Code::InvalidArgument,
1837
1
                        "Action timeout of {} seconds is greater than the maximum allowed timeout of {} seconds",
1838
1
                        timeout.as_secs_f32(),
1839
1
                        self.max_action_timeout.as_secs_f32()
1840
1
                    ));
1841
15
                }
1842
15
                let running_action = Arc::new(RunningActionImpl::new(
1843
15
                    execution_metadata,
1844
15
                    operation_id.clone(),
1845
15
                    action_directory,
1846
15
                    action_info,
1847
15
                    timeout,
1848
15
                    self.clone(),
1849
15
                ));
1850
15
                {
1851
15
                    let mut running_actions = self.running_actions.lock();
1852
15
                    running_actions.insert(operation_id, Arc::downgrade(&running_action));
1853
15
                }
1854
15
                Ok(running_action)
1855
16
            })
1856
16
            .await
1857
16
    }
1858
1859
0
    async fn cache_action_result(
1860
0
        &self,
1861
0
        action_info: DigestInfo,
1862
0
        action_result: &mut ActionResult,
1863
0
        hasher: DigestHasherFunc,
1864
6
    ) -> Result<(), Error> {
1865
6
        self.metrics
1866
6
            .cache_action_result
1867
6
            .wrap(self.upload_action_results.cache_action_result(
1868
6
                action_info,
1869
6
                action_result,
1870
6
                hasher,
1871
6
            ))
1872
6
            .await
1873
6
    }
1874
1875
0
    async fn kill_operation(&self, operation_id: &OperationId) -> Result<(), Error> {
1876
0
        let running_action = {
1877
0
            let running_actions = self.running_actions.lock();
1878
0
            running_actions
1879
0
                .get(operation_id)
1880
0
                .and_then(Weak::upgrade)
1881
0
                .ok_or_else(|| make_input_err!("Failed to get running action {operation_id}"))?
1882
        };
1883
0
        Self::kill_operation(running_action).await;
1884
0
        Ok(())
1885
0
    }
1886
1887
    // Waits for all running actions to complete and signals completion.
1888
    // Use the ShutdownGuard to signal the completion of the actions
1889
    // Dropping the sender automatically notifies the process to terminate.
1890
0
    async fn complete_actions(&self, _complete_msg: ShutdownGuard) {
1891
0
        drop(
1892
0
            self.action_done_tx
1893
0
                .subscribe()
1894
0
                .wait_for(|()| self.running_actions.lock().is_empty())
1895
0
                .await,
1896
        );
1897
0
    }
1898
1899
    // Note: When the future returns the process should be fully killed and cleaned up.
1900
2
    async fn kill_all(&self) {
1901
2
        self.metrics
1902
2
            .kill_all
1903
2
            .wrap_no_capture_result(async move {
1904
2
                let kill_operations: Vec<Arc<RunningActionImpl>> = {
1905
2
                    let running_actions = self.running_actions.lock();
1906
2
                    running_actions
1907
2
                        .iter()
1908
2
                        .filter_map(|(_operation_id, action)| action.upgrade())
1909
2
                        .collect()
1910
                };
1911
4
                for 
action2
in kill_operations {
1912
2
                    Self::kill_operation(action).await;
1913
                }
1914
2
            })
1915
2
            .await;
1916
        // Ignore error. If error happens it means there's no sender, which is not a problem.
1917
        // Note: Sanity check this API will always check current value then future values:
1918
        // https://play.rust-lang.org/?version=stable&edition=2021&gist=23103652cc1276a97e5f9938da87fdb2
1919
2
        drop(
1920
2
            self.action_done_tx
1921
2
                .subscribe()
1922
4
                .wait_for(|()| self.running_actions.lock().is_empty())
1923
2
                .await,
1924
        );
1925
2
    }
1926
1927
    #[inline]
1928
2
    fn metrics(&self) -> &Arc<Metrics> {
1929
2
        &self.metrics
1930
2
    }
1931
}
1932
1933
#[derive(Debug, Default, MetricsComponent)]
1934
pub struct Metrics {
1935
    #[metric(help = "Stats about the create_and_add_action command.")]
1936
    create_and_add_action: AsyncCounterWrapper,
1937
    #[metric(help = "Stats about the cache_action_result command.")]
1938
    cache_action_result: AsyncCounterWrapper,
1939
    #[metric(help = "Stats about the kill_all command.")]
1940
    kill_all: AsyncCounterWrapper,
1941
    #[metric(help = "Stats about the create_action_info command.")]
1942
    create_action_info: AsyncCounterWrapper,
1943
    #[metric(help = "Stats about the make_work_directory command.")]
1944
    make_action_directory: AsyncCounterWrapper,
1945
    #[metric(help = "Stats about the prepare_action command.")]
1946
    prepare_action: AsyncCounterWrapper,
1947
    #[metric(help = "Stats about the execute command.")]
1948
    execute: AsyncCounterWrapper,
1949
    #[metric(help = "Stats about the upload_results command.")]
1950
    upload_results: AsyncCounterWrapper,
1951
    #[metric(help = "Stats about the cleanup command.")]
1952
    cleanup: AsyncCounterWrapper,
1953
    #[metric(help = "Stats about the get_finished_result command.")]
1954
    get_finished_result: AsyncCounterWrapper,
1955
    #[metric(help = "Stats about the get_proto_command_from_store command.")]
1956
    get_proto_command_from_store: AsyncCounterWrapper,
1957
    #[metric(help = "Stats about the download_to_directory command.")]
1958
    download_to_directory: AsyncCounterWrapper,
1959
    #[metric(help = "Stats about the prepare_output_files command.")]
1960
    prepare_output_files: AsyncCounterWrapper,
1961
    #[metric(help = "Stats about the prepare_output_paths command.")]
1962
    prepare_output_paths: AsyncCounterWrapper,
1963
    #[metric(help = "Stats about the child_process command.")]
1964
    child_process: AsyncCounterWrapper,
1965
    #[metric(help = "Stats about the child_process_success_error_code command.")]
1966
    child_process_success_error_code: CounterWithTime,
1967
    #[metric(help = "Stats about the child_process_failure_error_code command.")]
1968
    child_process_failure_error_code: CounterWithTime,
1969
    #[metric(help = "Total time spent uploading stdout.")]
1970
    upload_stdout: AsyncCounterWrapper,
1971
    #[metric(help = "Total time spent uploading stderr.")]
1972
    upload_stderr: AsyncCounterWrapper,
1973
    #[metric(help = "Total number of task timeouts.")]
1974
    task_timeouts: CounterWithTime,
1975
}