From 3f928e71fa121bf97c9f3a1db3cc9f01e5d9e2af Mon Sep 17 00:00:00 2001 From: Schneems Date: Wed, 24 Jan 2024 15:40:27 -0600 Subject: [PATCH] Removes the boxed trait state machine pattern and replaces it with struct returns. Boxed traits proved to be difficult to work with. On the user side: the buildpack user mostly interacts with associated methods on `BuildLog` they cannot be called unless the traits that implement them are in scope so the user was forced to have a `*` import. On the implementation side, boxed traits are limited. For example, there was no way to have an associated function that accepts a `Fn` or `FnOnce` to call it and return itself. The boxed trait state machine pattern was a useful exercise in refining the shape of the API, but it is no longer bringing joy. With that, we wish it farewell. --- .../examples/print_style_guide.rs | 12 +- libherokubuildpack/src/output/build_log.rs | 237 ++++++++---------- libherokubuildpack/src/output/interface.rs | 53 ---- libherokubuildpack/src/output/mod.rs | 1 - libherokubuildpack/src/output/section_log.rs | 97 ++++--- 5 files changed, 158 insertions(+), 242 deletions(-) delete mode 100644 libherokubuildpack/src/output/interface.rs diff --git a/libherokubuildpack/examples/print_style_guide.rs b/libherokubuildpack/examples/print_style_guide.rs index aa907f47..8a18d43e 100644 --- a/libherokubuildpack/examples/print_style_guide.rs +++ b/libherokubuildpack/examples/print_style_guide.rs @@ -4,7 +4,7 @@ use indoc::formatdoc; use libherokubuildpack::output::style::{self, DEBUG_INFO, HELP}; #[allow(clippy::wildcard_imports)] use libherokubuildpack::output::{ - build_log::*, + build_log::BuildLog, section_log::{log_step, log_step_stream, log_step_timed}, }; use std::io::stdout; @@ -81,8 +81,7 @@ fn main() { command .stream_output(stream.io(), stream.io()) .expect("Implement real error handling in real apps"); - log = stream.finish_timed_stream().end_section(); - drop(log); + stream.finish_timed_stream().end_section(); } { @@ -174,10 +173,8 @@ fn main() { } { - let mut log = BuildLog::new(stdout()).buildpack_name("Formatting helpers"); - - log = log - .section("The style module") + let log = BuildLog::new(stdout()).buildpack_name("Formatting helpers"); + log.section("The style module") .step(&formatdoc! {" Formatting helpers can be used to enhance log output: "}) @@ -223,6 +220,5 @@ fn main() { ]; table.print(data); - drop(log); } } diff --git a/libherokubuildpack/src/output/build_log.rs b/libherokubuildpack/src/output/build_log.rs index 966c2de4..2d5a6847 100644 --- a/libherokubuildpack/src/output/build_log.rs +++ b/libherokubuildpack/src/output/build_log.rs @@ -1,6 +1,26 @@ +//! # Build output logging +//! +//! Use the `BuildLog` to output structured text as a buildpack is executing +//! +//! ``` +//! use libherokubuildpack::output::build_log::BuildLog; +//! +//! let mut logger = BuildLog::new(std::io::stdout()) +//! .buildpack_name("Heroku Ruby Buildpack"); +//! +//! logger = logger +//! .section("Ruby version") +//! .step_timed("Installing") +//! .finish_timed_step() +//! .end_section(); +//! +//! logger.finish_logging(); +//! ``` +//! +//! To log inside of a layer see `section_log`. +//! +//! For usage details run `cargo run --bin print_style_guide` use crate::output::background::{print_interval, state::PrintGuard}; -#[allow(clippy::wildcard_imports)] -pub use crate::output::interface::*; use crate::output::style; use std::fmt::Debug; use std::io::Write; @@ -8,29 +28,7 @@ use std::marker::PhantomData; use std::sync::{Arc, Mutex}; use std::time::{Duration, Instant}; -/// # Build output logging -/// -/// Use the `BuildLog` to output structured text as a buildpack is executing -/// -/// ``` -/// use libherokubuildpack::output::build_log::*; -/// -/// let mut logger = BuildLog::new(std::io::stdout()) -/// .buildpack_name("Heroku Ruby Buildpack"); -/// -/// logger = logger -/// .section("Ruby version") -/// .step_timed("Installing") -/// .finish_timed_step() -/// .end_section(); -/// -/// logger.finish_logging(); -/// ``` -/// -/// To log inside of a layer see `section_log`. -/// -/// For usage details run `cargo run --bin print_style_guide` - +/// See the module docs for example usage #[allow(clippy::module_name_repetitions)] #[derive(Debug)] pub struct BuildLog { @@ -79,83 +77,76 @@ where data: BuildData::default(), } } -} -impl Logger for BuildLog -where - W: Write + Send + Sync + Debug + 'static, -{ - fn buildpack_name(mut self, buildpack_name: &str) -> Box { + pub fn buildpack_name(mut self, buildpack_name: &str) -> BuildLog { write_now( &mut self.io, format!("{}\n\n", style::header(buildpack_name)), ); - Box::new(BuildLog { + BuildLog { io: self.io, data: self.data, state: PhantomData::, - }) + } } - fn without_buildpack_name(self) -> Box { - Box::new(BuildLog { + pub fn without_buildpack_name(self) -> BuildLog { + BuildLog { io: self.io, data: self.data, state: PhantomData::, - }) + } } } -impl StartedLogger for BuildLog +impl BuildLog where W: Write + Send + Sync + Debug + 'static, { - fn section(mut self: Box, s: &str) -> Box { + pub fn section(mut self, s: &str) -> BuildLog { writeln_now(&mut self.io, style::section(s)); - Box::new(BuildLog { + BuildLog { io: self.io, data: self.data, state: PhantomData::, - }) + } } - fn finish_logging(mut self: Box) { + pub fn finish_logging(mut self) { let elapsed = style::time::human(&self.data.started.elapsed()); let details = style::details(format!("finished in {elapsed}")); writeln_now(&mut self.io, style::section(format!("Done {details}"))); } - fn announce(self: Box) -> Box>> { - Box::new(AnnounceBuildLog { + pub fn announce(self) -> AnnounceLog { + AnnounceLog { io: self.io, data: self.data, state: PhantomData::, leader: Some("\n".to_string()), - }) + } } } -impl SectionLogger for BuildLog + +impl BuildLog where W: Write + Send + Sync + Debug + 'static, { - fn mut_step(&mut self, s: &str) { + pub fn mut_step(&mut self, s: &str) { writeln_now(&mut self.io, style::step(s)); } - fn step(mut self: Box, s: &str) -> Box { + #[must_use] + pub fn step(mut self, s: &str) -> BuildLog { self.mut_step(s); - Box::new(BuildLog { - io: self.io, - state: PhantomData::, - data: self.data, - }) + self } - fn step_timed(self: Box, s: &str) -> Box { + pub fn step_timed(self, s: &str) -> BackgroundLog { let mut io = self.io; let data = self.data; let timer = Instant::now(); @@ -169,49 +160,49 @@ where style::background_timer_end(), ); - Box::new(FinishTimedStep { + BackgroundLog { data, timer, dot_printer, - }) + } } - fn step_timed_stream(mut self: Box, s: &str) -> Box { + pub fn step_timed_stream(mut self, s: &str) -> StreamLog { self.mut_step(s); let started = Instant::now(); let arc_io = Arc::new(Mutex::new(self.io)); - let mut stream = StreamTimed { + let mut stream = StreamLog { arc_io, data: self.data, started, }; stream.start(); - Box::new(stream) + stream } - fn end_section(self: Box) -> Box { - Box::new(BuildLog { + pub fn end_section(self) -> BuildLog { + BuildLog { io: self.io, data: self.data, state: PhantomData::, - }) + } } - fn announce(self: Box) -> Box>> { - Box::new(AnnounceBuildLog { + pub fn announce(self) -> AnnounceLog { + AnnounceLog { io: self.io, data: self.data, state: PhantomData::, leader: Some("\n".to_string()), - }) + } } } // Store internal state, print leading character exactly once on warning or important #[derive(Debug)] -struct AnnounceBuildLog +pub struct AnnounceLog where W: Write + Send + Sync + Debug + 'static, { @@ -221,7 +212,7 @@ where leader: Option, } -impl AnnounceBuildLog +impl AnnounceLog where T: Debug, W: Write + Send + Sync + Debug + 'static, @@ -244,12 +235,12 @@ where } } -impl ErrorLogger for AnnounceBuildLog +impl AnnounceLog where T: Debug, W: Write + Send + Sync + Debug + 'static, { - fn error(mut self: Box, s: &str) { + pub fn error(mut self, s: &str) { if let Some(leader) = self.leader.take() { write_now(&mut self.io, leader); } @@ -258,61 +249,56 @@ where } } -impl AnnounceLogger for AnnounceBuildLog +impl AnnounceLog where W: Write + Send + Sync + Debug + 'static, { - type ReturnTo = Box; - - fn warning(mut self: Box, s: &str) -> Box> { + #[must_use] + pub fn warning(mut self, s: &str) -> AnnounceLog { self.log_warning_shared(s); self } - fn important( - mut self: Box, - s: &str, - ) -> Box> { + #[must_use] + pub fn important(mut self, s: &str) -> AnnounceLog { self.log_important_shared(s); self } - fn end_announce(self: Box) -> Box { - Box::new(BuildLog { + pub fn end_announce(self) -> BuildLog { + BuildLog { io: self.io, data: self.data, state: PhantomData::, - }) + } } } -impl AnnounceLogger for AnnounceBuildLog +impl AnnounceLog where W: Write + Send + Sync + Debug + 'static, { - type ReturnTo = Box; - - fn warning(mut self: Box, s: &str) -> Box> { + #[must_use] + pub fn warning(mut self, s: &str) -> AnnounceLog { self.log_warning_shared(s); self } - fn important( - mut self: Box, - s: &str, - ) -> Box> { + #[must_use] + pub fn important(mut self, s: &str) -> AnnounceLog { self.log_important_shared(s); self } - fn end_announce(self: Box) -> Box { - Box::new(BuildLog { + #[must_use] + pub fn end_announce(self) -> BuildLog { + BuildLog { io: self.io, data: self.data, state: PhantomData::, - }) + } } } @@ -322,7 +308,7 @@ where /// by wrapping in a mutex. /// /// It implements writing by unlocking and delegating to the internal writer. -/// Can be used for `Box::io()` +/// Can be used for streaming stdout and stderr to the same writer. #[derive(Debug)] struct LockedWriter { arc: Arc>, @@ -343,53 +329,30 @@ where } } -/// Used to implement `Box` interface +/// Stream output to the user /// /// Mostly used for logging a running command #[derive(Debug)] -struct StreamTimed { +pub struct StreamLog { data: BuildData, arc_io: Arc>, started: Instant, } -impl StreamTimed +impl StreamLog where - W: Write + Send + Sync + Debug, + W: Write + Send + Sync + Debug + 'static, { fn start(&mut self) { let mut guard = self.arc_io.lock().expect("Logging mutex posioned"); let mut io = guard.by_ref(); - // Newline before stream + // Newline before stream https://github.com/heroku/libcnb.rs/issues/582 writeln_now(&mut io, ""); } -} - -// Need a trait that is both write a debug -trait WriteDebug: Write + Debug {} -impl WriteDebug for T where T: Write + Debug {} -/// Attempt to unwrap an io inside of an `Arc` if this fails because there is more -/// than a single reference don't panic, return the original IO instead. -/// -/// This prevents a runtime panic and allows us to continue logging -fn try_unwrap_arc_io(arc_io: Arc>) -> Box -where - W: Write + Send + Sync + Debug + 'static, -{ - match Arc::try_unwrap(arc_io) { - Ok(mutex) => Box::new(mutex.into_inner().expect("Logging mutex was poisioned")), - Err(original) => Box::new(LockedWriter { arc: original }), - } -} - -impl StreamLogger for StreamTimed -where - W: Write + Send + Sync + Debug + 'static, -{ /// Yield boxed writer that can be used for formatting and streaming contents /// back to the logger. - fn io(&mut self) -> Box { + pub fn io(&mut self) -> Box { Box::new(crate::write::line_mapped( LockedWriter { arc: self.arc_io.clone(), @@ -398,9 +361,24 @@ where )) } - fn finish_timed_stream(self: Box) -> Box { + /// # Panics + /// + /// Ensure that the return of any calls to the `io` function + /// are not retained before calling this function. + /// + /// This struct yields a `Box` which is effectively an + /// Arc to allow using the same writer for streaming stdout and stderr. + /// + /// If any of those boxed writers are retained then the `W` cannot + /// be reclaimed and returned. This will cause a panic. + #[must_use] + pub fn finish_timed_stream(self) -> BuildLog { let duration = self.started.elapsed(); - let mut io = try_unwrap_arc_io(self.arc_io); + + let mut io = Arc::try_unwrap(self.arc_io) + .expect("Expected buildpack author to not retain any IO streaming IO instances") + .into_inner() + .expect("Logging mutex was poisioned"); // // Newline after stream writeln_now(&mut io, ""); @@ -416,15 +394,15 @@ where style::details(style::time::human(&duration)) )); - Box::new(section) + section } } -/// Implements `Box` +/// Logs to the user while work is being performed in the background /// /// Used to end a background inline timer i.e. Installing ...... (<0.1s) #[derive(Debug)] -struct FinishTimedStep +pub struct BackgroundLog where W: Write + Debug, { @@ -433,11 +411,12 @@ where dot_printer: PrintGuard, } -impl TimedStepLogger for FinishTimedStep +impl BackgroundLog where W: Write + Send + Sync + Debug + 'static, { - fn finish_timed_step(self: Box) -> Box { + #[must_use] + pub fn finish_timed_step(self) -> BuildLog { // Must stop background writing thread before retrieving IO let data = self.data; let timer = self.timer; @@ -450,11 +429,11 @@ where writeln_now(&mut io, style::details(style::time::human(&duration))); - Box::new(BuildLog { + BuildLog { io, data, state: PhantomData::, - }) + } } } diff --git a/libherokubuildpack/src/output/interface.rs b/libherokubuildpack/src/output/interface.rs deleted file mode 100644 index 52aa1da5..00000000 --- a/libherokubuildpack/src/output/interface.rs +++ /dev/null @@ -1,53 +0,0 @@ -use std::fmt::Debug; -use std::io::Write; - -/// Consuming stateful logger interface -/// -/// The log pattern used by `BuildLog` is a consuming state machine that is designed to minimize -/// the amount of mistakes that can result in malformed build output. -/// -/// The interface isn't stable and may need to change. - -pub trait Logger: Debug { - fn buildpack_name(self, s: &str) -> Box; - fn without_buildpack_name(self) -> Box; -} - -pub trait StartedLogger: Debug { - fn section(self: Box, s: &str) -> Box; - fn finish_logging(self: Box); - - fn announce(self: Box) -> Box>>; -} - -pub trait SectionLogger: Debug { - fn step(self: Box, s: &str) -> Box; - fn mut_step(&mut self, s: &str); - fn step_timed(self: Box, s: &str) -> Box; - fn step_timed_stream(self: Box, s: &str) -> Box; - fn end_section(self: Box) -> Box; - - fn announce(self: Box) -> Box>>; -} - -pub trait AnnounceLogger: ErrorLogger + Debug { - type ReturnTo; - - fn warning(self: Box, s: &str) -> Box>; - fn important(self: Box, s: &str) -> Box>; - - fn end_announce(self: Box) -> Self::ReturnTo; -} - -pub trait TimedStepLogger: Debug { - fn finish_timed_step(self: Box) -> Box; -} - -pub trait StreamLogger: Debug { - fn io(&mut self) -> Box; - fn finish_timed_stream(self: Box) -> Box; -} - -pub trait ErrorLogger: Debug { - fn error(self: Box, s: &str); -} diff --git a/libherokubuildpack/src/output/mod.rs b/libherokubuildpack/src/output/mod.rs index b3b211ef..ed883333 100644 --- a/libherokubuildpack/src/output/mod.rs +++ b/libherokubuildpack/src/output/mod.rs @@ -1,6 +1,5 @@ pub(crate) mod background; pub mod build_log; -pub mod interface; pub mod section_log; pub mod style; mod util; diff --git a/libherokubuildpack/src/output/section_log.rs b/libherokubuildpack/src/output/section_log.rs index ac1d4e30..40ab31e6 100644 --- a/libherokubuildpack/src/output/section_log.rs +++ b/libherokubuildpack/src/output/section_log.rs @@ -1,46 +1,44 @@ +//! Write to the build output in a `Box` format with functions +//! +//! ## What +//! +//! Logging from within a layer can be difficult because calls to the layer interface are not +//! mutable nor consumable. Functions can be used at any time with no restrictions. The +//! only downside is that the buildpack author (you) is now responsible for: +//! +//! - Ensuring that `Box::section()` was called right before any of these +//! functions are called. +//! - Ensuring that you are not attempting to log while already logging i.e. calling `step()` within a +//! `step_timed()` call. +//! +//! For usage details run `cargo run --bin print_style_guide` +//! +//! ## Use +//! +//! The main use case is logging inside of a layer: +//! +//! ```no_run +//! use libherokubuildpack::output::section_log::log_step_timed; +//! +//! // fn create( +//! // &self, +//! // context: &libcnb::build::BuildContext, +//! // layer_path: &std::path::Path, +//! // ) -> Result< +//! // libcnb::layer::LayerResult, +//! // ::Error, +//! // > { +//! log_step_timed("Installing", || { +//! // Install logic here +//! todo!() +//! }) +//! // } +//! ``` +use crate::output::build_log::StreamLog; use crate::output::build_log::{state, BuildData, BuildLog}; -#[allow(clippy::wildcard_imports)] -pub use crate::output::interface::*; use std::io::Stdout; use std::marker::PhantomData; -/// Write to the build output in a `Box` format with functions -/// -/// ## What -/// -/// Logging from within a layer can be difficult because calls to the layer interface are not -/// mutable nor consumable. Functions can be used at any time with no restrictions. The -/// only downside is that the buildpack author (you) is now responsible for: -/// -/// - Ensuring that `Box::section()` was called right before any of these -/// functions are called. -/// - Ensuring that you are not attempting to log while already logging i.e. calling `step()` within a -/// `step_timed()` call. -/// -/// For usage details run `cargo run --bin print_style_guide` -/// -/// ## Use -/// -/// The main use case is logging inside of a layer: -/// -/// ```no_run -/// use libherokubuildpack::output::section_log::log_step_timed; -/// -/// // fn create( -/// // &self, -/// // context: &libcnb::build::BuildContext, -/// // layer_path: &std::path::Path, -/// // ) -> Result< -/// // libcnb::layer::LayerResult, -/// // ::Error, -/// // > { -/// log_step_timed("Installing", || { -/// // Install logic here -/// todo!() -/// }) -/// // } -/// ``` - /// Output a message as a single step, ideally a short message /// /// ``` @@ -49,7 +47,7 @@ use std::marker::PhantomData; /// log_step("Clearing cache (ruby version changed)"); /// ``` pub fn log_step(s: impl AsRef) { - logger().step(s.as_ref()); + let _ = logger().step(s.as_ref()); } /// Will print the input string followed by a background timer @@ -67,7 +65,7 @@ pub fn log_step(s: impl AsRef) { pub fn log_step_timed(s: impl AsRef, f: impl FnOnce() -> T) -> T { let timer = logger().step_timed(s.as_ref()); let out = f(); - timer.finish_timed_step(); + let _ = timer.finish_timed_step(); out } @@ -88,13 +86,10 @@ pub fn log_step_timed(s: impl AsRef, f: impl FnOnce() -> T) -> T { /// ``` /// /// Timing information will be output at the end of the step. -pub fn log_step_stream( - s: impl AsRef, - f: impl FnOnce(&mut Box) -> T, -) -> T { +pub fn log_step_stream(s: impl AsRef, f: impl FnOnce(&mut StreamLog) -> T) -> T { let mut stream = logger().step_timed_stream(s.as_ref()); let out = f(&mut stream); - stream.finish_timed_stream(); + let _ = stream.finish_timed_stream(); out } @@ -105,20 +100,20 @@ pub fn log_error(s: impl AsRef) { /// Print an warning block to the output pub fn log_warning(s: impl AsRef) { - logger().announce().warning(s.as_ref()); + let _ = logger().announce().warning(s.as_ref()); } /// Print an important block to the output pub fn log_important(s: impl AsRef) { - logger().announce().important(s.as_ref()); + let _ = logger().announce().important(s.as_ref()); } -fn logger() -> Box { - Box::new(BuildLog:: { +fn logger() -> BuildLog { + BuildLog:: { io: std::io::stdout(), // Be careful not to do anything that might access this state // as it's ephemeral data (i.e. not passed in from the start of the build) data: BuildData::default(), state: PhantomData, - }) + } }