Skip to content

Commit

Permalink
Add background dot printer
Browse files Browse the repository at this point in the history
The `start_timer` emits dots in the background while the buildpack does work. This is important for things like downloading a file while on spotty internet so that the user knows the buildpack isn't stuck.
  • Loading branch information
schneems committed Feb 14, 2024
1 parent d806cbd commit 0f844cf
Show file tree
Hide file tree
Showing 3 changed files with 323 additions and 0 deletions.
3 changes: 3 additions & 0 deletions libherokubuildpack/src/buildpack_output/ansi_escape.rs
Expand Up @@ -31,10 +31,12 @@ const RED: &str = "\x1B[0;31m";
const YELLOW: &str = "\x1B[0;33m";
const BOLD_CYAN: &str = "\x1B[1;36m";
const BOLD_PURPLE: &str = "\x1B[1;35m";
pub(crate) const DIM: &str = "\x1B[2;1m"; // Default color but softer/less vibrant

#[derive(Debug)]
#[allow(clippy::upper_case_acronyms)]
pub(crate) enum ANSI {
Dim,
Red,
Yellow,
BoldCyan,
Expand All @@ -44,6 +46,7 @@ pub(crate) enum ANSI {
impl ANSI {
fn to_str(&self) -> &'static str {
match self {
ANSI::Dim => DIM,
ANSI::Red => RED,
ANSI::Yellow => YELLOW,
ANSI::BoldCyan => BOLD_CYAN,
Expand Down
196 changes: 196 additions & 0 deletions libherokubuildpack/src/buildpack_output/background_printer.rs
@@ -0,0 +1,196 @@
use std::io::Write;
use std::sync::mpsc::{channel, Sender};
use std::thread::JoinHandle;
use std::time::Duration;

/// This module is responsible for the logic involved in the printing to output while
/// other work is being performed. Such as printing dots while a download is being performed

/// Print dots to the given buffer at the given interval
///
/// Returns a struct that allows for manually stopping the timer or will automatically stop
/// the timer if the guard is dropped. This functionality allows for errors that trigger
/// an exit of the function to not accidentally have a timer printing in the background
/// forever.
#[must_use]
pub(crate) fn print_interval<W>(
mut buffer: W,
interval: Duration,
start: String,
tick: String,
end: String,
) -> PrintGuard<W>
where
W: Write + Send + 'static,
{
let (sender, receiver) = channel::<()>();

let join_handle = std::thread::spawn(move || {
write!(buffer, "{start}").expect("Internal error");
buffer.flush().expect("Internal error");

loop {
write!(buffer, "{tick}").expect("Internal error");
buffer.flush().expect("Internal error");

if receiver.recv_timeout(interval).is_ok() {
break;
}
}

write!(buffer, "{end}").expect("Internal error");
buffer.flush().expect("Internal error");

buffer
});

PrintGuard::new(join_handle, sender)
}

/// Holds the reference to the background printer
///
/// Ensures that the dot printer is stopped in the event of an error. By signaling
/// it and joining when this struct is dropped.
///
/// Gives access to the original io/buffer struct passed to the background writer
/// when the thread is manually stopped.
///
/// # Panics
///
/// Updates to this code need to take care to not introduce a panic. See
/// documentation in `PrintGuard::stop` below for more details.
#[derive(Debug)]
pub(crate) struct PrintGuard<W> {
/// Holds the handle to the thread printing dots
///
/// Structs that implement `Drop` must ensure a valid internal state at
/// all times due to E0509. The handle is wrapped in an option to allow the
/// inner value to be removed while preserving internal state.
join_handle: Option<JoinHandle<W>>,

/// Holds the signaling method to tell the background printer
/// to stop emitting.
stop_signal: Sender<()>,
}

impl<W> Drop for PrintGuard<W> {
fn drop(&mut self) {
// A note on correctness. It might seem that it's enough to signal the thread to
// stop, that we don't also have to join and wait for it to finish, but that's not
// the case. The printer can still emit a value after it's told to stop.
//
// When that happens the output can appear in the middle of another output, such
// as an error message if a global writer is being used such as stdout.
// As a result we have to signal AND ensure the thread is stopped before
// continuing.
if let Some(join_handle) = self.join_handle.take() {
let _ = self.stop_signal.send(());
let _ = join_handle.join();
}
}
}

impl<W> PrintGuard<W> {
/// Preserve internal state by ensuring the `Option` is always populated
fn new(join_handle: JoinHandle<W>, sender: Sender<()>) -> Self {
let guard = PrintGuard {
join_handle: Some(join_handle),
stop_signal: sender,
};
debug_assert!(guard.join_handle.is_some());

guard
}

/// The only thing a consumer can do is stop the dots and receive
/// the original buffer.
///
/// # Panics
///
/// This code can panic if it encounters an unexpected internal state.
/// If that happens it means there is an internal bug in this logic.
/// To avoid a panic, developers modifying this file must obey the following
/// rules:
///
/// - Always consume the struct when accessing the Option value outside of Drop
/// - Never construct this struct with a `None` option value.
///
/// This `Option` wrapping is needed to support a implementing Drop to
/// ensure the printing is stopped. When a struct implements drop it cannot
/// remove it's internal state due to E0509:
///
/// <https://github.com/rust-lang/rust/blob/27d8a577138c0d319a572cd1a464c2b755e577de/compiler/rustc_error_codes/src/error_codes/E0509.md>
///
/// The workaround is to never allow invalid internal state by replacing the
/// inner value with a `None` when removing it. We don't want to expose this
/// implementation detail to the user, so instead we accept the panic, ensure
/// the code is exercised under test, and exhaustively document why this panic
/// exists and how developers working with this code can maintain safety.
#[allow(clippy::panic_in_result_fn)]
pub(crate) fn stop(mut self) -> std::thread::Result<W> {
// Ignore if the channel is closed, likely means the thread died which
// we want in this case.
match self.join_handle.take() {
Some(join_handle) => {
let _ = self.stop_signal.send(());
join_handle.join()
}
None => panic!("Internal error: Dot print internal state should never be None"),
}
}
}

#[cfg(test)]
mod test {
use super::*;
use std::fs::{File, OpenOptions};
use tempfile::NamedTempFile;

#[test]
fn does_stop_does_not_panic() {
let mut buffer: Vec<u8> = vec![];
write!(buffer, "before").unwrap();

let dot = print_interval(
buffer,
Duration::from_millis(1),
String::from(" ."),
String::from("."),
String::from(". "),
);
let mut writer = dot.stop().unwrap();

write!(writer, "after").unwrap();
writer.flush().unwrap();

assert_eq!("before ... after", String::from_utf8_lossy(&writer));
}

#[test]
fn test_drop_stops_timer() {
let tempfile = NamedTempFile::new().unwrap();
let mut log = File::create(tempfile.path()).unwrap();
write!(log, "before").unwrap();

let dot = print_interval(
log,
Duration::from_millis(1),
String::from(" ."),
String::from("."),
String::from(". "),
);
drop(dot);

let mut log = OpenOptions::new()
.append(true)
.open(tempfile.path())
.unwrap();
write!(log, "after").unwrap();
log.flush().unwrap();

assert_eq!(
String::from("before ... after"),
std::fs::read_to_string(tempfile.path()).unwrap()
);
}
}
124 changes: 124 additions & 0 deletions libherokubuildpack/src/buildpack_output/mod.rs
Expand Up @@ -38,6 +38,7 @@ use std::io::Write;
use std::time::Instant;

mod ansi_escape;
mod background_printer;
mod duration_format;
pub mod style;
mod util;
Expand Down Expand Up @@ -70,6 +71,7 @@ pub struct BuildpackOutput<T> {
/// The [`BuildpackOutput`] struct acts as an output state machine. These structs
/// represent the various states. See struct documentation for more details.
pub mod state {
use crate::buildpack_output::background_printer::PrintGuard;
use crate::buildpack_output::util::ParagraphInspectWrite;
use crate::write::MappedWrite;
use std::time::Instant;
Expand Down Expand Up @@ -188,6 +190,35 @@ pub mod state {
pub(crate) started: Instant,
pub(crate) write: MappedWrite<ParagraphInspectWrite<W>>,
}

/// This state is intended for long running tasks that do not stream but wish to convey progress
/// to the end user. It is started from a `state::Section` and finished back to a `state::Section`.
///
/// ```rust
/// use libherokubuildpack::buildpack_output::{BuildpackOutput, state::{Started, Section}};
/// use std::io::Write;
///
/// let mut output = BuildpackOutput::new(std::io::stdout())
/// .start("Example Buildpack")
/// .section("Ruby version");
///
/// install_ruby(output).finish();
///
/// fn install_ruby<W>(mut output: BuildpackOutput<Section<W>>) -> BuildpackOutput<Section<W>>
/// where W: Write + Send + Sync + 'static {
/// let mut timer = output.step("Installing Ruby")
/// .start_timer("Installing");
///
/// /// ...
///
/// timer.finish()
///}
/// ```
#[derive(Debug)]
pub struct Background<W: std::io::Write> {
pub(crate) started: Instant,
pub(crate) write: PrintGuard<ParagraphInspectWrite<W>>,
}
}

trait AnnounceSupportedState {
Expand Down Expand Up @@ -491,6 +522,43 @@ where
}
}

/// Output periodic timer updates to the end user.
///
/// If a buildpack author wishes to start a long running task that does not stream, staring a timer
/// will let the user know that the buildpack is performing work and that the UI is not stuck.
///
/// One common use case is when downloading a file. This is especially important for the local
/// buildpack development experience where the user's network may be unexpectedly slow, such as
/// in a hotel or on a plane.
///
/// This function will transition your buildpack output to [`state::Background`].
///
/// # Panics
///
/// Will panic if the UI writer is closed.
pub fn start_timer(mut self, s: impl AsRef<str>) -> BuildpackOutput<state::Background<W>> {
// Do not emit a newline after the message
write!(self.state.write, "{}", Self::style(s)).expect("Output error: UI writer closed");
self.state
.write
.flush()
.expect("Output error: UI writer closed");

BuildpackOutput {
started: self.started,
state: state::Background {
started: Instant::now(),
write: background_printer::print_interval(
self.state.write,
std::time::Duration::from_secs(1),
ansi_escape::wrap_ansi_escape_each_line(&ANSI::Dim, " ."),
ansi_escape::wrap_ansi_escape_each_line(&ANSI::Dim, "."),
ansi_escape::wrap_ansi_escape_each_line(&ANSI::Dim, ". "),
),
},
}
}

/// Finish a section and transition back to [`state::Started`].
pub fn finish(self) -> BuildpackOutput<state::Started<W>> {
BuildpackOutput {
Expand All @@ -502,6 +570,30 @@ where
}
}

impl<W> BuildpackOutput<state::Background<W>>
where
W: Write + Send + Sync + 'static,
{
/// Finalize a timer's output
///
/// Once you're finished with your long running task, calling this function
/// finalizes the timer's output and transitions back to a [`state::Section`].
#[must_use]
pub fn finish(self) -> BuildpackOutput<state::Section<W>> {
let duration = self.state.started.elapsed();
let mut io = match self.state.write.stop() {
Ok(io) => io,
Err(e) => std::panic::resume_unwind(e),
};

writeln_now(&mut io, style::details(duration_format::human(&duration)));
BuildpackOutput {
started: self.started,
state: state::Section { write: io },
}
}
}

impl<W> BuildpackOutput<state::Stream<W>>
where
W: Write + Send + Sync + 'static,
Expand Down Expand Up @@ -560,6 +652,38 @@ mod test {
use libcnb_test::assert_contains;
use std::fs::File;

#[test]
fn background_timer() {
let io = BuildpackOutput::new(Vec::new())
.start_silent()
.section("Background")
.start_timer("Installing")
.finish()
.finish()
.finish();

// Test human readable timer output
let expected = formatdoc! {"
- Background
- Installing ... (< 0.1s)
- Done (finished in < 0.1s)
"};

assert_eq!(
expected,
strip_ansi_escape_sequences(String::from_utf8_lossy(&io))
);

// Test timer dot colorization
let expected = formatdoc! {"
- Background
- Installing\u{1b}[2;1m .\u{1b}[0m\u{1b}[2;1m.\u{1b}[0m\u{1b}[2;1m. \u{1b}[0m(< 0.1s)
- Done (finished in < 0.1s)
"};

assert_eq!(expected, String::from_utf8_lossy(&io));
}

#[test]
fn write_paragraph_empty_lines() {
let io = BuildpackOutput::new(Vec::new())
Expand Down

0 comments on commit 0f844cf

Please sign in to comment.