From 14894b984c01715a69f7787e30463591b196e809 Mon Sep 17 00:00:00 2001 From: SARDONYX-sard <68905624+SARDONYX-sard@users.noreply.github.com> Date: Mon, 22 Jan 2024 00:18:10 +0900 Subject: [PATCH] feat(log): change log display In parallel mode, logs are written out out of order, so data, paths, and indices during conversion are scattered. Therefore, using `tracing::instrument`, related information is connected and written out. --- dar2oar_cli/src/logger.rs | 19 ++++++++- dar2oar_core/src/error.rs | 24 ++++++------ dar2oar_core/src/fs/converter/common.rs | 43 +++++++++------------ dar2oar_core/src/fs/converter/mod.rs | 18 +++++++-- dar2oar_core/src/fs/converter/parallel.rs | 6 +-- dar2oar_core/src/fs/converter/sequential.rs | 5 +-- dar2oar_core/src/fs/mapping_table.rs | 8 ++-- dar2oar_core/src/test_helper.rs | 14 ++++++- src-tauri/src/logging.rs | 7 ++++ 9 files changed, 88 insertions(+), 56 deletions(-) diff --git a/dar2oar_cli/src/logger.rs b/dar2oar_cli/src/logger.rs index f0cd490..a4695e1 100644 --- a/dar2oar_cli/src/logger.rs +++ b/dar2oar_cli/src/logger.rs @@ -17,17 +17,32 @@ pub(crate) fn init_tracing( match with_stdout { true => tracing::subscriber::set_global_default( fmt::Subscriber::builder() + .compact() + .pretty() + .with_file(true) + .with_line_number(true) .with_max_level(filter) + .with_target(false) + .with_thread_ids(true) .finish() .with( fmt::Layer::default() - .with_writer(File::create(log_path)?) + .compact() + .with_ansi(false) + .with_file(true) .with_line_number(true) - .with_ansi(false), + .with_target(false) + .with_thread_ids(true) + .with_writer(File::create(log_path)?), ), )?, false => tracing_subscriber::fmt() + .compact() .with_ansi(false) + .with_file(true) + .with_line_number(true) + .with_target(false) + .with_thread_ids(true) .with_writer(File::create(log_path)?) .with_max_level(filter) .init(), diff --git a/dar2oar_core/src/error.rs b/dar2oar_core/src/error.rs index 13ca00a..0b67b85 100644 --- a/dar2oar_core/src/error.rs +++ b/dar2oar_core/src/error.rs @@ -1,31 +1,31 @@ #[derive(Debug, thiserror::Error)] pub enum ConvertError { - #[error("Nothing in the specified path")] - NotFoundEntry, #[error("Failed to write section config target: {0}")] FailedWriteSectionConfig(String), + #[error("Never converted.")] + NeverConverted, + #[error("No such paths exist: \"{0}\"")] + NonExistPath(String), + #[error("Nothing in the specified path")] + NotFoundEntry, #[error("Could not find files with \".mohidden\" extension")] NotFoundUnhideTarget, - #[error("Not found \"OpenAnimationReplacer\" directory")] - NotFoundOarDir, #[error("Not found \"DynamicAnimationReplacer\" directory")] NotFoundDarDir, - #[error("Not found DAR priority(Number) directory")] - NotFoundPriorityDir, - #[error("Never converted.")] - NeverConverted, #[error("Not found file name")] NotFoundFileName, - #[error("Could not find the mapping table file \"{0}\".")] - NotFoundSpecifiedMappingTable(String), - #[error("This is not valid utf8")] - InvalidUtf8, + #[error("Not found \"OpenAnimationReplacer\" directory")] + NotFoundOarDir, + #[error("Not found DAR priority(Number) directory")] + NotFoundPriorityDir, #[error("Incomplete conversion")] IncompleteConversion, #[error("Incomplete parse DAR. Remain:\n{0}")] IncompleteParseDar(String), #[error("DAR syntax error.:\n{0}")] InvalidDarSyntax(String), + #[error("This is not valid utf8")] + InvalidUtf8, #[error(transparent)] ConditionError(#[from] crate::conditions::ConditionError), #[error(transparent)] diff --git a/dar2oar_core/src/fs/converter/common.rs b/dar2oar_core/src/fs/converter/common.rs index c71e10b..4ba9155 100644 --- a/dar2oar_core/src/fs/converter/common.rs +++ b/dar2oar_core/src/fs/converter/common.rs @@ -8,15 +8,18 @@ use std::path::Path; use std::sync::atomic::{AtomicBool, Ordering::AcqRel, Ordering::Relaxed}; use tokio::fs; -/// Common parts of multi-threaded and single-threaded loop processing. -/// # Performance -/// - Since dir is created when a file is discovered, performance is improved if path.is_dir() is not put in path. -pub async fn convert_inner( +// NOTE: Variables in fields do not appear in the log if Option::None. +#[tracing::instrument(level = "debug", skip(options, is_converted_once), fields(specified_output = &options.oar_dir))] +/// Common parts of parallel & sequential loop processing. +pub async fn convert_inner

( options: &ConvertOptions, - path: impl AsRef, + path: P, parsed_path: &ParsedPath, is_converted_once: &AtomicBool, -) -> Result<()> { +) -> Result<()> +where + P: AsRef + std::fmt::Debug, +{ let path = path.as_ref(); let ConvertOptions { dar_dir: _, @@ -57,31 +60,24 @@ pub async fn convert_inner( .unwrap_or(oar_root.clone()) .join(&parsed_mod_name); - tracing::debug!("File: {:?}", path); - let file_name = path .file_name() - .ok_or_else(|| ConvertError::NotFoundFileName)? + .ok_or(ConvertError::NotFoundFileName)? .to_str() - .ok_or_else(|| ConvertError::InvalidUtf8)?; + .ok_or(ConvertError::InvalidUtf8)?; /// Copy motion files(.hkx), gender dir or other. macro_rules! copy_other_file { ($section_root:ident) => { if let Some(remain) = remain_dir { - let non_leaf_dir = $section_root.join(remain); - - tracing::debug!("Create dirs: {:?}", &non_leaf_dir); + tracing::debug!("Copy with Nest Dir: {:?}", remain.join(file_name)); + let non_leaf_dir = $section_root.join(remain); // e.g. mesh/[...]/male/ fs::create_dir_all(&non_leaf_dir).await?; - - let file = &non_leaf_dir.join(file_name); - tracing::debug!("Copy with Nest Dir:\n- From: {path:?}\n- To: {file:?}"); - fs::copy(path, file).await?; + fs::copy(path, &non_leaf_dir.join(file_name)).await?; } else { - let file = $section_root.join(file_name); - tracing::debug!("Copy:\n- From: {path:?}\n- To: {file:?}"); + tracing::debug!("Copy: {file_name}"); fs::create_dir_all(&$section_root).await?; - fs::copy(path, file).await?; + fs::copy(path, $section_root.join(file_name)).await?; } }; } @@ -117,7 +113,7 @@ pub async fn convert_inner( // # Ordering validity: // Use `AcqRel` to `happened before relationship`(form a memory read/write order between threads) of cas(compare_and_swap), - // so that other threads read after writing true to memory to prevent unnecessary file writing. + // so that other threads read after writing true to memory. // - In case of cas failure, use `Relaxed` because the order is unimportant. let _ = is_converted_once.compare_exchange(false, true, AcqRel, Relaxed); @@ -131,10 +127,7 @@ pub async fn convert_inner( } Err(invalid_priority) => { tracing::warn!( - r#"Got invalid priority: "{}". -DAR expects a numeric directory name directly under _CustomConditions, but this is invalid because it is not numeric. -Therefore, just copy it as a memo. -"#, + r#"Got invalid priority: "{}". DAR expects "DynamicAnimationReplacer/_CustomConditions//". Thus, copy it as a memo."#, invalid_priority ); let section_root = oar_name_space.join(invalid_priority); diff --git a/dar2oar_core/src/fs/converter/mod.rs b/dar2oar_core/src/fs/converter/mod.rs index 9b85f1d..c72b238 100644 --- a/dar2oar_core/src/fs/converter/mod.rs +++ b/dar2oar_core/src/fs/converter/mod.rs @@ -77,6 +77,13 @@ pub async fn convert_dar_to_oar( options: ConvertOptions, progress_fn: impl FnMut(usize), ) -> Result<()> { + let dar_dir = std::path::Path::new(&options.dar_dir); + if !dar_dir.exists() { + return Err(crate::error::ConvertError::NonExistPath(format!( + "{dar_dir:?}" + ))); + }; + match options.run_parallel { true => crate::fs::converter::parallel::convert_dar_to_oar(options, progress_fn).await, false => crate::fs::converter::sequential::convert_dar_to_oar(options, progress_fn).await, @@ -115,15 +122,20 @@ mod test { use super::*; use anyhow::Result; - const DAR_DIR: &str = "../test/data/UNDERDOG Animations"; - const TABLE_PATH: &str = "../test/mapping_tables/UnderDog Animations_v1.9.6_mapping_table.txt"; + // const DAR_DIR: &str = "../test/data/UNDERDOG - Animations"; + const DAR_DIR: &str = "../test/data/Delia"; + // const OAR_DIR: &str = + // "../test/data/Delia/meshes/actors/character/animations\\OpenAnimationReplacer"; + // const TABLE_PATH: &str = "../test/mapping_tables/UnderDog Animations_v1.9.6_mapping_table.txt"; async fn create_options() -> Result { Ok(ConvertOptions { dar_dir: DAR_DIR.into(), + // oar_dir: Some(OAR_DIR.into()), // cannot use include_str! - section_table: Some(crate::read_mapping_table(TABLE_PATH).await?), + // section_table: Some(crate::read_mapping_table(TABLE_PATH).await?), run_parallel: true, + // hide_dar: true, ..Default::default() }) } diff --git a/dar2oar_core/src/fs/converter/parallel.rs b/dar2oar_core/src/fs/converter/parallel.rs index cc0e504..356a31d 100644 --- a/dar2oar_core/src/fs/converter/parallel.rs +++ b/dar2oar_core/src/fs/converter/parallel.rs @@ -26,7 +26,7 @@ pub async fn convert_dar_to_oar( let dar_dir = options.dar_dir.as_str(); let walk_len = get_dar_files(dar_dir).into_iter().count(); - tracing::debug!("Parallel Converter/DAR dir & file counts: {}", walk_len); + tracing::info!("Parallel Converter/DAR dir & file counts: {}", walk_len); progress_fn(walk_len); let entires = get_dar_files(dar_dir).into_iter(); @@ -34,7 +34,7 @@ pub async fn convert_dar_to_oar( let is_converted_once = Arc::new(AtomicBool::new(false)); let mut task_handles: Vec>> = Vec::new(); - for (idx, entry) in entires.enumerate() { + for entry in entires { let path = entry.map_err(|_| ConvertError::NotFoundEntry)?.path(); if !path.is_file() { continue; @@ -51,7 +51,6 @@ pub async fn convert_dar_to_oar( let options = Arc::clone(&options); let is_converted_once = Arc::clone(&is_converted_once); async move { - tracing::debug!("[Start {}th conversion]\n{:?}", idx, &parsed_path); convert_inner( &options, path.as_ref(), @@ -59,7 +58,6 @@ pub async fn convert_dar_to_oar( is_converted_once.as_ref(), ) .await?; - tracing::debug!("[End {}th conversion]\n\n", idx); Ok(()) } })); diff --git a/dar2oar_core/src/fs/converter/sequential.rs b/dar2oar_core/src/fs/converter/sequential.rs index 5fc72b5..a18d39a 100644 --- a/dar2oar_core/src/fs/converter/sequential.rs +++ b/dar2oar_core/src/fs/converter/sequential.rs @@ -22,7 +22,7 @@ pub async fn convert_dar_to_oar( let dar_dir = options.dar_dir.as_str(); let walk_len = get_dar_file_count(dar_dir).await?; - tracing::debug!("Sequential Converter/DAR file counts: {}", walk_len); + tracing::info!("Sequential Converter/DAR file counts: {}", walk_len); progress_fn(walk_len); let is_converted_once = AtomicBool::new(false); @@ -31,8 +31,7 @@ pub async fn convert_dar_to_oar( while let Some(entry) = entries.next().await { let path = entry?.path(); let path = path.as_path(); - if path.is_dir() { - tracing::debug!("Dir: {:?}", path); + if !path.is_file() { continue; } let parsed_path = match parse_dar_path(path) { diff --git a/dar2oar_core/src/fs/mapping_table.rs b/dar2oar_core/src/fs/mapping_table.rs index 026796e..c0e84fd 100644 --- a/dar2oar_core/src/fs/mapping_table.rs +++ b/dar2oar_core/src/fs/mapping_table.rs @@ -15,11 +15,9 @@ pub async fn get_mapping_table( /// Try to read mapping table from path pub async fn read_mapping_table(table_path: impl AsRef) -> Result> { - if !table_path.as_ref().exists() { - return Err(ConvertError::NotFoundSpecifiedMappingTable(format!( - "{:?}", - table_path.as_ref() - ))); + let table_path = table_path.as_ref(); + if !table_path.exists() { + return Err(ConvertError::NonExistPath(format!("{table_path:?}"))); }; let mut file_contents = String::new(); diff --git a/dar2oar_core/src/test_helper.rs b/dar2oar_core/src/test_helper.rs index 5862558..d416b78 100644 --- a/dar2oar_core/src/test_helper.rs +++ b/dar2oar_core/src/test_helper.rs @@ -17,13 +17,23 @@ pub(crate) fn init_tracing( tracing_appender::non_blocking(std::fs::File::create(format!("../logs/{test_name}.log"))?); let thread_guard = tracing::subscriber::set_default( fmt::Subscriber::builder() + .compact() + .pretty() + .with_file(true) + .with_line_number(true) .with_max_level(filter) + .with_target(false) + .with_thread_ids(true) .finish() .with( fmt::Layer::default() - .with_writer(file_writer) + .compact() + .with_ansi(false) + .with_file(true) .with_line_number(true) - .with_ansi(false), + .with_target(false) + .with_thread_ids(true) + .with_writer(file_writer), ), ); Ok((guard, thread_guard)) diff --git a/src-tauri/src/logging.rs b/src-tauri/src/logging.rs index 8950fd3..8183c72 100644 --- a/src-tauri/src/logging.rs +++ b/src-tauri/src/logging.rs @@ -24,8 +24,15 @@ pub(crate) fn init_logger(app: &tauri::App) -> Result<()> { let log_dir = &resolver.app_log_dir().context("Not found log dir")?; let log_name = format!("{}.log", app.package_info().name); + // Not available yet because ansi(false) is not applied in tracing::instrument under the combination of pretty() and with_ansi(false). + // - See https://github.com/tokio-rs/tracing/issues/1310 let fmt_layer = fmt::layer() + .compact() .with_ansi(false) + .with_file(true) + .with_line_number(true) + .with_target(false) + .with_thread_ids(true) .with_writer(create_rotate_log(log_dir, &log_name, 4)?); let (filter, reload_handle) = reload::Layer::new(filter::LevelFilter::ERROR);