diff --git a/CHANGELOG.md b/CHANGELOG.md index a3c2713..d72bcfc 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] - yyyy-mm-dd +### Added + +- The last associated nix log is now shown next to the node name, including a + possible build name when `--print-build-logs` is passed. - Fix outputting coloured text, disrespecting NO_COLOR, in some case. ### Changed diff --git a/crates/cli/src/tracing_setup.rs b/crates/cli/src/tracing_setup.rs index 4cb02f6..e5d5e2c 100644 --- a/crates/cli/src/tracing_setup.rs +++ b/crates/cli/src/tracing_setup.rs @@ -19,7 +19,7 @@ use tracing_subscriber::{ registry::LookupSpan, util::SubscriberInitExt, }; -use wire_core::status::{UI_SENDER, UiMessage}; +use wire_core::status::{BUILD_NAME_CARET, BUILD_NAME_STYLE, UI_SENDER, UiMessage}; /// Forwards log lines to the UI worker over `UI_SENDER`. struct NonClobberingWriter; @@ -211,19 +211,21 @@ where if !visitor.build.is_empty() { write!( writer, - " {}", + " {}{}", visitor .build - .if_supports_color(Stream::Stderr, |text| text.dimmed()) + .if_supports_color(Stream::Stderr, |text| text.style(BUILD_NAME_STYLE)), + BUILD_NAME_CARET + .if_supports_color(Stream::Stderr, |text| text.style(BUILD_NAME_STYLE)) )?; } if !visitor.msg.is_empty() { - write!(writer, " | {}", visitor.msg)?; + write!(writer, " {}", visitor.msg)?; } if !visitor.other.is_empty() { - write!(writer, " | {}", visitor.other)?; + write!(writer, " {}", visitor.other)?; } writeln!(writer)?; diff --git a/crates/core/src/cache/mod.rs b/crates/core/src/cache/mod.rs index 89934ea..b92da01 100644 --- a/crates/core/src/cache/mod.rs +++ b/crates/core/src/cache/mod.rs @@ -277,7 +277,7 @@ impl InspectionCache { node_name: String, } - let mut client = NixClient::open_local(trace_nix_log_message, should_quit, false).await.inspect_err(|err| error!(err = ?err, "failed to open local nix client to verify cached evaluations")).ok()?; + let mut client = NixClient::open_local(|log, map, print| trace_nix_log_message(log, map, print, None), should_quit, false).await.inspect_err(|err| error!(err = ?err, "failed to open local nix client to verify cached evaluations")).ok()?; let store_path_digest = &prefetch.store_path.digest()[..]; let store_path_name = prefetch.store_path.name(); @@ -480,14 +480,19 @@ where let mut previous_rowid = 0; - let mut client = - match NixClient::open_local(trace_nix_log_message, should_quit, false).await { - Ok(c) => c, - Err(err) => { - error!(err = ?err, "failed to open local nix client for gc"); - return Ok(()); - } - }; + let mut client = match NixClient::open_local( + |log, map, print| trace_nix_log_message(log, map, print, None), + should_quit, + false, + ) + .await + { + Ok(c) => c, + Err(err) => { + error!(err = ?err, "failed to open local nix client for gc"); + return Ok(()); + } + }; // delete caches whose flake/output paths no longer exist in the nix store loop { diff --git a/crates/core/src/commands/common.rs b/crates/core/src/commands/common.rs index 06ff0ea..b155876 100644 --- a/crates/core/src/commands/common.rs +++ b/crates/core/src/commands/common.rs @@ -45,8 +45,9 @@ pub async fn push( ]); let child = run_command_with_env( - &CommandArguments::new(command_string, context.modifiers) - .mode(crate::commands::ChildOutputMode::Nix), + &CommandArguments::new(command_string, context.modifiers).mode( + crate::commands::ChildOutputMode::Nix(Some(context.name.clone())), + ), HashMap::from([( "NIX_SSHOPTS".into(), target.create_ssh_opts(context.modifiers)?, @@ -153,7 +154,7 @@ pub async fn evaluate_hive_attribute( let child = run_command( &CommandArguments::new(command_string, modifiers) - .mode(crate::commands::ChildOutputMode::Nix), + .mode(crate::commands::ChildOutputMode::Nix(None)), ) .await?; diff --git a/crates/core/src/commands/mod.rs b/crates/core/src/commands/mod.rs index 5ec6989..17d58e8 100644 --- a/crates/core/src/commands/mod.rs +++ b/crates/core/src/commands/mod.rs @@ -4,7 +4,8 @@ use crate::{ SafeStorePath, commands::pty::{InteractiveChildChip, interactive_command_with_env}, - hive::node::{BuildNameMap, SharedTarget}, + hive::node::{BuildNameMap, Name, SharedTarget}, + status::{UI_SENDER, UiMessage}, }; use core::str; use std::{ @@ -32,9 +33,9 @@ pub(crate) mod pty; static AT_NIX_FINDER: LazyLock = LazyLock::new(|| memmem::Finder::new(AT_NIX_PREFIX)); -#[derive(Copy, Clone, Debug)] +#[derive(Clone, Debug)] pub(crate) enum ChildOutputMode { - Nix, + Nix(Option), Generic, } @@ -75,7 +76,7 @@ impl> CommandArguments { self } - pub(crate) const fn mode(mut self, mode: ChildOutputMode) -> Self { + pub(crate) fn mode(mut self, mode: ChildOutputMode) -> Self { self.output_mode = mode; self } @@ -156,6 +157,7 @@ pub(crate) fn trace_nix_log_message( log_message: LogMessage, build_name_map: &BuildNameMap, print_build_logs: bool, + name: Option, ) -> Option { let (msg, level, build_name) = match log_message { LogMessage::Start { @@ -224,6 +226,16 @@ pub(crate) fn trace_nix_log_message( let msg = strip_ansi_escapes::strip_str(msg); + if let Some(name) = name + && let Some(sender) = UI_SENDER.get() + { + let _ = sender.send(UiMessage::ContextLogLine { + name, + log: msg.clone(), + build_name: build_name.clone(), + }); + } + let level = log_print(&level, build_name.as_ref(), &msg); if matches!(level, tracing::Level::ERROR | tracing::Level::WARN) { @@ -242,20 +254,20 @@ impl ChildOutputMode { build_name_map: &BuildNameMap, print_build_logs: bool, ) -> Option { - let slice = match self { + let (slice, name) = match self { Self::Generic => { let string = String::from_utf8_lossy(line); let stripped = strip_ansi_escapes::strip_str(&string); warn!("{stripped}"); return Some(string.to_string()); } - Self::Nix => { + Self::Nix(name) => { let position = AT_NIX_FINDER.find(line).map(|starting_position| { &mut line[(starting_position + AT_NIX_PREFIX.len())..] }); if let Some(json_buf) = position { - json_buf + (json_buf, name) } else { // usually happens when ssh is outputting something warn!("{}", String::from_utf8_lossy(line)); @@ -270,7 +282,7 @@ impl ChildOutputMode { return None; }; - trace_nix_log_message(log_message, build_name_map, print_build_logs) + trace_nix_log_message(log_message, build_name_map, print_build_logs, name) } } diff --git a/crates/core/src/commands/noninteractive.rs b/crates/core/src/commands/noninteractive.rs index 0fa7b93..377d684 100644 --- a/crates/core/src/commands/noninteractive.rs +++ b/crates/core/src/commands/noninteractive.rs @@ -51,7 +51,7 @@ pub async fn non_interactive_command_with_env + Sync>( command_string = arguments.command_string.as_ref(), extra = match arguments.output_mode { ChildOutputMode::Generic => "", - ChildOutputMode::Nix => " --log-format internal-json", + ChildOutputMode::Nix(..) => " --log-format internal-json", } ); @@ -87,7 +87,7 @@ pub async fn non_interactive_command_with_env + Sync>( .ok_or(HiveLibError::CommandError(CommandError::NoHandle))?; let mut joinset = JoinSet::new(); - let output_mode = Arc::new(arguments.output_mode); + let output_mode = Arc::new(arguments.output_mode.clone()); joinset.spawn( handle_io( @@ -174,7 +174,11 @@ pub async fn handle_io( let mut line = line.into_bytes(); let log = if should_log { - Some(output_mode.trace_slice(&mut line, &build_name_map, print_build_logs)) + Some(output_mode.as_ref().clone().trace_slice( + &mut line, + &build_name_map, + print_build_logs, + )) } else { None }; diff --git a/crates/core/src/commands/pty/mod.rs b/crates/core/src/commands/pty/mod.rs index b7aebb3..5bdb476 100644 --- a/crates/core/src/commands/pty/mod.rs +++ b/crates/core/src/commands/pty/mod.rs @@ -116,7 +116,7 @@ pub async fn interactive_command_with_env + Sync>( "{starting}{command} {flags} {IO_SUBS} && {ending}", command = arguments.command_string.as_ref(), flags = match arguments.output_mode { - ChildOutputMode::Nix => "--log-format internal-json", + ChildOutputMode::Nix(..) => "--log-format internal-json", ChildOutputMode::Generic => "", }, starting = create_starting_segment(&needles.start), @@ -162,7 +162,7 @@ pub async fn interactive_command_with_env + Sync>( began_tx, reader, needles, - output_mode: arguments.output_mode, + output_mode: arguments.output_mode.clone(), stderr_collection: stderr_collection.clone(), stdout_collection: stdout_collection.clone(), span: Span::current(), diff --git a/crates/core/src/commands/pty/output.rs b/crates/core/src/commands/pty/output.rs index 32122da..1d9c8ee 100644 --- a/crates/core/src/commands/pty/output.rs +++ b/crates/core/src/commands/pty/output.rs @@ -135,7 +135,7 @@ pub(super) fn handle_pty_stdout(arguments: WatchStdoutArguments) -> Result<(), C &stdout_collection, &mut line, log_stdout, - output_mode, + output_mode.clone(), &build_name_map, print_build_logs, ); diff --git a/crates/core/src/hive/executor.rs b/crates/core/src/hive/executor.rs index 192d842..2a69cf2 100644 --- a/crates/core/src/hive/executor.rs +++ b/crates/core/src/hive/executor.rs @@ -183,7 +183,10 @@ pub async fn execute( if let Some(tx) = UI_SENDER.get() { let _ = tx.send(UiMessage::SetStatus( plan.context.name.clone(), - NodeStatus::Running(step.to_string()), + NodeStatus::Running { + status: step.to_string(), + last_log: None, + }, )); } diff --git a/crates/core/src/hive/node.rs b/crates/core/src/hive/node.rs index d73b921..f0a7011 100644 --- a/crates/core/src/hive/node.rs +++ b/crates/core/src/hive/node.rs @@ -108,9 +108,16 @@ impl Target { &self, modifiers: SubCommandModifiers, should_quit: Arc, + name: &Name, ) -> Result<(), HiveLibError> { if modifiers.experimental_nix_client { - open_remote_client(&self, modifiers, trace_nix_log_message, should_quit).await?; + open_remote_client( + &self, + modifiers, + |log, map, print| trace_nix_log_message(log, map, print, Some(name.clone())), + should_quit, + ) + .await?; return Ok(()); } diff --git a/crates/core/src/hive/steps/activate.rs b/crates/core/src/hive/steps/activate.rs index e456d02..fcd4c4d 100644 --- a/crates/core/src/hive/steps/activate.rs +++ b/crates/core/src/hive/steps/activate.rs @@ -45,7 +45,9 @@ async fn wait_for_ping(target: &SharedTarget, ctx: &Context) -> Result<(), HiveL for num in 0..MAX_ATTEMPTS { warn!("Trying to ping {host} (attempt {}/{MAX_ATTEMPTS})", num + 1); - let result = target.ping(ctx.modifiers, ctx.should_quit.clone()).await; + let result = target + .ping(ctx.modifiers, ctx.should_quit.clone(), &ctx.name) + .await; if result.is_ok() { info!("Regained connection to {} via {host}", ctx.name); @@ -78,7 +80,9 @@ impl SwitchToConfiguration { let child = run_command( &CommandArguments::new(command_string, ctx.modifiers) - .mode(crate::commands::ChildOutputMode::Nix) + .mode(crate::commands::ChildOutputMode::Nix(Some( + ctx.name.clone(), + ))) .execute_on_remote(self.target.clone()) .privileged(&self.privilege_escalation_command), ) diff --git a/crates/core/src/hive/steps/build.rs b/crates/core/src/hive/steps/build.rs index 0745d06..af4daa0 100644 --- a/crates/core/src/hive/steps/build.rs +++ b/crates/core/src/hive/steps/build.rs @@ -74,7 +74,9 @@ impl ExecuteStep for Build { open_remote_client( &target, ctx.modifiers, - trace_nix_log_message, + |log, map, print| { + trace_nix_log_message(log, map, print, Some(ctx.name.clone())) + }, ctx.should_quit.clone(), ) .await? @@ -83,7 +85,9 @@ impl ExecuteStep for Build { } else { Either::Right( NixClient::open_local( - trace_nix_log_message, + |log, map, print| { + trace_nix_log_message(log, map, print, Some(ctx.name.clone())) + }, ctx.should_quit.clone(), ctx.modifiers.print_build_logs, ) @@ -195,7 +199,9 @@ impl ExecuteStep for Build { } NixCommandBuildMetadata::Locally { .. } => None, }) - .mode(crate::commands::ChildOutputMode::Nix) + .mode(crate::commands::ChildOutputMode::Nix(Some( + ctx.name.clone(), + ))) .log_stdout(), std::collections::HashMap::new(), ) diff --git a/crates/core/src/hive/steps/ping.rs b/crates/core/src/hive/steps/ping.rs index dcccb63..5333e0a 100644 --- a/crates/core/src/hive/steps/ping.rs +++ b/crates/core/src/hive/steps/ping.rs @@ -35,7 +35,7 @@ impl ExecuteStep for Ping { ); if target - .ping(ctx.modifiers, ctx.should_quit.clone()) + .ping(ctx.modifiers, ctx.should_quit.clone(), &ctx.name) .await .is_ok() { diff --git a/crates/core/src/lib.rs b/crates/core/src/lib.rs index 1b23338..2ac1f1c 100644 --- a/crates/core/src/lib.rs +++ b/crates/core/src/lib.rs @@ -167,7 +167,7 @@ pub async fn push_with_daemon( substitute_on_destination: bool, ) -> Result<(), HiveLibError> { let mut local_daemon = NixClient::open_local( - trace_nix_log_message, + |log, map, print| trace_nix_log_message(log, map, print, Some(context.name.clone())), context.should_quit.clone(), context.modifiers.print_build_logs, ) @@ -179,7 +179,7 @@ pub async fn push_with_daemon( let (mut remote_daemon, host) = open_remote_client( &target, context.modifiers, - trace_nix_log_message, + |log, map, print| trace_nix_log_message(log, map, print, Some(context.name.clone())), context.should_quit.clone(), ) .await?; diff --git a/crates/core/src/status.rs b/crates/core/src/status.rs index 575b5e6..59f0baf 100644 --- a/crates/core/src/status.rs +++ b/crates/core/src/status.rs @@ -1,11 +1,11 @@ // SPDX-License-Identifier: AGPL-3.0-or-later // Copyright 2024-2025 wire Contributors -use owo_colors::OwoColorize; +use owo_colors::{OwoColorize, Stream, Style}; use std::{ collections::VecDeque, fmt::Write, - sync::OnceLock, + sync::{Arc, OnceLock}, time::{Duration, Instant}, }; use termion::{clear, cursor, terminal_size}; @@ -18,12 +18,19 @@ use crate::hive::node::Name; use std::collections::HashMap; +pub const BUILD_NAME_STYLE: Style = Style::new().dimmed(); +pub const BUILD_NAME_CARET: &'static str = ">"; + // Statuses are ordered deliberately such that failed nodes are at the top of // the list and Succeeded nodes are at the bottom / never shown. #[derive(Default, PartialEq, PartialOrd, Ord, Eq)] pub enum NodeStatus { Failed, - Running(String), + Running { + status: String, + /// optional previous log with associated build name + last_log: Option<(String, Option>)>, + }, #[default] Pending, Succeeded, @@ -43,8 +50,15 @@ pub enum UiMessage { Release, /// Clear the status line, mostly for when the program is about to end Clear, - /// Writes above the status line + /// Writes above the status line, optionally ties it to a specific node LogLine(Vec), + /// A log line with associated context, including name and possible build + /// name + ContextLogLine { + name: Name, + build_name: Option>, + log: String, + }, } pub struct Status { @@ -82,7 +96,7 @@ impl Status { (0, 0, 0), |(mut finished, mut running, mut failed), status| { let did_fail = matches!(status, NodeStatus::Failed); - let is_running = matches!(status, NodeStatus::Running(..)); + let is_running = matches!(status, NodeStatus::Running { .. }); let did_succeeded = matches!(status, NodeStatus::Succeeded | NodeStatus::Failed); if did_fail { @@ -190,6 +204,34 @@ impl Status { ) .to_string() } + NodeStatus::Running { + status, + last_log: Some((last_log, None)), + } => { + format!( + "{} {}", + status.if_supports_color(Stream::Stderr, |x| x + .style(Style::new().blue().on_default_color())), + last_log + ) + .to_string() + } + NodeStatus::Running { + status, + last_log: Some((last_log, Some(build_name))), + } => { + format!( + "{} {}{} {}", + status.if_supports_color(Stream::Stderr, |x| x + .style(Style::new().blue().on_default_color())), + build_name + .if_supports_color(Stream::Stderr, |x| x.style(BUILD_NAME_STYLE)), + BUILD_NAME_CARET + .if_supports_color(Stream::Stderr, |x| x.style(BUILD_NAME_STYLE)), + last_log + ) + .to_string() + } NodeStatus::Succeeded => unreachable!("filtered above"), NodeStatus::Failed => "Failed" .if_supports_color(Stream::Stderr, |x| x.red()) @@ -291,6 +333,13 @@ pub async fn status_tick_worker(mut rx: UnboundedReceiver, show_progr UiMessage::Clear => { status.clear(&mut stderr); }, + UiMessage::ContextLogLine { name, log, build_name } => { + if let Some(node_status) = status.statuses.get_mut(&name) && let NodeStatus::Running { last_log, .. } = node_status { + // ensure only a single line is kept or the status + // bar might accidentally spread into multiple lines + *last_log = log.lines().next().map(|log| (log.to_string(), build_name)); + } + }, UiMessage::LogLine(line) => { if taken_over { log_queue.push_back(line);