feat(engine): implement run_engine function and update command handling

fix(logging): change debug logs to info for better visibility in MFT processing
refactor(fixup): enhance logging format for entry size and count in apply_fixups_parallel

Author: TeamDman

src/cli/command/engine.rs

@@ -1,4 +1,5 @@
 use crate::cli::to_args::ToArgs;
+use crate::engine::run::run_engine;
 use arbitrary::Arbitrary;
 use clap::Args;
 use clap::Subcommand;
@@ -18,7 +19,7 @@ impl EngineArgs {
     pub fn invoke(self) -> eyre::Result<()> {
         match self.command {
             EngineCommand::Run => {
-                println!("Engine command is a work in progress.");
+                run_engine()?;
                 Ok(())
             }
         }

src/engine/mft_file_plugin.rs

@@ -54,7 +54,7 @@ pub fn on_sync_dir_added_emit_loads(
                         .map(|ext| ext.eq_ignore_ascii_case("mft"))
                         .unwrap_or(false);
                     if is_mft && path.is_file() {
-                        debug!(?path, "Queueing MFT load from path");
+                        info!(?path, "Queueing MFT load from path");
                         messages.write(MftFileMessage::LoadFromPath(path));
                     }
                 }
@@ -101,7 +101,7 @@ pub fn finish_mft_file_tasks(
         if let Some(result) = block_on(poll_once(task)) {
             match result {
                 Ok(mft) => {
-                    debug!(?path, mft=?format!("{:?}", &mft), "Loaded MFT file from disk");
+                    info!(?path, mft=?format!("{:?}", &mft), "Loaded MFT file from disk");
                     commands.spawn(mft);
                 }
                 Err(e) => {
@@ -111,6 +111,13 @@ pub fn finish_mft_file_tasks(
             completed.push(path.clone());
         }
     }
+    if !completed.is_empty() {
+        debug!(
+            "Completed {} MFT load tasks, {} remaining",
+            completed.len(),
+            tasks.loading_from_disk.len() - completed.len()
+        );
+    }
     for path in completed {
         tasks.loading_from_disk.remove(&path);
     }

src/engine/run.rs

@@ -4,11 +4,13 @@ use bevy::log::LogPlugin;
 use bevy::prelude::*;
 use bevy::window::ExitCondition;
 use compact_str::CompactString;
+use tracing::debug;
 
 #[derive(Component, Reflect)]
 pub struct PhysicalDiskLabel(pub CompactString);
 
 pub fn run_engine() -> eyre::Result<()> {
+    debug!("Building Bevy engine");
     let mut app = App::new();
     app.add_plugins(
         DefaultPlugins
@@ -21,6 +23,9 @@ pub fn run_engine() -> eyre::Result<()> {
     );
     app.add_plugins(SyncDirectoryPlugin);
     app.add_plugins(MftFilePlugin);
+    debug!("Bevy engine built");
+
+    info!("Running Bevy engine");
     app.run();
     Ok(())
 }

src/engine/sync_dir_plugin.rs

@@ -5,13 +5,14 @@ use bevy::tasks::IoTaskPool;
 use bevy::tasks::Task;
 use bevy::tasks::block_on;
 use bevy::tasks::poll_once;
+use std::any::type_name;
 use std::ops::Deref;
 use std::path::PathBuf;
 
 pub struct SyncDirectoryPlugin;
 impl Plugin for SyncDirectoryPlugin {
     fn build(&self, app: &mut App) {
-    app.register_type::<SyncDirectory>();
+        app.register_type::<SyncDirectory>();
         app.register_type::<SyncDirectoryEvents>();
         app.init_resource::<SyncDirectoryTasks>();
         app.add_message::<SyncDirectoryEvents>();
@@ -61,6 +62,7 @@ pub fn read_sync_directory_events_and_launch_task(
     mut tasks: ResMut<SyncDirectoryTasks>,
 ) -> Result<()> {
     for ev in events.read() {
+        info!(event=?ev, "Processing {}", type_name::<SyncDirectoryEvents>());
         match ev {
             SyncDirectoryEvents::ReadSyncDirectory => {
                 if tasks.get_sync_dir.is_some() {
@@ -75,7 +77,7 @@ pub fn read_sync_directory_events_and_launch_task(
                     let path = try_get_sync_dir()?;
                     Ok(SyncDirectory(path))
                 });
-                debug!(task=?task, "Spawned task to load sync dir from preferences");
+                info!(task=?task, "Spawned task to load sync dir from preferences");
                 tasks.get_sync_dir = Some(task);
             }
         }
@@ -91,7 +93,7 @@ pub fn finish_load_sync_dir_from_preferences(
     if let Some(task) = tasks.get_sync_dir.as_mut() {
         if let Some(result) = block_on(poll_once(task)) {
             let sync_dir = result?;
-            debug!(sync_dir=?sync_dir, "Loaded sync dir from preferences");
+            info!(sync_dir=?sync_dir, "Loaded sync dir from preferences");
             if let Ok(entity) = existing.single() {
                 commands.entity(entity).insert(sync_dir);
             } else {

src/lib.rs

@@ -1,7 +1,7 @@
 #![feature(btree_cursors)]
-pub mod engine;
 pub mod cli;
 pub mod drive_letter_pattern;
+pub mod engine;
 pub mod mft;
 pub mod mft_check;
 pub mod mft_process;
@@ -25,15 +25,16 @@ use tracing_subscriber::util::SubscriberInitExt;
 /// In debug builds, include file and line number without timestamp.
 /// In release builds, include timestamp and log level.
 pub fn init_tracing(level: Level) {
-    let builder = tracing_subscriber::fmt().with_env_filter(
-        EnvFilter::try_from_default_env().unwrap_or_else(|_| {
+    let builder = tracing_subscriber::fmt()
+        .with_env_filter(EnvFilter::try_from_default_env().unwrap_or_else(|_| {
             EnvFilter::builder().parse_lossy(format!(
                 "{default_log_level},{bevy_defaults}",
                 default_log_level = level,
                 bevy_defaults = DEFAULT_FILTER
             ))
-        }),
-    );
+        }))
+        .with_writer(std::io::stderr)
+        .pretty();
     #[cfg(debug_assertions)]
     let subscriber = builder
         .with_target(false)

src/mft/fast_fixup.rs

@@ -174,8 +174,8 @@ pub fn apply_fixups_parallel(buf: &mut [u8], entry_size: usize) -> FixupStats {
     let entry_count = buf.len() / entry_size;
     debug!(
         "Detected entry size: {} bytes, total entries: {}",
-        entry_size,
-        entry_count
+        entry_size.separate_with_commas(),
+        entry_count.separate_with_commas()
     );
 
     let start = Instant::now();
@@ -203,12 +203,13 @@ pub fn apply_fixups_parallel(buf: &mut [u8], entry_size: usize) -> FixupStats {
     let total_size = Information::new::<byte>(buf.len() as f64);
     let rate = total_size / elapsed;
     debug!(
-        "Took {} ({}/s) applied/already/invalid={}/{}/{}",
-        elapsed.get_human(),
-        rate.get::<hertz>().trunc().separate_with_commas(),
-        stats.applied.separate_with_commas(),
-        stats.already_applied.separate_with_commas(),
-        stats.invalid.separate_with_commas()
+        "Took {elapsed} to process {count} records ({rate}/s) - fixup stats: applied={applied} already-applied={already_applied} invalid={invalid}",
+        elapsed = elapsed.get_human(),
+        count = entry_count.separate_with_commas(),
+        rate = rate.get::<hertz>().trunc().separate_with_commas(),
+        applied = stats.applied.separate_with_commas(),
+        already_applied = stats.already_applied.separate_with_commas(),
+        invalid = stats.invalid.separate_with_commas()
     );
 
     stats

src/mft/mft_file.rs

@@ -98,10 +98,10 @@ impl MftFile {
 
         // Log summary
         debug!(
-            "Read {} in {:.2?}, found entry size {} and {} entries",
+            "Read {} in {:.2?}, found entry size {} bytes and {} entries",
             mft_file_size.get_human(),
             read_start.elapsed(),
-            rtn.entry_size().get_human(),
+            rtn.entry_size().get::<byte>().separate_with_commas(),
             rtn.entry_count().separate_with_commas()
         );