feat(experimental): Build multiple recipes in parallel (#182)

The `build` subcommand can now take in any number of recipe files and
will build them all in parallel. Along with this new ability, I've added
a way to easily distinguish which part of the build log belongs to which
recipe. Check out the `docker_build` action of this PR for an example.


![gif](https://gitlab.com/wunker-bunker/wunker-os/-/raw/main/bluebuild.gif)

## Tasks

- [x] Make build log follow same pattern as normal logs to keep things
consistent
- [x] Update color ranges based on @xynydev 's feedback
- [x] Deal with ANSI control characters in log output
- [x] Add [`indicatif`](https://crates.io/crates/indicatif) to make logs
look nicer
- [x] Add ability to print logs to a file
This commit is contained in:
Gerald Pinder 2024-06-07 17:52:26 -04:00 committed by GitHub
parent 18e48a34a4
commit 4ca98c1c2a
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
24 changed files with 1449 additions and 500 deletions

View file

@ -10,7 +10,13 @@ license.workspace = true
[dependencies]
atty = "0.2"
base64 = "0.22.1"
blake2 = "0.10.6"
directories = "5"
rand = "0.8.5"
log4rs = { version = "1.3.0", features = ["background_rotation"] }
nu-ansi-term = { version = "0.50.0", features = ["gnu_legacy"] }
os_pipe = { version = "1", features = ["io_safety"] }
process_control = { version = "4", features = ["crossbeam-channel"] }
syntect = "5"
which = "6"
@ -19,12 +25,15 @@ anyhow.workspace = true
chrono.workspace = true
clap = { workspace = true, features = ["derive"] }
colored.workspace = true
env_logger.workspace = true
format_serde_error.workspace = true
indicatif.workspace = true
indicatif-log-bridge.workspace = true
log.workspace = true
once_cell.workspace = true
serde.workspace = true
serde_yaml.workspace = true
serde_json.workspace = true
typed-builder.workspace = true
[build-dependencies]
syntect = "5.2.0"

View file

@ -3,12 +3,25 @@ pub mod constants;
pub mod logging;
pub mod syntax_highlighting;
use std::{ffi::OsStr, io::Write, path::PathBuf, process::Command, thread, time::Duration};
use std::{
os::unix::ffi::OsStrExt,
path::{Path, PathBuf},
process::Command,
thread,
time::Duration,
};
use anyhow::{anyhow, Result};
use base64::prelude::*;
use blake2::{
digest::{Update, VariableOutput},
Blake2bVar,
};
use format_serde_error::SerdeError;
use log::trace;
use crate::constants::CONTAINER_FILE;
pub use command_output::*;
/// Checks for the existance of a given command.
@ -34,23 +47,6 @@ pub fn check_command_exists(command: &str) -> Result<()> {
}
}
/// Appends a string to a file.
///
/// # Errors
/// Will error if it fails to append to a file.
pub fn append_to_file<T: Into<PathBuf> + AsRef<OsStr>>(file_path: &T, content: &str) -> Result<()> {
let file_path: PathBuf = file_path.into();
trace!("append_to_file({}, {content})", file_path.display());
let mut file = std::fs::OpenOptions::new()
.append(true)
.create(true)
.open(file_path)?;
writeln!(file, "\n{content}")?;
Ok(())
}
/// Creates a serde error for displaying the file
/// and where the error occurred.
pub fn serde_yaml_err(contents: &str) -> impl Fn(serde_yaml::Error) -> SerdeError + '_ {
@ -93,3 +89,22 @@ where
pub fn home_dir() -> Option<PathBuf> {
directories::BaseDirs::new().map(|base_dirs| base_dirs.home_dir().to_path_buf())
}
/// Generates a 1-1 related Containerfile to a recipe.
/// The file is in the format of `Containerfile.{path_hash}`.
///
/// # Errors
/// Will error if unable to create a hash of the
pub fn generate_containerfile_path<T: AsRef<Path>>(path: T) -> Result<PathBuf> {
const HASH_SIZE: usize = 8;
let mut buf = [0u8; HASH_SIZE];
let mut hasher = Blake2bVar::new(HASH_SIZE)?;
hasher.update(path.as_ref().as_os_str().as_bytes());
hasher.finalize_variable(&mut buf)?;
Ok(PathBuf::from(format!(
"{CONTAINER_FILE}.{}",
BASE64_URL_SAFE_NO_PAD.encode(buf)
)))
}

View file

@ -1,60 +1,406 @@
use std::io::{self, Write};
use std::{
env,
fs::OpenOptions,
io::{BufRead, BufReader, Result, Write as IoWrite},
path::{Path, PathBuf},
process::{Command, ExitStatus},
sync::{Arc, Mutex},
thread,
time::Duration,
};
use chrono::Local;
use colored::{ColoredString, Colorize};
use env_logger::fmt::Formatter;
use log::{Level, LevelFilter, Record};
use colored::{control::ShouldColorize, ColoredString, Colorize};
use indicatif::{MultiProgress, ProgressBar};
use indicatif_log_bridge::LogWrapper;
use log::{warn, Level, LevelFilter, Record};
use log4rs::{
append::{
console::ConsoleAppender,
rolling_file::{
policy::compound::{
roll::fixed_window::FixedWindowRoller, trigger::size::SizeTrigger, CompoundPolicy,
},
RollingFileAppender,
},
},
config::{Appender, Root},
encode::{pattern::PatternEncoder, Encode, Write},
Config, Logger as L4RSLogger,
};
use nu_ansi_term::Color;
use once_cell::sync::Lazy;
use rand::Rng;
use typed_builder::TypedBuilder;
fn colored_level(level: Level) -> ColoredString {
match level {
Level::Error => Level::Error.as_str().bright_red(),
Level::Warn => Level::Warn.as_str().yellow(),
Level::Info => Level::Info.as_str().bright_green(),
Level::Debug => Level::Debug.as_str().blue(),
Level::Trace => Level::Trace.as_str().bright_cyan(),
}
static MULTI_PROGRESS: Lazy<MultiProgress> = Lazy::new(MultiProgress::new);
static LOG_DIR: Lazy<Mutex<PathBuf>> = Lazy::new(|| Mutex::new(PathBuf::new()));
#[derive(Debug, Clone)]
pub struct Logger {
modules: Vec<(String, LevelFilter)>,
level: LevelFilter,
log_dir: Option<PathBuf>,
}
/// Given a `LevelFilter`, returns the function
/// used to format logs. The more verbose the log level,
/// the more info is displayed in each log header.
pub fn format_log(
log_level: LevelFilter,
) -> impl Fn(&mut Formatter, &Record) -> io::Result<()> + Sync + Send {
move |buf: &mut Formatter, record: &Record| match log_level {
LevelFilter::Error | LevelFilter::Warn | LevelFilter::Info => {
writeln!(
buf,
"{:width$} => {}",
colored_level(record.level()),
record.args(),
width = 5,
impl Logger {
const TRIGGER_FILE_SIZE: u64 = 10 * 1024;
const ARCHIVE_FILENAME_PATTERN: &'static str = "bluebuild-log.{}.log";
const LOG_FILENAME: &'static str = "bluebuild-log.log";
const LOG_FILE_COUNT: u32 = 4;
#[must_use]
pub fn new() -> Self {
Self::default()
}
pub fn filter_modules<I, S>(&mut self, filter_modules: I) -> &mut Self
where
I: IntoIterator<Item = (S, LevelFilter)>,
S: AsRef<str>,
{
self.modules = filter_modules
.into_iter()
.map(|(module, level)| (module.as_ref().to_string(), level))
.collect::<Vec<_>>();
self
}
pub fn filter_level(&mut self, filter_level: LevelFilter) -> &mut Self {
self.level = filter_level;
self
}
pub fn log_out_dir<P>(&mut self, path: Option<P>) -> &mut Self
where
P: AsRef<Path>,
{
self.log_dir = path.map(|p| p.as_ref().to_path_buf());
self
}
/// Initializes logging for the application.
///
/// # Panics
/// Will panic if logging is unable to be initialized.
pub fn init(&mut self) {
let home = env::var("HOME").expect("$HOME should be defined");
let log_dir = self.log_dir.as_ref().map_or_else(
|| Path::new(home.as_str()).join(".local/share/bluebuild"),
Clone::clone,
);
let mut lock = LOG_DIR.lock().expect("Should lock LOG_DIR");
lock.clone_from(&log_dir);
drop(lock);
let log_out_path = log_dir.join(Self::LOG_FILENAME);
let log_archive_pattern =
format!("{}/{}", log_dir.display(), Self::ARCHIVE_FILENAME_PATTERN);
let stderr = ConsoleAppender::builder()
.encoder(Box::new(
CustomPatternEncoder::builder()
.filter_modules(self.modules.clone())
.build(),
))
.target(log4rs::append::console::Target::Stderr)
.tty_only(true)
.build();
let file = RollingFileAppender::builder()
.encoder(Box::new(PatternEncoder::new("{d} - {l} - {m}{n}")))
.build(
log_out_path,
Box::new(CompoundPolicy::new(
Box::new(SizeTrigger::new(Self::TRIGGER_FILE_SIZE)),
Box::new(
FixedWindowRoller::builder()
.build(&log_archive_pattern, Self::LOG_FILE_COUNT)
.expect("Roller should be created"),
),
)),
)
}
LevelFilter::Debug => writeln!(
buf,
"[{} {:>width$}] => {}",
Local::now().format("%H:%M:%S"),
colored_level(record.level()),
record.args(),
width = 5,
),
LevelFilter::Trace => writeln!(
buf,
"[{} {:width$} {}:{}] => {}",
Local::now().format("%H:%M:%S"),
colored_level(record.level()),
record
.module_path()
.map_or_else(|| "", |p| p)
.bright_yellow(),
record
.line()
.map_or_else(String::new, |l| l.to_string())
.bright_green(),
record.args(),
width = 5,
),
LevelFilter::Off => Ok(()),
.expect("Must be able to create log FileAppender");
let config = Config::builder()
.appender(Appender::builder().build("stderr", Box::new(stderr)))
.appender(Appender::builder().build("file", Box::new(file)))
.build(
Root::builder()
.appender("stderr")
.appender("file")
.build(self.level),
)
.expect("Logger config should build");
let logger = L4RSLogger::new(config);
LogWrapper::new(MULTI_PROGRESS.clone(), logger)
.try_init()
.expect("LogWrapper should initialize");
}
pub fn multi_progress() -> MultiProgress {
MULTI_PROGRESS.clone()
}
}
impl Default for Logger {
fn default() -> Self {
Self {
modules: vec![],
level: LevelFilter::Info,
log_dir: None,
}
}
}
trait ColoredLevel {
fn colored(&self) -> ColoredString;
}
impl ColoredLevel for Level {
fn colored(&self) -> ColoredString {
match self {
Self::Error => Self::Error.as_str().red(),
Self::Warn => Self::Warn.as_str().yellow(),
Self::Info => Self::Info.as_str().green(),
Self::Debug => Self::Debug.as_str().blue(),
Self::Trace => Self::Trace.as_str().cyan(),
}
}
}
pub trait CommandLogging {
/// Prints each line of stdout/stderr with an image ref string
/// and a progress spinner. This helps to keep track of every
/// build running in parallel.
///
/// # Errors
/// Will error if there was an issue executing the process.
fn status_image_ref_progress<T, U>(self, image_ref: T, message: U) -> Result<ExitStatus>
where
T: AsRef<str>,
U: AsRef<str>;
}
impl CommandLogging for Command {
fn status_image_ref_progress<T, U>(mut self, image_ref: T, message: U) -> Result<ExitStatus>
where
T: AsRef<str>,
U: AsRef<str>,
{
let ansi_color = gen_random_ansi_color();
let name = color_str(&image_ref, ansi_color);
let short_name = color_str(shorten_name(&image_ref), ansi_color);
let log_prefix = Arc::new(log_header(short_name));
let (reader, writer) = os_pipe::pipe()?;
self.stdout(writer.try_clone()?).stderr(writer);
let progress = Logger::multi_progress()
.add(ProgressBar::new_spinner().with_message(format!("{} {name}", message.as_ref())));
progress.enable_steady_tick(Duration::from_millis(100));
let mut child = self.spawn()?;
// We drop the `Command` to prevent blocking on writer
// https://docs.rs/os_pipe/latest/os_pipe/#examples
drop(self);
let reader = BufReader::new(reader);
let log_file_path = {
let lock = LOG_DIR.lock().expect("Should lock LOG_DIR");
lock.join(format!(
"{}.log",
image_ref.as_ref().replace(['/', ':', '.'], "_")
))
};
let log_file = OpenOptions::new()
.create(true)
.append(true)
.open(log_file_path.as_path())?;
thread::spawn(move || {
let mp = Logger::multi_progress();
reader.lines().for_each(|line| {
if let Ok(l) = line {
let text = format!("{log_prefix} {l}");
if mp.is_hidden() {
eprintln!("{text}");
} else {
mp.println(text).unwrap();
}
if let Err(e) = writeln!(&log_file, "{l}") {
warn!(
"Failed to write to log for build {}: {e:?}",
log_file_path.display()
);
}
}
});
});
let status = child.wait()?;
progress.finish();
Logger::multi_progress().remove(&progress);
Ok(status)
}
}
#[derive(Debug, TypedBuilder)]
struct CustomPatternEncoder {
#[builder(default, setter(into))]
filter_modules: Vec<(String, LevelFilter)>,
}
impl Encode for CustomPatternEncoder {
fn encode(&self, w: &mut dyn Write, record: &Record) -> anyhow::Result<()> {
if record.module_path().is_some_and(|mp| {
self.filter_modules
.iter()
.any(|(module, level)| mp.contains(module) && *level <= record.level())
}) {
Ok(())
} else {
match log::max_level() {
LevelFilter::Error | LevelFilter::Warn | LevelFilter::Info => Ok(writeln!(
w,
"{prefix} {args}",
prefix = log_header(format!(
"{level:width$}",
level = record.level().colored(),
width = 5,
)),
args = record.args(),
)?),
LevelFilter::Debug => Ok(writeln!(
w,
"{prefix} {args}",
prefix = log_header(format!(
"{level:>width$}",
level = record.level().colored(),
width = 5,
)),
args = record.args(),
)?),
LevelFilter::Trace => Ok(writeln!(
w,
"{prefix} {args}",
prefix = log_header(format!(
"{level:width$} {module}:{line}",
level = record.level().colored(),
width = 5,
module = record
.module_path()
.map_or_else(|| "", |p| p)
.bright_yellow(),
line = record
.line()
.map_or_else(String::new, |l| l.to_string())
.bright_green(),
)),
args = record.args(),
)?),
LevelFilter::Off => Ok(()),
}
}
}
}
/// Used to keep the style of logs consistent between
/// normal log use and command output.
fn log_header<T: AsRef<str>>(text: T) -> String {
let text = text.as_ref();
match log::max_level() {
LevelFilter::Error | LevelFilter::Warn | LevelFilter::Info => {
format!("{text} {sep}", sep = "=>".bold())
}
LevelFilter::Debug | LevelFilter::Trace => format!(
"[{time} {text}] {sep}",
time = Local::now().format("%H:%M:%S"),
sep = "=>".bold(),
),
LevelFilter::Off => String::new(),
}
}
/// Shortens the image name so that it won't take up the
/// entire width of the terminal. This is a similar format
/// to what Earthly does in their terminal output for long
/// images on their log prefix output.
///
/// # Examples
/// `ghcr.io/blue-build/cli:latest` -> `g.i/b/cli:latest`
/// `registry.gitlab.com/some/namespace/image:latest` -> `r.g.c/s/n/image:latest`
#[must_use]
fn shorten_name<T>(text: T) -> String
where
T: AsRef<str>,
{
let text = text.as_ref();
// Split the reference by colon to separate the tag or digest
let mut parts = text.split(':');
let path = match parts.next() {
None => return text.to_string(),
Some(path) => path,
};
let tag = parts.next();
// Split the path by slash to work on each part
let path_parts: Vec<&str> = path.split('/').collect();
// Shorten each part except the last one to their initial letters
let shortened_parts: Vec<String> = path_parts
.iter()
.enumerate()
.map(|(i, part)| {
if i < path_parts.len() - 1 {
// Split on '.' and shorten each section
part.split('.')
.filter_map(|p| p.chars().next())
.map(|c| c.to_string())
.collect::<Vec<String>>()
.join(".")
} else {
(*part).into() // Keep the last part as it is
}
})
.collect();
// Rejoin the parts with '/'
let joined_path = shortened_parts.join("/");
// If there was a tag, append it back with ':', otherwise just return the path
match tag {
Some(t) => format!("{joined_path}:{t}"),
None => joined_path,
}
}
fn gen_random_ansi_color() -> u8 {
// ANSI extended color range
// https://www.ditig.com/publications/256-colors-cheat-sheet
const LOW_END: u8 = 21; // Blue1 #0000ff rgb(0,0,255) hsl(240,100%,50%)
const HIGH_END: u8 = 230; // Cornsilk1 #ffffd7 rgb(255,255,215) hsl(60,100%,92%)
rand::thread_rng().gen_range(LOW_END..=HIGH_END)
}
fn color_str<T>(text: T, ansi_color: u8) -> String
where
T: AsRef<str>,
{
if ShouldColorize::from_env().should_colorize() {
Color::Fixed(ansi_color)
.paint(text.as_ref().to_string())
.to_string()
} else {
text.as_ref().to_string()
}
}