From c3daa29a91865e7abd3523d0863e067f540c7056 Mon Sep 17 00:00:00 2001 From: Tom Parker-Shemilt Date: Wed, 20 May 2026 16:06:12 +0100 Subject: [PATCH] Add improved logging around command failures --- .../src/running_actions_manager.rs | 5 +- .../tests/running_actions_manager_test.rs | 105 ++++++++++++++++++ .../src/content/docs/docs/contribute/nix.mdx | 2 +- 3 files changed, 110 insertions(+), 2 deletions(-) diff --git a/nativelink-worker/src/running_actions_manager.rs b/nativelink-worker/src/running_actions_manager.rs index 431cc0d29..ffdb13959 100644 --- a/nativelink-worker/src/running_actions_manager.rs +++ b/nativelink-worker/src/running_actions_manager.rs @@ -987,7 +987,9 @@ impl RunningActionImpl { // level more effectively and adjust this. info!(?args, "Executing command"); - let program = self.canonicalise_path(args[0], &command_proto.working_directory)?; + let program = self + .canonicalise_path(args[0], &command_proto.working_directory) + .err_tip(|| format!("Canonicalisation failure. Command={args:#?}"))?; let mut command_builder = process::Command::new(program); #[cfg(target_family = "unix")] @@ -1534,6 +1536,7 @@ impl RunningActionImpl { exit_code = ?execution_result.exit_code, stdout = ?stdout[..min(stdout.len(), 1000)], stderr = ?stderr[..min(stderr.len(), 1000)], + command = ?command_proto.arguments, "Command returned non-zero exit code", ); } diff --git a/nativelink-worker/tests/running_actions_manager_test.rs b/nativelink-worker/tests/running_actions_manager_test.rs index 50db30b8e..240dd9ea0 100644 --- a/nativelink-worker/tests/running_actions_manager_test.rs +++ b/nativelink-worker/tests/running_actions_manager_test.rs @@ -2489,6 +2489,9 @@ exit 1 result.error.err_tip(|| "Error should exist")?.code, Code::DeadlineExceeded ); + assert!(logs_contain( + "Command returned non-zero exit code exit_code=1 stdout=\"\" stderr=\"\" command=[\"true\"]" + )); Ok(()) } @@ -4603,4 +4606,106 @@ exit 1 Ok(()) } + + #[nativelink_test] + async fn canonicalisation_failure() -> Result<(), Box> { + const WORKER_ID: &str = "foo_worker_id"; + + fn test_monotonic_clock() -> SystemTime { + static CLOCK: AtomicU64 = AtomicU64::new(0); + monotonic_clock(&CLOCK) + } + + let root_action_directory = make_temp_path("root_action_directory"); + fs::create_dir_all(&root_action_directory).await?; + + let (_, _, cas_store, ac_store) = setup_stores().await?; + + let arguments = vec![ + "garbage/to-canonicalise".to_string(), + "arguments".to_string(), + "to test".to_string(), + ]; + let command = Command { + arguments, + ..Default::default() + }; + let command_digest = serialize_and_upload_message( + &command, + cas_store.as_pin(), + &mut DigestHasherFunc::Sha256.hasher(), + ) + .await?; + let input_root_digest = serialize_and_upload_message( + &Directory::default(), + cas_store.as_pin(), + &mut DigestHasherFunc::Sha256.hasher(), + ) + .await?; + + let action = Action { + command_digest: Some(command_digest.into()), + input_root_digest: Some(input_root_digest.into()), + ..Default::default() + }; + let action_digest = serialize_and_upload_message( + &action, + cas_store.as_pin(), + &mut DigestHasherFunc::Sha256.hasher(), + ) + .await?; + + let running_actions_manager = Arc::new(RunningActionsManagerImpl::new_with_callbacks( + RunningActionsManagerArgs { + root_action_directory: root_action_directory.clone(), + execution_configuration: ExecutionConfiguration::default(), + cas_store: cas_store.clone(), + ac_store: Some(Store::new(ac_store.clone())), + historical_store: Store::new(cas_store.clone()), + upload_action_result_config: &UploadActionResultConfig { + upload_ac_results_strategy: UploadCacheResultsStrategy::Never, + ..Default::default() + }, + max_action_timeout: Duration::MAX, + max_upload_timeout: Duration::MAX, + timeout_handled_externally: false, + directory_cache: None, + #[cfg(target_os = "linux")] + use_namespaces: use_namespaces(), + }, + Callbacks { + now_fn: test_monotonic_clock, + sleep_fn: |_duration| Box::pin(future::pending()), + }, + )?); + + let execute_request = ExecuteRequest { + action_digest: Some(action_digest.into()), + ..Default::default() + }; + let operation_id = OperationId::default().to_string(); + + let res = running_actions_manager + .create_and_add_action( + WORKER_ID.to_string(), + StartExecute { + execute_request: Some(execute_request), + operation_id, + queued_timestamp: Some(make_system_time(1000).into()), + platform: action.platform.clone(), + worker_id: WORKER_ID.to_string(), + }, + ) + .and_then(|action| action.prepare_action().and_then(RunningAction::execute)) + .await; + assert!(res.is_err(), "{res:#?}"); + assert_eq!(res.unwrap_err(), Error::new_with_messages(Code::NotFound, vec![ + if cfg!(target_family = "windows") { "The system cannot find the path specified. (os error 3)" } else { "No such file or directory (os error 2)" }, + "Could not canonicalize path for command root garbage/to-canonicalise.", + "Canonicalisation failure. Command=[\n \"garbage/to-canonicalise\",\n \"arguments\",\n \"to test\",\n]" + ].into_iter().map(String::from).collect() + + )); + Ok(()) + } } diff --git a/web/platform/src/content/docs/docs/contribute/nix.mdx b/web/platform/src/content/docs/docs/contribute/nix.mdx index 119d90f80..e254b3a57 100644 --- a/web/platform/src/content/docs/docs/contribute/nix.mdx +++ b/web/platform/src/content/docs/docs/contribute/nix.mdx @@ -41,7 +41,7 @@ and get tagged with nix derivation hashes. To build an image locally and make it available to your container runtime: ```sh -nix run create-local-image +create-local-image ``` which will be called `local-nativelink:latest`