/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 | | } |