Skip to content

Commit

Permalink
[reconfigurator-cli] Customize log outputs
Browse files Browse the repository at this point in the history
* Dump them to stdout instead of stderr
* Omit timestamps (which should fix the test failure on #7307, where our
  expectorate tests don't know how to redact slog timestamps)
  • Loading branch information
jgallagher committed Jan 8, 2025
1 parent f460a3c commit 953b99f
Show file tree
Hide file tree
Showing 4 changed files with 151 additions and 10 deletions.
3 changes: 2 additions & 1 deletion Cargo.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

3 changes: 2 additions & 1 deletion dev-tools/reconfigurator-cli/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,7 @@ assert_matches.workspace = true
camino.workspace = true
chrono.workspace = true
clap.workspace = true
dropshot.workspace = true
colored.workspace = true
humantime.workspace = true
indent_write.workspace = true
internal-dns-types.workspace = true
Expand All @@ -32,6 +32,7 @@ pq-sys = "*"
reedline.workspace = true
serde_json.workspace = true
slog-error-chain.workspace = true
slog-term.workspace = true
slog.workspace = true
swrite.workspace = true
tabled.workspace = true
Expand Down
131 changes: 131 additions & 0 deletions dev-tools/reconfigurator-cli/src/log_capture.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,131 @@
// This Source Code Form is subject to the terms of the Mozilla Public
// License, v. 2.0. If a copy of the MPL was not distributed with this
// file, You can obtain one at https://mozilla.org/MPL/2.0/.

//! in-memory slog drain
use colored::Color;
use colored::Colorize;
use slog::Drain;
use slog::Level;
use slog::LevelFilter;
use slog::Logger;
use slog::KV as _;
use slog_term::Decorator;
use slog_term::PlainSyncDecorator;
use slog_term::Serializer;
use std::io;
use std::mem;
use std::sync::Arc;
use std::sync::Mutex;

/// `LogCapture` creates a `slog::Logger` where log lines are buffered in memory
/// and can be fetched when desired via [`LogCapture::take_log_lines()`].
pub struct LogCapture {
lines: Arc<Mutex<Vec<String>>>,
}

impl LogCapture {
/// Create a new [`Logger`] that emits to the returned `LogCapture`.
pub fn new(colorize: bool) -> (Self, Logger) {
let lines = Arc::default();
let slf = LogCapture { lines };

let line_buf = LineBuf::default();
let drain = LogCaptureDrain {
colorize,
lines: Arc::clone(&slf.lines),
line_buf: line_buf.clone(),
decorator: PlainSyncDecorator::new(line_buf),
};

let drain = slog::Fuse(LevelFilter::new(drain, Level::Info));
let logger = Logger::root(drain, slog::o!());

(slf, logger)
}

/// Take all buffered log lines out of the `LogCapture`.
///
/// Additional logs emitted after this is called will continue to be
/// buffered and can be fetched by subsequent calls to `take_log_lines()`.
pub fn take_log_lines(&self) -> Vec<String> {
mem::take(&mut *self.lines.lock().unwrap())
}
}

struct LogCaptureDrain {
colorize: bool,
lines: Arc<Mutex<Vec<String>>>,
line_buf: LineBuf,
decorator: PlainSyncDecorator<LineBuf>,
}

impl Drain for LogCaptureDrain {
type Ok = ();
type Err = io::Error;

fn log(
&self,
record: &slog::Record,
values: &slog::OwnedKVList,
) -> Result<Self::Ok, Self::Err> {
self.decorator.with_record(record, values, |d| {
// This is heavily derived from `slog_term::print_msg_header()`, but
// we omit some options we don't care about and intentionally omit
// any kind of timestamp (so expectorate-based reconfigurator-cli
// tests don't have to deal with redacting log timestamps).
d.start_level()?;
let level = record.level();
if self.colorize {
let color = match level {
Level::Critical => Color::Magenta,
Level::Error => Color::Red,
Level::Warning => Color::Yellow,
Level::Info => Color::Green,
Level::Debug => Color::Cyan,
Level::Trace => Color::Blue,
};
write!(d, "{}", level.as_short_str().color(color))?;
} else {
write!(d, "{}", level.as_short_str())?;
}

d.start_whitespace()?;
write!(d, " ")?;

d.start_msg()?;
write!(d, "{}", record.msg())?;

let mut serializer = Serializer::new(d, true, true);
record.kv().serialize(record, &mut serializer)?;
values.serialize(record, &mut serializer)?;
serializer.finish()?;
d.flush()
})?;
let line = self.line_buf.take_as_string()?;
self.lines.lock().unwrap().push(line);
Ok(())
}
}

#[derive(Clone, Default)]
struct LineBuf(Arc<Mutex<Vec<u8>>>);

impl LineBuf {
fn take_as_string(&self) -> io::Result<String> {
let contents = mem::take(&mut *self.0.lock().unwrap());
String::from_utf8(contents)
.map_err(|err| io::Error::new(io::ErrorKind::Other, err))
}
}

impl io::Write for LineBuf {
fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
self.0.lock().unwrap().write(buf)
}

fn flush(&mut self) -> io::Result<()> {
self.0.lock().unwrap().flush()
}
}
24 changes: 16 additions & 8 deletions dev-tools/reconfigurator-cli/src/main.rs
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@ use clap::ValueEnum;
use clap::{Args, Parser, Subcommand};
use indent_write::fmt::IndentWriter;
use internal_dns_types::diff::DnsDiff;
use log_capture::LogCapture;
use nexus_inventory::CollectionBuilder;
use nexus_reconfigurator_planning::blueprint_builder::BlueprintBuilder;
use nexus_reconfigurator_planning::example::ExampleSystemBuilder;
Expand Down Expand Up @@ -42,10 +43,13 @@ use std::borrow::Cow;
use std::collections::BTreeMap;
use std::fmt::Write;
use std::io::BufRead;
use std::io::IsTerminal;
use swrite::{swriteln, SWrite};
use tabled::Tabled;
use uuid::Uuid;

mod log_capture;

/// REPL state
#[derive(Debug)]
struct ReconfiguratorSim {
Expand Down Expand Up @@ -157,11 +161,7 @@ struct CmdReconfiguratorSim {
fn main() -> anyhow::Result<()> {
let cmd = CmdReconfiguratorSim::parse();

let log = dropshot::ConfigLogging::StderrTerminal {
level: dropshot::ConfigLoggingLevel::Info,
}
.to_logger("reconfigurator-sim")
.context("creating logger")?;
let (log_capture, log) = LogCapture::new(std::io::stdout().is_terminal());

let seed_provided = cmd.seed.is_some();
let mut sim = ReconfiguratorSim::new(log, cmd.seed);
Expand All @@ -179,7 +179,7 @@ fn main() -> anyhow::Result<()> {
let buffer = maybe_buffer
.with_context(|| format!("read {:?}", &input_file))?;
println!("> {}", buffer);
match process_entry(&mut sim, buffer) {
match process_entry(&mut sim, buffer, &log_capture) {
LoopResult::Continue => (),
LoopResult::Bail(error) => return Err(error),
}
Expand All @@ -194,7 +194,7 @@ fn main() -> anyhow::Result<()> {
loop {
match ed.read_line(&prompt) {
Ok(Signal::Success(buffer)) => {
match process_entry(&mut sim, buffer) {
match process_entry(&mut sim, buffer, &log_capture) {
LoopResult::Continue => (),
LoopResult::Bail(error) => return Err(error),
}
Expand Down Expand Up @@ -225,7 +225,11 @@ enum LoopResult {
}

/// Processes one "line" of user input.
fn process_entry(sim: &mut ReconfiguratorSim, entry: String) -> LoopResult {
fn process_entry(
sim: &mut ReconfiguratorSim,
entry: String,
logs: &LogCapture,
) -> LoopResult {
// If no input was provided, take another lap (print the prompt and accept
// another line). This gets handled specially because otherwise clap would
// treat this as a usage error and print a help message, which isn't what we
Expand Down Expand Up @@ -289,6 +293,10 @@ fn process_entry(sim: &mut ReconfiguratorSim, entry: String) -> LoopResult {
Commands::Wipe(args) => cmd_wipe(sim, args),
};

for line in logs.take_log_lines() {
println!("{line}");
}

match cmd_result {
Err(error) => println!("error: {:#}", error),
Ok(Some(s)) => println!("{}", s),
Expand Down

0 comments on commit 953b99f

Please sign in to comment.