diff --git a/Cargo.lock b/Cargo.lock index bf0c5cb..7f29ed1 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -258,7 +258,7 @@ dependencies = [ [[package]] name = "builder" -version = "0.1.25" +version = "0.1.26" dependencies = [ "builder-assemble", "builder-command", @@ -277,7 +277,7 @@ dependencies = [ [[package]] name = "builder-assemble" -version = "0.1.25" +version = "0.1.26" dependencies = [ "base64", "builder-command", @@ -289,14 +289,15 @@ dependencies = [ [[package]] name = "builder-command" -version = "0.1.25" +version = "0.1.26" dependencies = [ "camino-fs", + "log", ] [[package]] name = "builder-copy" -version = "0.1.25" +version = "0.1.26" dependencies = [ "builder-command", "common", @@ -305,7 +306,7 @@ dependencies = [ [[package]] name = "builder-fontforge" -version = "0.1.25" +version = "0.1.26" dependencies = [ "builder-command", "camino-fs", @@ -316,7 +317,7 @@ dependencies = [ [[package]] name = "builder-localized" -version = "0.1.25" +version = "0.1.26" dependencies = [ "builder-command", "camino-fs", @@ -327,7 +328,7 @@ dependencies = [ [[package]] name = "builder-sass" -version = "0.1.25" +version = "0.1.26" dependencies = [ "builder-command", "common", @@ -339,26 +340,28 @@ dependencies = [ [[package]] name = "builder-swift-package" -version = "0.1.25" +version = "0.1.26" dependencies = [ "builder-command", "common", + "log", "swift-package", ] [[package]] name = "builder-uniffi" -version = "0.1.25" +version = "0.1.26" dependencies = [ "builder-command", "camino-fs", + "common", "log", "uniffi_bindgen", ] [[package]] name = "builder-wasm" -version = "0.1.25" +version = "0.1.26" dependencies = [ "anyhow", "base64", @@ -572,7 +575,7 @@ checksum = "b05b61dc5112cbb17e4b6cd61790d9845d13888356391624cbe7e41efeac1e75" [[package]] name = "common" -version = "0.1.25" +version = "0.1.26" dependencies = [ "anyhow", "base64", diff --git a/Cargo.toml b/Cargo.toml index b2671be..ba7195b 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -5,7 +5,7 @@ resolver = "2" members = ["crates/*"] [workspace.package] -version = "0.1.25" +version = "0.1.26" repository = "https://github.com/human-solutions/builder" license = "MIT" edition = "2024" diff --git a/crates/assemble/src/lib.rs b/crates/assemble/src/lib.rs index a6d079d..a0c4375 100644 --- a/crates/assemble/src/lib.rs +++ b/crates/assemble/src/lib.rs @@ -8,25 +8,31 @@ use asset_ext::AssetExt; use builder_command::AssembleCmd; use camino_fs::*; use common::site_fs::parse_site; +use common::{Timer, log_command, log_operation, log_trace}; use generator::generate_code; use std::process::Command; use tempfile::NamedTempFile; pub fn run(cmd: &AssembleCmd) { - log::info!("Running builder-assemble"); + let _timer = Timer::new("ASSEMBLE processing"); + log_command!("ASSEMBLE", "Processing site root: {}", cmd.site_root); let assets = parse_site(&cmd.site_root).unwrap(); + log_operation!("ASSEMBLE", "Found {} assets", assets.len()); let out = generate_code(&assets); + log_operation!("ASSEMBLE", "Generated {} bytes of code", out.len()); let tmp_file = NamedTempFile::new().unwrap(); let tmp_path = Utf8PathBuf::from_path(tmp_file.path()).unwrap(); tmp_path.write(out).unwrap(); - log::debug!("Formatting {tmp_path}"); + log_operation!("ASSEMBLE", "Formatting generated code with rustfmt"); let status = Command::new("rustfmt").arg(&tmp_path).status().unwrap(); if !status.success() { - log::warn!("Failed to format {tmp_path}"); + common::warn_cargo!("ASSEMBLE: rustfmt failed, using unformatted code"); + } else { + log_operation!("ASSEMBLE", "Code formatting successful"); } let formatted = tmp_path.read_bytes().unwrap(); @@ -34,11 +40,16 @@ pub fn run(cmd: &AssembleCmd) { if code_file.exists() { let current = code_file.read_bytes().unwrap(); if current == formatted { - log::info!("No change detected, skipping {}", code_file); + log_command!("ASSEMBLE", "No changes detected, skipping code file write"); return; } - } else if let Some(parent) = code_file.parent() { - parent.mkdirs().unwrap(); + log_operation!("ASSEMBLE", "Code file changed, updating: {}", code_file); + } else { + if let Some(parent) = code_file.parent() { + log_trace!("ASSEMBLE", "Creating parent directory: {}", parent); + parent.mkdirs().unwrap(); + } + log_operation!("ASSEMBLE", "Creating new code file: {}", code_file); } code_file.write(formatted).unwrap(); } @@ -46,7 +57,12 @@ pub fn run(cmd: &AssembleCmd) { let mut envs = assets.iter().map(|a| a.url_const()).collect::>(); envs.sort(); - log::info!("Writing URL envs to {url_env_file}"); + log_operation!( + "ASSEMBLE", + "Writing {} URL constants to: {}", + envs.len(), + url_env_file + ); url_env_file.write(envs.join("\n")).unwrap(); } } diff --git a/crates/builder/src/main.rs b/crates/builder/src/main.rs index 598841a..9bf384d 100644 --- a/crates/builder/src/main.rs +++ b/crates/builder/src/main.rs @@ -3,7 +3,7 @@ use std::env; use builder_command::{BuilderCmd, Cmd}; use camino_fs::*; -use common::{RELEASE, VERBOSE, setup_logging}; +use common::{LOG_LEVEL, RELEASE, setup_logging}; fn main() { let args = std::env::args().collect::>(); @@ -22,8 +22,8 @@ fn main() { RELEASE.set(builder.release).unwrap(); - setup_logging(builder.verbose); - VERBOSE.set(builder.verbose).unwrap(); + setup_logging(builder.log_level, builder.log_destination.clone()); + LOG_LEVEL.set(builder.log_level).unwrap(); let bin_version = env!("CARGO_PKG_VERSION"); let metadata = cargo_metadata::MetadataCommand::new().exec().unwrap(); diff --git a/crates/command/Cargo.toml b/crates/command/Cargo.toml index 8e61066..feac514 100644 --- a/crates/command/Cargo.toml +++ b/crates/command/Cargo.toml @@ -10,3 +10,4 @@ version.workspace = true [dependencies] camino-fs.workspace = true +log.workspace = true diff --git a/crates/command/src/lib.rs b/crates/command/src/lib.rs index fe50826..4ffa3e0 100644 --- a/crates/command/src/lib.rs +++ b/crates/command/src/lib.rs @@ -15,6 +15,7 @@ use camino_fs::Utf8PathBuf; pub use copy::CopyCmd; pub use fontforge::FontForgeCmd; pub use localized::LocalizedCmd; +use log::LevelFilter; pub use out::{Encoding, Output}; pub use sass::SassCmd; use std::fs; @@ -22,9 +23,35 @@ pub use swift_package::SwiftPackageCmd; pub use uniffi::UniffiCmd; pub use wasm::{DebugSymbolsMode, Profile, WasmProcessingCmd}; +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub enum LogLevel { + Normal, // Info level + enhanced summaries + Verbose, // Debug + detailed operations + Trace, // Everything including file-level operations +} + +#[derive(Debug, Clone, PartialEq, Eq)] +pub enum LogDestination { + Cargo, // via cargo::warning + File(Utf8PathBuf), // given a path + Terminal, // standard output + TerminalPlain, // standard output, designed for when run in a Command that adds it's own prefixes to the logs +} + +impl LogLevel { + pub fn to_level_filter(self) -> LevelFilter { + match self { + LogLevel::Normal => LevelFilter::Info, + LogLevel::Verbose => LevelFilter::Debug, + LogLevel::Trace => LevelFilter::Trace, + } + } +} + #[derive(Debug, PartialEq)] pub struct BuilderCmd { - pub verbose: bool, + pub log_level: LogLevel, + pub log_destination: LogDestination, pub release: bool, /// The directory where the builder.toml file is located /// Defaults to env OUT_DIR @@ -41,9 +68,16 @@ impl Default for BuilderCmd { impl BuilderCmd { pub fn new() -> Self { + let default_log_destination = if env::var("CI").is_ok() { + LogDestination::Cargo + } else { + LogDestination::Terminal + }; + Self { cmds: Vec::new(), - verbose: false, + log_level: LogLevel::Normal, + log_destination: default_log_destination, release: env::var("PROFILE").unwrap_or_default() == "release", in_cargo: env::var("CARGO").is_ok(), builder_toml: Utf8PathBuf::from( @@ -101,8 +135,13 @@ impl BuilderCmd { self } - pub fn verbose(mut self, val: bool) -> Self { - self.verbose = val; + pub fn log_level(mut self, level: LogLevel) -> Self { + self.log_level = level; + self + } + + pub fn log_destination(mut self, destination: LogDestination) -> Self { + self.log_destination = destination; self } @@ -142,9 +181,8 @@ impl BuilderCmd { } fn log(&self, msg: &str) { - if self.verbose && self.in_cargo { - println!("cargo::warning={msg}"); - } else if self.verbose { + let is_verbose = matches!(self.log_level, LogLevel::Verbose | LogLevel::Trace); + if is_verbose { println!("{msg}"); } } @@ -152,7 +190,21 @@ impl BuilderCmd { impl Display for BuilderCmd { fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { - writeln!(f, "verbose={}", self.verbose)?; + let log_level_str = match self.log_level { + LogLevel::Normal => "normal", + LogLevel::Verbose => "verbose", + LogLevel::Trace => "trace", + }; + writeln!(f, "log_level={}", log_level_str)?; + + let log_destination_str = match &self.log_destination { + LogDestination::Cargo => "cargo".to_string(), + LogDestination::File(path) => format!("file:{}", path), + LogDestination::Terminal => "terminal".to_string(), + LogDestination::TerminalPlain => "terminal_plain".to_string(), + }; + writeln!(f, "log_destination={}", log_destination_str)?; + writeln!(f, "release={}", self.release)?; writeln!(f, "builder_toml={}", self.builder_toml)?; for cmd in &self.cmds { @@ -167,10 +219,38 @@ impl FromStr for BuilderCmd { fn from_str(s: &str) -> Result { let mut lines = s.lines(); let mut builder = BuilderCmd::new(); - for line in lines.by_ref().take(3) { + for line in lines.by_ref().take(4) { let (key, value) = line.split_once('=').unwrap(); match key { - "verbose" => builder.verbose = value.parse().unwrap(), + "log_level" => { + builder.log_level = match value { + "normal" => LogLevel::Normal, + "verbose" => LogLevel::Verbose, + "trace" => LogLevel::Trace, + _ => LogLevel::Normal, + }; + } + "log_destination" => { + builder.log_destination = if let Some(path) = value.strip_prefix("file:") { + LogDestination::File(Utf8PathBuf::from(path)) + } else { + match value { + "cargo" => LogDestination::Cargo, + "terminal" => LogDestination::Terminal, + "terminal_plain" => LogDestination::TerminalPlain, + _ => LogDestination::Terminal, + } + }; + } + "verbose" => { + // Keep backward compatibility + let verbose: bool = value.parse().unwrap(); + builder.log_level = if verbose { + LogLevel::Verbose + } else { + LogLevel::Normal + }; + } "release" => builder.release = value.parse().unwrap(), "builder_toml" => builder.builder_toml = value.parse().unwrap(), _ => panic!("Unknown key: {}", key), @@ -247,7 +327,8 @@ fn roundtrip() { .add_wasm(WasmProcessingCmd::default().debug_symbols(DebugSymbolsMode::Keep)) .add_copy(CopyCmd::default()) .add_swift_package(SwiftPackageCmd::default()) - .verbose(true) + .log_level(LogLevel::Verbose) + .log_destination(LogDestination::File(camino_fs::Utf8PathBuf::from("/tmp/builder.log"))) .release(true) .builder_toml("builder.toml"); @@ -255,3 +336,24 @@ fn roundtrip() { let cmd2 = s.parse::().unwrap(); assert_eq!(cmd, cmd2); } + +#[test] +fn roundtrip_log_destinations() { + // Test all log destination variants + let destinations = [ + LogDestination::Cargo, + LogDestination::File(camino_fs::Utf8PathBuf::from("/path/to/log.txt")), + LogDestination::Terminal, + LogDestination::TerminalPlain, + ]; + + for destination in destinations { + let cmd = BuilderCmd::new() + .log_destination(destination) + .log_level(LogLevel::Normal); + + let s = cmd.to_string(); + let cmd2 = s.parse::().unwrap(); + assert_eq!(cmd, cmd2); + } +} diff --git a/crates/common/src/lib.rs b/crates/common/src/lib.rs index 0dd66fb..53c30f0 100644 --- a/crates/common/src/lib.rs +++ b/crates/common/src/lib.rs @@ -3,24 +3,35 @@ mod ext; pub mod out; pub mod site_fs; -use log::LevelFilter; +use builder_command::{LogDestination, LogLevel}; +use log::{Log, Metadata, Record}; use simplelog::{ - ColorChoice, Config as LogConfig, ConfigBuilder, TermLogger, TerminalMode, format_description, + ColorChoice, ConfigBuilder, TermLogger, TerminalMode, WriteLogger, format_description, }; -use std::env; +use std::fs::OpenOptions; use std::sync::OnceLock; +use time::OffsetDateTime; pub use envargs::CargoEnv; pub use ext::RustNaming; pub static RELEASE: OnceLock = OnceLock::new(); -pub static VERBOSE: OnceLock = OnceLock::new(); +pub static LOG_LEVEL: OnceLock = OnceLock::new(); pub fn is_release() -> bool { RELEASE.get().copied().unwrap_or(false) } + +pub fn log_level() -> LogLevel { + LOG_LEVEL.get().copied().unwrap_or(LogLevel::Normal) +} + pub fn is_verbose() -> bool { - VERBOSE.get().copied().unwrap_or(false) + matches!(log_level(), LogLevel::Verbose | LogLevel::Trace) +} + +pub fn is_trace() -> bool { + matches!(log_level(), LogLevel::Trace) } #[allow(unused_imports)] @@ -31,37 +42,175 @@ use log::{debug, info, warn}; #[cfg(test)] use std::{println as info, println as warn, println as debug}; // Workaround to use prinltn! for logs. -pub fn setup_logging(verbose: bool) { - let log_level = if verbose { - LevelFilter::Debug - } else { - LevelFilter::Info +pub struct Timer { + start: OffsetDateTime, + name: String, +} + +impl Timer { + pub fn new(name: &str) -> Self { + Self { + start: OffsetDateTime::now_utc(), + name: name.to_string(), + } + } + + pub fn elapsed_ms(&self) -> i64 { + (OffsetDateTime::now_utc() - self.start) + .whole_milliseconds() + .try_into() + .unwrap_or(i64::MAX) + } + + pub fn log_completion(&self) { + let elapsed = self.elapsed_ms(); + log::info!( + "Completed {} ({}.{}s)", + self.name, + elapsed / 1000, + elapsed % 1000 / 100 + ); + } +} + +impl Drop for Timer { + fn drop(&mut self) { + if is_verbose() { + self.log_completion(); + } + } +} + +#[macro_export] +macro_rules! log_command { + ($cmd:expr, $msg:expr) => { + log::info!("[{}] {}", $cmd, $msg) + }; + ($cmd:expr, $fmt:expr, $($arg:tt)*) => { + log::info!("[{}] {}", $cmd, format!($fmt, $($arg)*)) + }; +} + +#[macro_export] +macro_rules! log_operation { + ($cmd:expr, $msg:expr) => { + log::debug!("[{}] {}", $cmd, $msg) + }; + ($cmd:expr, $fmt:expr, $($arg:tt)*) => { + log::debug!("[{}] {}", $cmd, format!($fmt, $($arg)*)) + }; +} + +#[macro_export] +macro_rules! log_trace { + ($cmd:expr, $msg:expr) => { + log::trace!("[{}] {}", $cmd, $msg) + }; + ($cmd:expr, $fmt:expr, $($arg:tt)*) => { + log::trace!("[{}] {}", $cmd, format!($fmt, $($arg)*)) + }; +} + +/// Log a warning that should use cargo::warning when running under cargo +#[macro_export] +macro_rules! warn_cargo { + ($fmt:expr, $($arg:tt)*) => { + if std::env::var("CARGO").is_ok() { + println!("cargo::warning={}", format!($fmt, $($arg)*)); + } else { + log::warn!($fmt, $($arg)*); + } + }; + ($msg:expr) => { + if std::env::var("CARGO").is_ok() { + println!("cargo::warning={}", $msg); + } else { + log::warn!("{}", $msg); + } }; +} + +/// Custom logger that routes log messages through cargo's warning system +struct CargoLogger { + level: log::LevelFilter, +} + +impl CargoLogger { + fn new(level: log::LevelFilter) -> Self { + Self { level } + } +} + +impl Log for CargoLogger { + fn enabled(&self, metadata: &Metadata) -> bool { + metadata.level() <= self.level + } + + fn log(&self, record: &Record) { + if self.enabled(record.metadata()) { + let level_str = match record.level() { + log::Level::Error => "ERROR", + log::Level::Warn => "WARN", + log::Level::Info => "INFO", + log::Level::Debug => "DEBUG", + log::Level::Trace => "TRACE", + }; + + // Route through cargo warning system + println!("cargo:warning=[{}] {}", level_str, record.args()); + } + } + + fn flush(&self) { + // cargo warnings are flushed automatically + } +} + +pub fn setup_logging(level: LogLevel, destination: LogDestination) { + let log_level = level.to_level_filter(); let mut log_config_builder = ConfigBuilder::new(); // Filter out walrus debug logs when in verbose mode - if verbose { + if matches!(level, LogLevel::Verbose | LogLevel::Trace) { log_config_builder.add_filter_ignore_str("walrus"); log_config_builder.add_filter_ignore_str("wasm_bindgen_cli_support"); } - let log_config = if env::var("CARGO").is_ok() && verbose { - log_config_builder - .set_time_format_custom(format_description!( - "cargo::warning=[hour]:[minute]:[second]" - )) - .build() - } else if verbose { - log_config_builder.build() - } else { - LogConfig::default() - }; + let log_config = log_config_builder + .set_time_format_custom(format_description!("[hour]:[minute]:[second]")) + .build(); + + match destination { + LogDestination::Cargo => { + // Use custom CargoLogger that routes messages through cargo warnings + let logger = Box::new(CargoLogger::new(log_level)); + let _ = log::set_boxed_logger(logger).map(|()| log::set_max_level(log_level)); + } + LogDestination::File(path) => { + let file = OpenOptions::new() + .create(true) + .append(true) + .open(path) + .expect("Could not create log file"); - let _ = TermLogger::init( - log_level, - log_config, - TerminalMode::Mixed, - ColorChoice::Auto, - ); + let _ = WriteLogger::init(log_level, log_config, file); + } + LogDestination::Terminal => { + let _ = TermLogger::init( + log_level, + log_config, + TerminalMode::Mixed, + ColorChoice::Never, + ); + } + LogDestination::TerminalPlain => { + let _ = TermLogger::init( + log_level, + log_config, + TerminalMode::Stdout, + ColorChoice::Never, + ); + } + } } diff --git a/crates/common/src/site_fs/asset.rs b/crates/common/src/site_fs/asset.rs index 463f646..8a84e02 100644 --- a/crates/common/src/site_fs/asset.rs +++ b/crates/common/src/site_fs/asset.rs @@ -48,19 +48,19 @@ impl Asset { pub fn join(&mut self, other: Self) { if self.sub_dir != other.sub_dir { - crate::warn!("Can't join assets with different subdirs {self} {other}"); + crate::warn_cargo!("Can't join assets with different subdirs {self} {other}"); return; } if self.name != other.name { - crate::warn!("Can't join assets with different names {self} {other}"); + crate::warn_cargo!("Can't join assets with different names {self} {other}"); return; } if self.ext != other.ext { - crate::warn!("Can't join assets with different extensions {self} {other}"); + crate::warn_cargo!("Can't join assets with different extensions {self} {other}"); return; } if self.hash != other.hash { - crate::warn!("Can't join assets with different hashes {self} {other}"); + crate::warn_cargo!("Can't join assets with different hashes {self} {other}"); return; } self.encodings.join(&other.encodings); @@ -94,8 +94,18 @@ impl Display for Asset { } fn parse_asset(path: &Utf8Path) -> Option { - let mut parts = path.file_name()?.split('.'); - let (name, hash, ext) = parse_name_hash_ext(&mut parts)?; + let file_name = path.file_name()?; + + // Skip hashed directories (e.g., "wasm.abc123=") - they don't have extensions + if path.is_dir() { + let parts: Vec<&str> = file_name.split('.').collect(); + if parts.len() == 2 && parts[1].ends_with('=') { + return None; + } + } + + let mut parts = file_name.split('.'); + let (name, hash, ext) = parse_name_hash_ext(&mut parts, path)?; let encodings = parse_encoding(&mut parts)?; Some(Asset { @@ -110,14 +120,23 @@ fn parse_asset(path: &Utf8Path) -> Option { fn parse_translated_asset(path: &Utf8Path) -> Option { let dir = path.parent()?; - let mut dir_parts = dir.file_name()?.split('.'); + let dir_name = dir.file_name()?; + let mut dir_parts = dir_name.split('.'); + + // For WASM and other hashed directories without extensions, handle separately + let dir_parts_vec: Vec<&str> = dir_name.split('.').collect(); + if dir_parts_vec.len() == 2 && dir_parts_vec[1].ends_with('=') { + // This is a hashed directory without extension (e.g., "wasm.abc123=") + // Not a translated asset pattern, so return None to let parse_asset handle it + return None; + } - let (name, hash, ext) = parse_name_hash_ext(&mut dir_parts)?; + let (name, hash, ext) = parse_name_hash_ext(&mut dir_parts, path)?; let mut file_parts = path.file_name()?.split('.'); let lang = parse_language(&mut file_parts)?; if file_parts.next() != Some(ext) { - crate::warn!("Translated asset dir extension doesn't match file extension {path}"); + crate::warn_cargo!("Translated asset dir extension doesn't match file extension {path}"); return None; } let encodings = parse_encoding(&mut file_parts)?; @@ -134,12 +153,15 @@ fn parse_translated_asset(path: &Utf8Path) -> Option { fn parse_name_hash_ext<'a>( parts: &mut Split<'a, char>, + path: &Utf8Path, ) -> Option<(&'a str, Option<&'a str>, &'a str)> { let name = parts.next()?; let hash_or_ext = parts.next()?; Some(if hash_or_ext.ends_with('=') { let Some(ext) = parts.next() else { - crate::warn!("No extension found after {hash_or_ext}"); + if !path.is_dir() { + crate::warn_cargo!("No extension found after '{}' for {}", hash_or_ext, path); + } return None; }; (name, Some(hash_or_ext), ext) @@ -152,8 +174,8 @@ fn parse_language(parts: &mut Split) -> Option { let lang_str = parts.next()?; match lang_str.parse() { Ok(lang) => Some(lang), - Err(e) => { - crate::warn!("Failed to parse language identifier '{lang_str}': {e}"); + Err(_e) => { + crate::warn_cargo!("Failed to parse language identifier '{lang_str}': {_e}"); None } } @@ -165,8 +187,8 @@ fn parse_encoding(parts: &mut Split) -> Option { }; match enc_str.parse() { Ok(enc) => Some(enc), - Err(e) => { - crate::warn!("Failed to parse encoding '{enc_str}': {e}"); + Err(_e) => { + crate::warn_cargo!("Failed to parse encoding '{enc_str}': {_e}"); None } } diff --git a/crates/common/src/site_fs/encoding.rs b/crates/common/src/site_fs/encoding.rs index e36b822..84813fe 100644 --- a/crates/common/src/site_fs/encoding.rs +++ b/crates/common/src/site_fs/encoding.rs @@ -1,4 +1,4 @@ -use crate::{debug, is_release, warn}; +use crate::{debug, is_release}; use std::{ io::{Cursor, Write}, str::FromStr, @@ -75,7 +75,7 @@ impl AssetEncodings { match enc { "br" => self.brotli = true, "gzip" => self.gzip = true, - _ => warn!("invalid encoding: {enc}"), + _ => crate::warn_cargo!("invalid encoding: {enc}"), } } diff --git a/crates/common/src/site_fs/mod.rs b/crates/common/src/site_fs/mod.rs index 576fe76..d08a76e 100644 --- a/crates/common/src/site_fs/mod.rs +++ b/crates/common/src/site_fs/mod.rs @@ -4,7 +4,7 @@ mod encoding; #[cfg(test)] mod tests; -use crate::debug; +use crate::{debug, is_trace, log_trace}; pub use anyhow::Result; pub use asset::Asset; pub use asset_path::{AssetPath, SiteFile, TranslatedAssetPath}; @@ -18,23 +18,36 @@ use std::{collections::BTreeMap, hash::Hasher}; pub fn parse_site(root: &Utf8Path) -> Result> { let mut assets: BTreeMap = Default::default(); + let mut file_count = 0; debug!("Parsing site {root}"); for path in root.ls().recurse() { if path.file_name() == Some(".DS_Store") { + if is_trace() { + log_trace!("SITE_FS", "Skipping .DS_Store file: {}", path); + } continue; } + file_count += 1; let rel_path = path.relative_to(root).unwrap(); - debug!("Parsing asset from {rel_path}"); + log_trace!("SITE_FS", "Parsing asset from: {}", rel_path); if let Some(asset) = Asset::from_site_path(rel_path) { let url = asset.to_url(); if let Some(current) = assets.get_mut(&url) { + log_trace!("SITE_FS", "Merging asset with existing URL: {}", url); current.join(asset); } else { + log_trace!("SITE_FS", "New asset URL: {}", url); assets.insert(url, asset); } } } + + debug!( + "Parsed {} files into {} unique assets from site root", + file_count, + assets.len() + ); Ok(assets.into_values().collect()) } @@ -46,16 +59,34 @@ pub fn copy_files_to_site bool>( predicate: F, output: &[Output], ) { + let mut copied_count = 0; + let mut total_size = 0u64; + for file in folder.ls().recurse_if(move |_| recursive).filter(predicate) { if !file.is_file() { - debug!("Skipping non-file {file}"); + log_trace!("SITE_FS", "Skipping non-file: {}", file); continue; } let bytes = file.read_bytes().unwrap(); + total_size += bytes.len() as u64; let rel_path = file.relative_to(folder).unwrap(); let site_file = SiteFile::from_relative_path(rel_path); - debug!("Copying {file} to {site_file}"); + log_trace!( + "SITE_FS", + "Copying {} ({} bytes) to {}", + file, + bytes.len(), + site_file + ); write_file_to_site(&site_file, &bytes, output); + copied_count += 1; + } + + if copied_count > 0 { + debug!( + "Copied {} files ({} bytes total) from {}", + copied_count, total_size, folder + ); } } @@ -92,12 +123,19 @@ pub fn write_file_to_site(site_file: &SiteFile, bytes: &[u8], output: &[Output]) .unwrap_or(false) }) .for_each(|f| { - log::debug!("Removing file: {f}"); + log_trace!("SITE_FS", "Removing existing file: {}", f); f.rm().unwrap(); }); let path = asset.absolute_path(&out.dir); let encodings = AssetEncodings::from_output(out); + log_trace!( + "SITE_FS", + "Writing file: {} ({} bytes, encodings: {:?})", + path, + bytes.len(), + encodings + ); encodings.write(&path, bytes).unwrap() } } diff --git a/crates/copy/src/lib.rs b/crates/copy/src/lib.rs index 10dfa80..6a121b5 100644 --- a/crates/copy/src/lib.rs +++ b/crates/copy/src/lib.rs @@ -1,11 +1,15 @@ use builder_command::CopyCmd; +use common::{Timer, log_command, log_operation}; use common::site_fs::copy_files_to_site; pub fn run(cmd: &CopyCmd) { - log::info!("Running builder-copy"); + let _timer = Timer::new("COPY processing"); + log_command!("COPY", "Copying files from: {}", cmd.src_dir); + log_operation!("COPY", "Recursive: {}, Extensions: {:?}", cmd.recursive, cmd.file_extensions); + log_operation!("COPY", "Output destinations: {}", cmd.output.len()); if !cmd.src_dir.exists() { - log::warn!("Directory not found: {}", cmd.src_dir); + log_command!("COPY", "Source directory not found: {}", cmd.src_dir); return; } diff --git a/crates/fontforge/src/lib.rs b/crates/fontforge/src/lib.rs index cba8352..e72e5f1 100644 --- a/crates/fontforge/src/lib.rs +++ b/crates/fontforge/src/lib.rs @@ -2,52 +2,67 @@ use std::process::Command; use builder_command::FontForgeCmd; use camino_fs::*; +use common::{Timer, log_command, log_operation, log_trace}; use common::site_fs::{SiteFile, write_file_to_site}; pub fn run(cmd: &FontForgeCmd) { - log::info!("Running builder-fontforge"); + let _timer = Timer::new("FONTFORGE processing"); let sfd_file = Utf8Path::new(&cmd.font_file); let sum_file = sfd_file.with_extension("hash"); let name = sfd_file.file_stem().unwrap(); + log_command!("FONTFORGE", "Processing font file: {}", sfd_file); + log_operation!("FONTFORGE", "Output destinations: {}", cmd.output.len()); + if !sfd_file.exists() { - panic!("File not found: {:?}", sfd_file); + panic!("Font file not found: {:?}", sfd_file); } + let sfd_bytes = sfd_file.read_bytes().unwrap(); let hash = format!("{:x}", seahash::hash(&sfd_bytes)); + log_operation!("FONTFORGE", "Font file hash: {} ({} bytes)", hash, sfd_bytes.len()); let sfd_dir = sfd_file.parent().unwrap(); let generate_woff2 = if sum_file.exists() { - log::debug!("Reading hash from {sum_file}"); + log_trace!("FONTFORGE", "Checking existing hash file: {}", sum_file); let current_hash = sum_file.read_string().unwrap(); - hash != current_hash + let needs_regeneration = hash != current_hash; + if needs_regeneration { + log_operation!("FONTFORGE", "Hash changed, regeneration needed"); + } else { + log_operation!("FONTFORGE", "Hash unchanged, skipping regeneration"); + } + needs_regeneration } else { + log_operation!("FONTFORGE", "No hash file found, initial generation needed"); true }; if generate_woff2 { generate_woff2_otf(sfd_dir, name); - log::debug!("Writing hash to {sum_file}"); + log_trace!("FONTFORGE", "Writing hash to: {}", sum_file); sum_file.write(hash).unwrap(); let otf_file = sfd_dir.join(name).with_extension("otf"); // copy otf file to font directory (only macos) if cfg!(target_os = "macos") { + log_operation!("FONTFORGE", "Installing font to macOS system (target_os=macos)"); macos_install_font(&otf_file, name); } + log_trace!("FONTFORGE", "Removing temporary OTF file: {}", otf_file); otf_file.rm().unwrap(); - log::info!("Removed {otf_file}"); } else { - log::info!("No change detected, skipping {sfd_file}"); + log_command!("FONTFORGE", "No changes detected, skipping generation"); } let woff2_filename = format!("{name}.woff2"); - let bytes = sfd_dir.join(&woff2_filename).read_bytes().unwrap(); + let woff2_path = sfd_dir.join(&woff2_filename); + let bytes = woff2_path.read_bytes().unwrap(); - log::info!("Generating output for {name}"); + log_operation!("FONTFORGE", "Writing WOFF2 output: {} ({} bytes)", woff2_filename, bytes.len()); let site_file = SiteFile::new(name, "woff2"); write_file_to_site(&site_file, &bytes, &cmd.output); } @@ -55,7 +70,9 @@ pub fn run(cmd: &FontForgeCmd) { fn generate_woff2_otf(sfd_dir: &Utf8Path, name: &str) { let ff = format!("Open('{name}.sfd'); Generate('{name}.woff2'); Generate('{name}.otf')"); - log::info!("Generating {name}.woff2 and {name}.otf from {name}.sfd"); + log_operation!("FONTFORGE", "Generating {}.woff2 and {}.otf from {}.sfd", name, name, name); + log_trace!("FONTFORGE", "FontForge command: {}", ff); + let cmd = Command::new("fontforge") .args(["-lang=ff", "-c", &ff]) .current_dir(sfd_dir) @@ -63,16 +80,20 @@ fn generate_woff2_otf(sfd_dir: &Utf8Path, name: &str) { .unwrap(); if !cmd.success() { - panic!("installed binary fontforge failed") + panic!("FontForge command failed") } + + log_operation!("FONTFORGE", "FontForge generation completed successfully"); } fn macos_install_font(otf_file: &Utf8Path, name: &str) { - log::info!("Copying polygot.otf to ~/Library/Fonts"); let home = std::env::var("HOME").unwrap(); let dest = Utf8Path::new(&home) .join("Library/Fonts") .join(name) .with_extension("otf"); - otf_file.cp(dest).unwrap(); + + log_trace!("FONTFORGE", "Installing font: {} -> {}", otf_file, dest); + otf_file.cp(&dest).unwrap(); + log_operation!("FONTFORGE", "Font installed to macOS Library/Fonts"); } diff --git a/crates/localized/src/lib.rs b/crates/localized/src/lib.rs index 2fd7a05..4594f77 100644 --- a/crates/localized/src/lib.rs +++ b/crates/localized/src/lib.rs @@ -3,18 +3,34 @@ mod tests; use builder_command::LocalizedCmd; use camino_fs::*; +use common::{Timer, log_command, log_operation, log_trace}; use common::site_fs::write_translations; use icu_locid::LanguageIdentifier; pub fn run(cmd: &LocalizedCmd) { - log::info!("Running builder-localized"); + let _timer = Timer::new("LOCALIZED processing"); + log_command!("LOCALIZED", "Processing localized files from: {}", cmd.input_dir); + log_operation!("LOCALIZED", "File extension: {}, Output destinations: {}", cmd.file_extension, cmd.output.len()); let variants = get_variants(cmd); + log_operation!("LOCALIZED", "Found {} language variants", variants.len()); + + if variants.is_empty() { + log_command!("LOCALIZED", "No matching files found, skipping processing"); + return; + } + + for (lang, content) in &variants { + log_trace!("LOCALIZED", "Variant: {} ({} bytes)", lang, content.len()); + } + let name = format!( "{name}.{ext}", name = cmd.input_dir.file_name().unwrap(), ext = cmd.file_extension ); + + log_operation!("LOCALIZED", "Writing translations as: {}", name); write_translations(&name, &variants, &cmd.output); } @@ -32,7 +48,10 @@ fn get_variants(cmd: &LocalizedCmd) -> Vec<(LanguageIdentifier, Vec)> { let loc = file.file_stem().unwrap(); let langid: LanguageIdentifier = loc.parse().unwrap(); let content = file.read_bytes().unwrap(); + log_trace!("LOCALIZED", "Processing file: {} -> language: {}", file, langid); variants.push((langid, content)); + } else if file.is_file() { + log_trace!("LOCALIZED", "Skipping file (extension mismatch): {}", file); } } diff --git a/crates/sass/src/lib.rs b/crates/sass/src/lib.rs index b735ffa..38579ec 100644 --- a/crates/sass/src/lib.rs +++ b/crates/sass/src/lib.rs @@ -1,5 +1,6 @@ use builder_command::SassCmd; use common::site_fs::{SiteFile, write_file_to_site}; +use common::{Timer, log_command, log_operation, log_trace}; use lightningcss::{ printer::PrinterOptions, stylesheet::StyleSheet, @@ -9,10 +10,17 @@ use std::process::Command; use which::which; pub fn run(sass_cmd: &SassCmd) { - log::info!("Running builder-sass on {}", sass_cmd.in_scss); + let _timer = Timer::new("SASS processing"); + log_command!("SASS", "Processing file: {}", sass_cmd.in_scss); + log_operation!( + "SASS", + "Optimize: {}, Replacements: {}", + sass_cmd.optimize, + sass_cmd.replacements.len() + ); let mut css = if let Ok(sass) = which("sass") { - log::debug!("Compiling sass with {sass:?}"); + log_operation!("SASS", "Compiling with external sass binary: {:?}", sass); let cmd = Command::new(sass) .args([ @@ -26,21 +34,42 @@ pub fn run(sass_cmd: &SassCmd) { let err = String::from_utf8(cmd.stderr).unwrap(); if !cmd.status.success() { - panic!("installed binary sass failed: {err}{out}") + panic!("External sass binary failed: {err}{out}") } + log_operation!( + "SASS", + "External sass compilation successful ({} bytes)", + out.len() + ); out } else { - log::debug!("No installed sass compiler found. Compiling with builtin grass compiler"); - grass::from_path(&sass_cmd.in_scss, &Default::default()).unwrap() + log_operation!( + "SASS", + "Using built-in grass compiler (no external sass found)" + ); + let css = grass::from_path(&sass_cmd.in_scss, &Default::default()).unwrap(); + log_operation!("SASS", "Grass compilation successful ({} bytes)", css.len()); + css }; - for (from, to) in &sass_cmd.replacements { - css = css.replace(from, to); + if !sass_cmd.replacements.is_empty() { + let original_len = css.len(); + for (from, to) in &sass_cmd.replacements { + css = css.replace(from, to); + log_trace!("SASS", "Replacement: '{}' -> '{}'", from, to); + } + log_operation!( + "SASS", + "Applied {} replacements ({} -> {} bytes)", + sass_cmd.replacements.len(), + original_len, + css.len() + ); } let site_file = SiteFile::new(sass_cmd.in_scss.file_stem().unwrap(), "css"); if sass_cmd.optimize { - log::info!("Optimizing css"); + log_operation!("SASS", "Optimizing CSS with Lightning CSS"); let stylesheet = StyleSheet::parse(&css, Default::default()).unwrap(); @@ -52,6 +81,7 @@ pub fn run(sass_cmd: &SassCmd) { ..Default::default() }; + let original_size = css.len(); let out_css = stylesheet .to_css(PrinterOptions { minify: true, @@ -59,8 +89,19 @@ pub fn run(sass_cmd: &SassCmd) { ..Default::default() }) .unwrap(); + + let savings = + ((original_size - out_css.code.len()) as f64 / original_size as f64 * 100.0) as i32; + log_operation!( + "SASS", + "CSS optimization complete: {} -> {} bytes ({}% reduction)", + original_size, + out_css.code.len(), + savings + ); write_file_to_site(&site_file, out_css.code.as_bytes(), &sass_cmd.output); } else { + log_operation!("SASS", "Writing unoptimized CSS ({} bytes)", css.len()); write_file_to_site(&site_file, css.as_bytes(), &sass_cmd.output); } } diff --git a/crates/swift_package/Cargo.toml b/crates/swift_package/Cargo.toml index 2efb592..d250906 100644 --- a/crates/swift_package/Cargo.toml +++ b/crates/swift_package/Cargo.toml @@ -11,4 +11,5 @@ authors.workspace = true builder-command = { path = "../command" } common = { path = "../common" } +log.workspace = true swift-package.workspace = true diff --git a/crates/swift_package/src/lib.rs b/crates/swift_package/src/lib.rs index 52f5320..8eba441 100644 --- a/crates/swift_package/src/lib.rs +++ b/crates/swift_package/src/lib.rs @@ -1,14 +1,22 @@ use builder_command::SwiftPackageCmd; -use common::{is_release, is_verbose}; +use common::{is_release, is_verbose, Timer, log_command, log_operation}; use swift_package::{CliArgs, build_cli}; pub fn run(cmd: &SwiftPackageCmd) { + let _timer = Timer::new("SWIFT_PACKAGE processing"); + log_command!("SWIFT_PACKAGE", "Building Swift package from: {}", cmd.manifest_dir); + + let verbose_level = if is_verbose() { 1 } else { 0 }; + let release_mode = is_release(); + + log_operation!("SWIFT_PACKAGE", "Configuration: release={}, verbose={}", release_mode, verbose_level > 0); + let cli = CliArgs { quiet: false, package: None, - verbose: if is_verbose() { 1 } else { 0 }, + verbose: verbose_level, unstable_flags: None, - release: is_release(), + release: release_mode, profile: None, features: vec![], all_features: false, @@ -16,5 +24,8 @@ pub fn run(cmd: &SwiftPackageCmd) { target_dir: None, manifest_path: Some(cmd.manifest_dir.clone()), }; - build_cli(cli).unwrap() + + log_operation!("SWIFT_PACKAGE", "Executing swift-package build command"); + build_cli(cli).unwrap(); + log_operation!("SWIFT_PACKAGE", "Swift package build completed successfully"); } diff --git a/crates/uniffi/Cargo.toml b/crates/uniffi/Cargo.toml index 12cf833..1870fd3 100644 --- a/crates/uniffi/Cargo.toml +++ b/crates/uniffi/Cargo.toml @@ -9,6 +9,7 @@ version.workspace = true [dependencies] builder-command = { path = "../command" } +common = { path = "../common" } camino-fs.workspace = true log.workspace = true diff --git a/crates/uniffi/src/lib.rs b/crates/uniffi/src/lib.rs index 5b53c6e..bcad08d 100644 --- a/crates/uniffi/src/lib.rs +++ b/crates/uniffi/src/lib.rs @@ -1,16 +1,23 @@ use builder_command::UniffiCmd; use camino_fs::*; +use common::{Timer, log_command, log_operation, log_trace}; use uniffi_bindgen::{ bindings::{KotlinBindingGenerator, SwiftBindingGenerator}, generate_external_bindings, }; pub fn run(cmd: &UniffiCmd) { - log::info!("Running builder-uniffi"); - + let _timer = Timer::new("UNIFFI processing"); + log_command!("UNIFFI", "Processing library: {}", cmd.library_name); + log_operation!("UNIFFI", "UDL file: {}", cmd.udl_file); + log_operation!("UNIFFI", "Output directory: {}", cmd.out_dir); + log_operation!("UNIFFI", "Kotlin: {}, Swift: {}", cmd.kotlin, cmd.swift); + let udl_copy = cmd.out_dir.join(cmd.udl_file.file_name().unwrap()); let cli_copy = cmd.out_dir.join("self.json"); let conf_copy = cmd.out_dir.join("uniffi.toml"); + + log_trace!("UNIFFI", "Checking cache files: udl={}, cli={}, config={}", udl_copy, cli_copy, conf_copy); if udl_copy.exists() && cli_copy.exists() { let udl_ref_bytes = udl_copy.read_bytes().unwrap(); @@ -31,45 +38,48 @@ pub fn run(cmd: &UniffiCmd) { match (is_udl_same, is_cli_same, is_config_same) { (true, true, true) => { - log::info!( - "No changes to UDL file, cli params, or config file, skipping generation" - ); + log_command!("UNIFFI", "No changes detected, skipping generation"); return; } (false, _, _) => { - log::info!("UDL file changed, regenerating bindings"); + log_operation!("UNIFFI", "UDL file changed, regenerating bindings"); } (_, false, _) => { - log::info!("CLI params changed, regenerating bindings"); + log_operation!("UNIFFI", "CLI parameters changed, regenerating bindings"); } (_, _, false) => { - log::info!("Config file changed, regenerating bindings"); + log_operation!("UNIFFI", "Configuration file changed, regenerating bindings"); } } + } else { + log_operation!("UNIFFI", "First time processing, setting up cache files"); } + + log_operation!("UNIFFI", "Setting up output directory and cache files"); cmd.out_dir.mkdirs().unwrap(); cmd.udl_file.cp(&udl_copy).unwrap(); if let Some(config_file) = &cmd.config_file { + log_trace!("UNIFFI", "Copying config file: {}", config_file); config_file.cp(&conf_copy).unwrap(); } cli_copy.write(cmd.to_string()).unwrap(); if cmd.kotlin { - log::info!("Generating Kotlin bindings for {}", cmd.library_name); + log_operation!("UNIFFI", "Generating Kotlin bindings for library: {}", cmd.library_name); generate_external_bindings( &KotlinBindingGenerator, &cmd.udl_file, cmd.config_file.as_ref(), Some(&cmd.out_dir), - // None::<&Utf8PathBuf>, Some(cmd.built_lib_file.clone()), Some(&cmd.library_name), true, ) .unwrap(); + log_operation!("UNIFFI", "Kotlin bindings generation completed"); } if cmd.swift { - log::info!("Generating Swift bindings for {}", cmd.library_name); + log_operation!("UNIFFI", "Generating Swift bindings for library: {}", cmd.library_name); generate_external_bindings( &SwiftBindingGenerator, &cmd.udl_file, @@ -80,7 +90,9 @@ pub fn run(cmd: &UniffiCmd) { false, ) .unwrap(); + log_operation!("UNIFFI", "Fixing Swift modulemap file"); fix_modulemap_file(&cmd.out_dir); + log_operation!("UNIFFI", "Swift bindings generation completed"); } } @@ -92,6 +104,8 @@ fn fix_modulemap_file(out_dir: &Utf8Path) { .find(|f| f.extension() == Some("modulemap")) .unwrap(); + log_trace!("UNIFFI", "Found modulemap file: {}", modulemap_file); + let modulemap = modulemap_file.read_string().unwrap(); if !modulemap.starts_with("module ") { @@ -103,4 +117,5 @@ fn fix_modulemap_file(out_dir: &Utf8Path) { new_modulemap.push_str(&modulemap); modulemap_file.write(new_modulemap.as_bytes()).unwrap(); + log_trace!("UNIFFI", "Fixed modulemap file: added 'framework' prefix"); } diff --git a/crates/wasm/src/dwarf.rs b/crates/wasm/src/dwarf.rs index f26eba4..a8f30c0 100644 --- a/crates/wasm/src/dwarf.rs +++ b/crates/wasm/src/dwarf.rs @@ -59,7 +59,7 @@ pub fn split_debug_symbols( // Write the complete module (including debug info) to the debug file log::debug!("Write _debug.wasm file {}", wasm_debug_path); module - .encode_into(BufWriter::new(File::create(&wasm_debug_path)?)) + .encode_into(BufWriter::new(File::create(wasm_debug_path)?)) .map_err(|e| anyhow::anyhow!("Failed to encode debug WASM file: {}", e))?; // Strip debug sections from main file @@ -68,10 +68,7 @@ pub fn split_debug_symbols( .sections .retain(|section| !is_strippable_section(section, true)); - let is_adjacent = match (wasm_debug_path.parent(), wasm_path.parent()) { - (Some(p1), Some(p2)) if p1 == p2 => true, - _ => false, - }; + let is_adjacent = matches!((wasm_debug_path.parent(), wasm_path.parent()), (Some(p1), Some(p2)) if p1 == p2); // Add external debug info reference if we have a debug file if is_adjacent { let file_name = wasm_debug_path.file_name().unwrap().to_string(); diff --git a/crates/wasm/src/lib.rs b/crates/wasm/src/lib.rs index 0940cd5..60553a2 100644 --- a/crates/wasm/src/lib.rs +++ b/crates/wasm/src/lib.rs @@ -5,22 +5,35 @@ use base64::{Engine, engine::general_purpose::URL_SAFE}; use builder_command::{DebugSymbolsMode, WasmProcessingCmd}; use camino_fs::*; use common::site_fs::{SiteFile, write_file_to_site}; +use common::{Timer, log_command, log_operation, log_trace}; use std::{fs::File, hash::Hasher}; use wasm_opt::OptimizationOptions; use crate::dwarf::split_debug_symbols; pub fn run(cmd: &WasmProcessingCmd) { + let _timer = Timer::new("WASM processing"); let release = matches!(cmd.profile, builder_command::Profile::Release); let package_name = cmd.package.replace("-", "_"); + log_command!( + "WASM", + "Processing package '{}' ({} mode)", + package_name, + if release { "release" } else { "debug" } + ); + log_operation!("WASM", "Debug symbols mode: {:?}", cmd.debug_symbols); + let tmp_dir = Utf8PathBuf::from("target/wasm_tmp"); + log_trace!("WASM", "Creating temp directory: {}", tmp_dir); tmp_dir.mkdir().unwrap(); let wasm_path = Utf8PathBuf::from(format!( "target/wasm32-unknown-unknown/{}/{package_name}.wasm", cmd.profile.as_target_folder() )); + log_operation!("WASM", "Source WASM path: {}", wasm_path); + let wasm_mtime = wasm_path .mtime() .with_context(|| format!("Failed to get mtime for {}", wasm_path)) @@ -30,12 +43,22 @@ pub fn run(cmd: &WasmProcessingCmd) { if wasm_mtime_path.exists() { let prev_mtime = wasm_mtime_path.mtime().unwrap(); - log::debug!("\nprev_mtime: {prev_mtime:?}, \nwasm_mtime: {wasm_mtime:?}"); + log_trace!( + "WASM", + "Previous mtime: {:?}, current mtime: {:?}", + prev_mtime, + wasm_mtime + ); if wasm_mtime == prev_mtime { - log::info!("No change detected, skipping wasmbindgen for {wasm_path}"); + log_command!("WASM", "No changes detected, skipping processing"); return; } + log_operation!("WASM", "WASM file changed, proceeding with processing"); } else { + log_operation!( + "WASM", + "First time processing, creating mtime tracking file" + ); wasm_mtime_path .write("this file has the mtime of the last time the wasm was built") .unwrap(); @@ -44,7 +67,9 @@ pub fn run(cmd: &WasmProcessingCmd) { wasm_mtime_file.set_modified(wasm_mtime).unwrap(); let keep_debug = !matches!(cmd.debug_symbols, DebugSymbolsMode::Strip); + log_operation!("WASM", "Keep debug symbols: {}", keep_debug); + log_operation!("WASM", "Generating bindings (typescript=false, web=true)"); wasm_bindgen_cli_support::Bindgen::new() .input_path(&wasm_path) .typescript(false) @@ -66,33 +91,58 @@ pub fn run(cmd: &WasmProcessingCmd) { let wasm_file_path = tmp_dir.join(format!("{package_name}_bg.wasm")); if release { + log_operation!( + "WASM", + "Running wasm-opt (size optimization, debug_info={})", + keep_debug + ); let tmp = tmp_dir.with_extension("wasm-opt.wasm"); + let original_size = wasm_file_path.metadata().unwrap().len(); + OptimizationOptions::new_optimize_for_size_aggressively() .debug_info(keep_debug) .run(&wasm_file_path, &tmp) .unwrap(); + + let optimized_size = tmp.metadata().unwrap().len(); tmp.mv(&wasm_file_path).unwrap(); + + let savings = + ((original_size - optimized_size) as f64 / original_size as f64 * 100.0) as i32; + log_operation!( + "WASM", + "Optimization complete: {} -> {} bytes ({}% reduction)", + original_size, + optimized_size, + savings + ); } // Handle debug symbols based on mode match &cmd.debug_symbols { DebugSymbolsMode::Strip => { - // Debug symbols are already stripped by wasm-bindgen (keep_debug=false) - // and wasm-opt (debug_info=false) + log_operation!("WASM", "Debug symbols stripped"); } DebugSymbolsMode::Keep => { - // Debug symbols remain in the main WASM file - no additional processing needed + log_operation!("WASM", "Debug symbols kept in main WASM file"); } DebugSymbolsMode::WriteTo(debug_path) => { + log_operation!("WASM", "Splitting debug symbols to: {}", debug_path); split_debug_symbols(&wasm_file_path, debug_path).unwrap(); } DebugSymbolsMode::WriteAdjacent => { let name = wasm_file_path.file_stem().unwrap(); let debug_path = wasm_file_path.with_file_name(format!("{name}_debug.wasm")); + log_operation!( + "WASM", + "Splitting debug symbols to adjacent file: {}", + debug_path + ); split_debug_symbols(&wasm_file_path, &debug_path).unwrap(); } } + log_operation!("WASM", "Computing checksums and collecting files"); let mut hasher = seahash::SeaHasher::new(); let file_and_content = files .into_iter() @@ -100,22 +150,43 @@ pub fn run(cmd: &WasmProcessingCmd) { let p = p.relative_to(&tmp_dir).unwrap().to_path_buf(); let content = tmp_dir.join(&p).read_bytes().unwrap(); hasher.write(&content); + log_trace!("WASM", "Processed file: {} ({} bytes)", p, content.len()); (p, content) }) .collect::>(); let hash = URL_SAFE.encode(hasher.finish().to_be_bytes()); + let total_size: usize = file_and_content + .iter() + .map(|(_, content)| content.len()) + .sum(); + log_operation!( + "WASM", + "Computed checksums ({} files, {} bytes total, hash={})", + file_and_content.len(), + total_size, + hash + ); for opts in cmd.output.iter() { - // TODO: use the hash as the dir name - opts.dir + log_operation!("WASM", "Writing output to: {}", opts.dir); + + // Clean up old wasm directories + let old_dirs: Vec<_> = opts + .dir .ls() .recurse() .filter(|dir| dir.file_name().is_some_and(|n| n.starts_with("wasm"))) - .for_each(|dir| { - log::debug!("Removing old wasm dir {dir}"); - dir.rm().unwrap(); - }); + .collect(); + + for dir in &old_dirs { + log_trace!("WASM", "Removing old wasm dir: {}", dir); + dir.rm().unwrap(); + } + + if !old_dirs.is_empty() { + log_operation!("WASM", "Cleaned up {} old wasm directories", old_dirs.len()); + } let hash_dir = if opts.checksum { Utf8PathBuf::from(format!("wasm.{hash}")) @@ -128,11 +199,18 @@ pub fn run(cmd: &WasmProcessingCmd) { opts.checksum = false; let opts = [opts]; + log_operation!( + "WASM", + "Writing {} files to {}", + file_and_content.len(), + hash_dir + ); for (file, contents) in file_and_content.iter() { let site_file = SiteFile::from_file(file).with_dir(&hash_dir); + log_trace!("WASM", "Writing file: {} -> {}", file, site_file); write_file_to_site(&site_file, contents, &opts); } } - log::debug!("Removing tmp dir {tmp_dir}"); + log_trace!("WASM", "Removing tmp dir: {}", tmp_dir); tmp_dir.rm().unwrap(); }