- Commit
- cf11502b59177ed6a54c43af3a454fab8ef50c0f
- Parent
- 983f58332fd7a0b8bb69938ed12a628779977374
- Author
- Pablo <pablo-pie@riseup.net>
- Date
Refactored the logging system
Custum build of stapix for tikz.pablopie.xyz
Refactored the logging system
3 files changed, 225 insertions, 189 deletions
| Status | Name | Changes | Insertions | Deletions |
| Added | TODO.md | 1 file changed | 7 | 0 |
| Modified | src/log.rs | 2 files changed | 150 | 144 |
| Modified | src/main.rs | 2 files changed | 68 | 45 |
diff --git /dev/null b/TODO.md @@ -0,0 +1,7 @@ +# TODO + +* use SIMD for HTML escaping +* refactor the page visuals + * Also make the page root configurable +* add a flag to configure the size of the thread pool +* introduce a static configuration file?
diff --git a/src/log.rs b/src/log.rs @@ -1,172 +1,178 @@ -//! Macros for logging. +//! Macros and functions for logging. //! -//! This implementation should be thread safe (unlink an implementation using -//! `println!` and `eprintln!`) because access to the global stdout/stderr -//! handle is syncronized using a lock. -use crossterm::style::Stylize; -use std::{io::{self, Write}, fmt::Arguments}; +//! This implementation is NOT thread safe: the only logging which does not +//! happen on the main thread are thumbnail rendering error, which do not +//! require synchronization because they happen right before the entire +//! application is killed. + +use std::{io::{self, Write}, fmt::Arguments, time::Duration}; + +const BOLD_RED: &str = "\u{001b}[1;31m"; +const BOLD_GREEN: &str = "\u{001b}[1;32m"; +const BOLD_YELLOW: &str = "\u{001b}[1;33m"; +const BOLD_BLUE: &str = "\u{001b}[1;34m"; +const BOLD_CYAN: &str = "\u{001b}[1;36m"; +const BOLD_WHITE: &str = "\u{001b}[1;37m"; +const RESET: &str = "\u{001b}[0m"; + +const PROGRAM_VERSION: &str = env!("CARGO_PKG_VERSION"); #[derive(Clone, Copy, Debug)] pub(crate) enum Level { - Error, - Info, - Warn, + Error, + Info, + Warn, + Usage, } -pub(crate) fn log(level: Level, args: &Arguments<'_>, newline: bool) { - match level { - Level::Error => { - let mut stderr = io::stderr(); - let _ = write!(stderr, "{} ", "[ERROR]".red().bold()); - let _ = if newline { - writeln!(stderr, "{}", args) - } else { - write!(stderr, "{}", args) - }; - if !newline { let _ = stderr.flush(); } - } - Level::Info => { - let mut stdout = io::stdout().lock(); - let _ = write!(stdout, "{} ", "[INFO]".green().bold()); - let _ = if newline { - writeln!(stdout, "{}", args) - } else { - write!(stdout, "{}", args) - }; - if !newline { let _ = stdout.flush(); } - } - Level::Warn => { - let mut stdout = io::stdout().lock(); - let _ = write!(stdout, "{} ", "[WARNING]".yellow().bold()); - let _ = if newline { - writeln!(stdout, "{}", args) - } else { - write!(stdout, "{}", args) - }; - if !newline { let _ = stdout.flush(); } - } - } +pub struct JobListLogger { + total: usize, + count: usize, + current_job_name: String, } #[macro_export] -macro_rules! info { - // info!("a {} event", "log"); - ($($arg:tt)+) => ({ - $crate::log::log( - $crate::log::Level::Info, - &std::format_args!($($arg)+), - false, - ); - }); +macro_rules! infoln { + // infoln!("a {} event", "log"); + ($($arg:tt)+) => ({ + $crate::log::log( + $crate::log::Level::Info, + &std::format_args!($($arg)+), + ); + }); } #[macro_export] -macro_rules! infoln { - // infoln!("a {} event", "log"); - ($($arg:tt)+) => ({ - $crate::log::log( - $crate::log::Level::Info, - &std::format_args!($($arg)+), - true, - ); - }); +macro_rules! errorln { + // errorln!("a {} event", "log"); + ($($arg:tt)+) => ({ + $crate::log::log( + $crate::log::Level::Error, + &std::format_args!($($arg)+), + ); + }); } #[macro_export] -macro_rules! info_done { - () => ({ - let _ = writeln!(io::stdout().lock(), " Done!"); - }); - - // infoln!("a {} event", "log"); - ($($arg:tt)+) => ({ - let _ = writeln!( - io::stdout().lock(), - " {}", - &std::format_args!($($arg)+) - ); - }); +macro_rules! warnln { + // warnln!("a {} event", "log"); + ($($arg:tt)+) => ({ + $crate::log::log( + $crate::log::Level::Warn, + &std::format_args!($($arg)+), + ); + }); } #[macro_export] -macro_rules! error { - // info!("a {} event", "log"); - ($($arg:tt)+) => ({ - $crate::log::log( - $crate::log::Level::Error, - &std::format_args!($($arg)+), - false, - ); - }); +macro_rules! usageln { + // usageln!("a {} event", "log"); + ($($arg:tt)+) => ({ + $crate::log::log( + $crate::log::Level::Usage, + &std::format_args!($($arg)+), + ); + }); } -#[macro_export] -macro_rules! errorln { - // errorln!("a {} event", "log"); - ($($arg:tt)+) => ({ - $crate::log::log( - $crate::log::Level::Error, - &std::format_args!($($arg)+), - true, - ); - }); +pub fn finished(duration: Duration) { + let duration = duration.as_millis() / 100; + let secs = duration / 10; + let dsecs = duration % 10; + + println!(" {BOLD_GREEN}Finished{RESET} Rendering took {secs}.{dsecs}s"); } -#[macro_export] -macro_rules! warnln { - // info!("a {} event", "log"); - ($($arg:tt)+) => ({ - $crate::log::log( - $crate::log::Level::Warn, - &std::format_args!($($arg)+), - true, - ); - }); +#[cfg(target_arch = "x86_64")] +pub fn version(program_name: &str) { + if is_x86_feature_detected!("ssse3") { + infoln!("Running {BOLD_WHITE}{program_name} {PROGRAM_VERSION}{RESET} (SIMD optimizations enabled)"); + } else { + infoln!("Running {BOLD_WHITE}{program_name} {PROGRAM_VERSION}{RESET}"); + } } -#[macro_export] -macro_rules! usage { - ($program:expr) => { - let mut stderr = io::stderr(); - let _ = writeln!( - stderr, - "{usage_header_msg} {} config.yml [--full-build]", - $program, - usage_header_msg = "[USAGE]".yellow().bold() - ); - }; +#[cfg(not(target_arch = "x86_64"))] +pub fn version(program_name: &str) { + infoln!("Running {BOLD_WHITE}{program_name} {PROGRAM_VERSION}{RESET}"); } -#[macro_export] -macro_rules! usage_config { - () => { - let mut stderr = io::stderr(); - - let _ = writeln!( - stderr, - "{usage_header_msg} The YAML configuration file should look like this:", - usage_header_msg = "[USAGE]".yellow().bold() - ); - let _ = writeln!( - stderr, - " - {path_attr} examples/images/grothendieck-riemann-roch.tex - {license_attr} PD - {author_attr} Alexander Grothendieck - {alt_attr} A hand-drawn commutative diagram surrounded by fire and devils carrying forks - {caption_attr} The infamous commutative diagram from Gothendieck's 1971 manuscript - - - {path_attr} examples/images/caleb-yau.png - {license_attr} CC-BY-SA-2.5 - {author_attr} Lunch - {alt_attr} A convoluted self-intersecting surface in pastel shades of pink and blue - {caption_attr} A visual representation of the Calabi-Yau manifold", - path_attr = "path:".green(), - license_attr = "license:".green(), - author_attr = "author:".green(), - alt_attr = "alt:".green(), - caption_attr = "caption:".green() - ); - - let _ = stderr.flush(); +impl JobListLogger { + pub fn new(total_jobs: usize) -> Self { + Self { + total: total_jobs, + count: 0, + current_job_name: String::with_capacity(64) + } + } + + /// Adds a job to the queue and logs the fact this job has started + pub fn job_started(&mut self, job_name: &str) { + self.inc_counter(job_name); + + let mut stdout = io::stdout(); + let _ = write!( + stdout, + " {BOLD_CYAN}Rendering{RESET} {name}... {BOLD_WHITE}[{count:>padding$}/{total}]{RESET}\r", + count = self.count, + total = self.total, + padding = crate::log_floor(self.total), + name = self.current_job_name, + ); + let _ = stdout.flush(); + } + + /// Logs the fact the current job has just finished + pub fn job_finished(&self) { + debug_assert!(self.count > 0); + self.job_finished_impl(); + } + + /// Adds a job to the queue and logs the fact the it has just finished + pub fn job_started_and_finished(&mut self, job_name: &str) { + self.inc_counter(job_name); + self.job_finished_impl(); + } + + pub fn job_skipped(&mut self, job_name: &str) { + use crate::FULL_BUILD_OPT; + + self.inc_counter(job_name); + println!( + " {BOLD_YELLOW} Skiped{RESET} {name} (use {FULL_BUILD_OPT} to overwrite)", + name = self.current_job_name, + ); + } + + fn inc_counter(&mut self, job_name: &str) { + self.count += 1; + self.current_job_name.clear(); + self.current_job_name.push_str(job_name); + } + + fn job_finished_impl(&self) { + let space_padding = "... [/]".len() + 2 * crate::log_floor(self.total); + println!( + " {BOLD_GREEN}Rendered{RESET} {name}{empty:space_padding$}", + name = self.current_job_name, + empty = "", + ); + } +} + +pub(crate) fn log(level: Level, args: &Arguments<'_>) { + match level { + Level::Error => { + eprintln!(" {BOLD_RED}Error{RESET} {args}"); + } + Level::Info => { + println!(" {BOLD_BLUE}Info{RESET} {args}"); + } + Level::Warn => { + println!(" {BOLD_YELLOW}Warning{RESET} {args}"); + } + Level::Usage => { + println!(" {BOLD_YELLOW}Usage{RESET} {args}"); } + } }
diff --git a/src/main.rs b/src/main.rs @@ -1,4 +1,3 @@ -use crossterm::style::Stylize; use image::{DynamicImage, io::Reader as ImageReader}; use std::{ cmp, @@ -9,9 +8,11 @@ use std::{ path::{Path, PathBuf}, process::{ExitCode, Command}, sync::mpsc, + time::Instant, }; use gallery_entry::{GalleryEntry, FileFormat, LicenseType}; use threadpool::ThreadPool; +use log::JobListLogger; #[macro_use] mod log; @@ -40,50 +41,47 @@ const PAGE_TITLE: &str = "TikZ Gallery"; const AUTHOR: &str = "Pablo"; const LICENSE: &str = "GPLv3"; -/// HTML to be inserted in the beginning/end of index.html during generation -const INTRO_MSG: &str = include_str!("intro.html"); -const OUTRO_MSG: &str = include_str!("outro.html"); - /// WebP image quality const WEBP_IMAGE_QUALITY: f32 = 90.0; /// Target height of the thumbnails const THUMB_HEIGHT: u32 = 500; fn main() -> ExitCode { - infoln!("Running {package} version {version}", - package = env!("CARGO_PKG_NAME"), - version = env!("CARGO_PKG_VERSION")); - - let args: Vec<String> = env::args().collect(); - - let (program, config, full_build) = match &args[..] { - [program, config] => (program, config, false), - [program, config, opt] if opt == FULL_BUILD_OPT => { - (program, config, true) + let mut args = env::args(); + let program = args + .next() + .expect("args always contains at least the input program"); + let args: Vec<String> = args.collect(); + + log::version(&program); + + let (config, full_build) = match &args[..] { + [config] => (config, false), + [config, opt] if opt == FULL_BUILD_OPT => { + (config, true) } - [program, _config, ..] => { - errorln!("Unknown arguments: {}", ArgList(&args[2..])); - usage!(program); + [_config, ..] => { + errorln!("Unknown arguments: {}", ArgList(&args[1..])); + usageln!("{program} [{FULL_BUILD_OPT}] <config.yml>"); return ExitCode::FAILURE; } - [program] => { + [] => { errorln!("Expected 1 command line argument, found none"); - usage!(program); + usageln!("{program} [{FULL_BUILD_OPT}] <config.yml>"); return ExitCode::FAILURE; } - [] => unreachable!("args always contains at least the input program"), }; let f = File::open(config); match f.map(serde_yaml::from_reader::<_, Vec<GalleryEntry>>) { Err(err) => { errorln!("Couldn't open {config:?}: {err}"); - usage!(program); + usageln!("{program} [{FULL_BUILD_OPT}] <config.yml>"); return ExitCode::FAILURE; } Ok(Err(err)) => { errorln!("Couldn't parse {config:?}: {err}"); - usage_config!(); + usageln!("See `examples/config.yaml` for an example of configuration file"); return ExitCode::FAILURE; } Ok(Ok(pics)) => if render_gallery(pics, full_build).is_err() { @@ -99,8 +97,9 @@ fn render_gallery( pics: Vec<GalleryEntry>, full_build: bool ) -> Result<(), ()> { - info!("Copying image files to the target directory..."); + let start = Instant::now(); + // ======================================================================== for pic in &pics { let mut target_path = PathBuf::from(TARGET_PATH); target_path.push(IMAGES_PATH); @@ -109,7 +108,7 @@ fn render_gallery( copy(&pic.path, &target_path)?; } - info_done!(); + infoln!("Copied image files to the target directory"); // ======================================================================== for pic in &pics { @@ -129,17 +128,15 @@ fn render_gallery( ); let (sender, reciever) = mpsc::channel(); - infoln!( "Started generating thumbnails (using {num_threads} threads)"); + infoln!("Rendering thumbnails... (using {num_threads} threads)"); + let mut thumbs_logger = JobListLogger::new(pics.len()); let mut render_pool_count = 0; - for pic in &pics { + for (id, pic) in pics.iter().enumerate() { let thumb_path: PathBuf = ThumbPath(pic).into(); if !full_build && !needs_rebuild(pic, &thumb_path) { - warnln!( - "Skipped rendering the thumbnail for {:?} (use {FULL_BUILD_OPT} to overwrite)", - pic.file_name, - ); + thumbs_logger.job_skipped(&pic.file_name); continue; } @@ -149,8 +146,9 @@ fn render_gallery( let pic = pic.clone(); rendering_pool.execute(move || { - sender.send(render_thumbnail(pic, &thumb_path)) - .expect("channel should still be alive awaiting for the completion of this task"); + // NOTE: we need to send the picture id back so that the main thread + // knows how to log the fact we finished rendering it + let _ = sender.send(render_thumbnail(&pic, &thumb_path).map(|()| id)); }); } @@ -159,26 +157,36 @@ fn render_gallery( // propagate the panic to the main thread: reciever.recv should // only fail if some of the rendering threads panicked if msg.is_err() { panic!("rendering thread panicked!"); } - msg.unwrap()?; - } - infoln!("Done generating thumbnails!"); + let job_id = msg.unwrap()?; + let pic = &pics[job_id]; + thumbs_logger.job_started_and_finished(&pic.file_name); + } + drop(thumbs_logger); // ======================================================================== - info!("Rendering index.html..."); - render_index(&pics).map_err(|_| ())?; - info_done!(); + infoln!("Rendering HTML files..."); + let mut pages_logger = JobListLogger::new(1 + pics.len()); + + pages_logger.job_started("index page"); + render_index(&pics).map_err(|_| ())?; + pages_logger.job_finished(); for pic in pics { let mut path = PathBuf::from(TARGET_PATH); path.push(PAGES_PATH); path.push(pic.file_name.clone() + ".html"); - if !full_build && !needs_rebuild(&pic, &path) { continue; } - info!("Rendering HTML page for {name:?}...", name = pic.file_name); - render_pic_page(&pic, &path).map_err(|_| ())?; + if !full_build && !needs_rebuild(&pic, &path) { + pages_logger.job_skipped(&pic.file_name); + continue; + } + pages_logger.job_started(&pic.file_name); + render_pic_page(&pic, &path).map_err(|_| ())?; + pages_logger.job_finished(); } + log::finished(start.elapsed()); Ok(()) } @@ -209,6 +217,7 @@ fn render_index(pics: &Vec) -> io::Result<()> { writeln!(f, "<body>")?; writeln!(f, "<main>")?; + const INTRO_MSG: &str = include_str!("intro.html"); writeln!(f, "{}", INTRO_MSG)?; writeln!(f, "<div id=\"gallery\" role=\"feed\">")?; @@ -231,6 +240,7 @@ fn render_index(pics: &Vec) -> io::Result<()> { writeln!(f, "</div>")?; + const OUTRO_MSG: &str = include_str!("outro.html"); writeln!(f, "{}", OUTRO_MSG)?; writeln!(f, "</main>")?; @@ -401,7 +411,7 @@ fn write_license(f: &mut File) -> io::Result<()> { ) } -fn render_thumbnail(pic: GalleryEntry, thumb_path: &Path) -> Result<(), ()> { +fn render_thumbnail(pic: &GalleryEntry, thumb_path: &Path) -> Result<(), ()> { match pic.file_format { FileFormat::TeX => { // tikztosvg -o thumb_path @@ -425,7 +435,7 @@ fn render_thumbnail(pic: GalleryEntry, thumb_path: &Path) -> Result<(), ()> { "-l", "arrows", "-q", ]) - .arg(pic.path); + .arg(&pic.path); let exit_code = tikztosvg_cmd .status() @@ -482,7 +492,6 @@ fn render_thumbnail(pic: GalleryEntry, thumb_path: &Path) -> Result<(), ()> { } } - infoln!("Rendered thumbnail for {name:?}", name = pic.file_name); Ok(()) } @@ -508,6 +517,20 @@ fn copy(from: &Path, to: &Path) -> Result<(), ()> { .map_err(|e| errorln!("Failed to copy {from:?} to {to:?}: {e}")) } +fn log_floor(n: usize) -> usize { + if n == 0 { return 1; } + + let mut d = 0; + let mut m = n; + + while m > 0 { + d += 1; + m /= 10; + } + + d +} + impl Display for ThumbPath<'_> { fn fmt(&self, f: &mut fmt::Formatter<'_>) -> Result<(), fmt::Error> { write!(f, "/{THUMBS_PATH}/{name}", name = Escaped(&self.0.file_name))?;