feat(assets): Add feature flag cid_debug_trace to bones_asset (#422)

With feature flag, during asset load, each input used to update cid are
tracked and then logged.

One issue is that for dep_cid, I tried to get the AssetLoc for deps, but
it appears to be None. Would be good to improve with some identifying
information on dependency, right now just logs dep_cid and asset cid
after update. If dep_cid differs, hard to tell which it is / why.

Dump for each asset is a single trace call, which hopefully will avoid
any interleaved output as this runs in parallel for multiple assets.

Sample output:
```
2024-07-11T01:45:13.558171Z  INFO bones_asset::server: Cid trace schema: u!("jumpy::GameMeta") file path: "/game.yaml"
Trace is in order of updates, which impacts result
[Intermediate] Cid from schema fullname: u!("jumpy::GameMeta") cid: GqGtXP1KVcKyCvAHaUFYKt6miTj83mNfamjHYhfnScDm
[Intermediate] Cid from contents: cid: Ee6Z9iFMXp9PZkHgH5UCdbT9RQqy1UwUBZPePWaqUXgu
Dumping updates from sorted dependency cids:
    dep_cid: 1sp1JT5VhgEas7h5A55pmMLSo7SGj44VtnwKF3xVtjq, cid: 5MtTGxtP5C2ytUANTrQRw8cufhRvVykGALggTzgY1eFA, dep_asset_loc: None

... <truncated, quite long> ...

    dep_cid: 5VYCqN78NFaPYig354UZW9Pu6Bj8qoLHCDP59UXF2cr, cid: 8NCDAQU5ETULQ78FcSWtyHZePi5iWZciyAoRF2C2fyET, dep_asset_loc: None
Final cid: A71MVvdDbboEKKx8tQULZh9baqoqDQn45PDeS6QxWrWQ
```

Hopefully useful for issues like:
fishfolk/jumpy#995

Author: MaxCWhitehead

framework_crates/bones_asset/Cargo.toml

@@ -13,6 +13,9 @@ keywords.workspace      = true
 [features]
 default = []
 
+# Enables debug logging of asset cid computation during loading.
+cid_debug_trace = []
+
 [dependencies]
 bones_utils  = { version = "0.3", path = "../bones_utils", features = ["serde"] }
 bones_schema = { version = "0.3", path = "../bones_schema", features = ["serde"] }

framework_crates/bones_asset/src/cid.rs

@@ -1,5 +1,8 @@
 use serde::{Deserialize, Serialize};
 
+#[cfg(feature = "cid_debug_trace")]
+pub(crate) use cid_debug_trace::*;
+
 /// A unique content ID.
 ///
 /// Represents the Sha-256 hash of the contents of a [`LoadedAsset`][crate::LoadedAsset].
@@ -31,3 +34,79 @@ impl Cid {
         self.0.copy_from_slice(&result);
     }
 }
+
+#[cfg(feature = "cid_debug_trace")]
+mod cid_debug_trace {
+
+    use crate::{AssetLoc, Cid};
+    use std::path::Path;
+
+    use bones_utils::{default, Ustr};
+
+    pub(crate) struct CidDebugTrace<'a> {
+        pub schema_full_name: Ustr,
+        pub file_path: &'a Path,
+
+        pub cid_after_schema_fullname: Cid,
+        pub cid_after_contents: Cid,
+
+        /// Tuple of dep_cid, updated cid, and dep asset loc
+        pub cid_after_deps: Vec<(Cid, Cid, Option<AssetLoc>)>,
+
+        pub final_cid: Cid,
+    }
+
+    impl<'a> CidDebugTrace<'a> {
+        pub(crate) fn new(schema_full_name: Ustr, file_path: &'a Path) -> Self {
+            Self {
+                schema_full_name,
+                file_path,
+                cid_after_schema_fullname: default(),
+                cid_after_contents: default(),
+                cid_after_deps: default(),
+                final_cid: default(),
+            }
+        }
+    }
+
+    impl<'a> std::fmt::Display for CidDebugTrace<'a> {
+        fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
+            // dump asset meta
+            writeln!(
+                f,
+                "Cid trace schema: {:?} file path: {:?}",
+                self.schema_full_name, self.file_path
+            )?;
+            writeln!(f, "Trace is in order of updates, which impacts result")?;
+
+            // cid schema fullname update
+            writeln!(
+                f,
+                "[Intermediate] Cid from schema fullname: {:?} cid: {}",
+                self.schema_full_name, self.cid_after_schema_fullname
+            )?;
+
+            // cid content update
+            writeln!(
+                f,
+                "[Intermediate] Cid from contents: cid: {}",
+                self.cid_after_contents
+            )?;
+
+            // cid dependency update
+            writeln!(f, "Dumping updates from sorted dependency cids:")?;
+            for (dep_cid, updated_cid, dep_asset_loc) in self.cid_after_deps.iter() {
+                writeln!(
+                    f,
+                    "    dep_cid: {}, cid: {}, dep_asset_loc: {:?}",
+                    dep_cid, updated_cid, dep_asset_loc
+                )?;
+            }
+
+            // final cid
+            writeln!(f, "Final cid: {}", self.final_cid)?;
+
+            Ok(())
+        }
+    }
+}

framework_crates/bones_asset/src/server.rs

@@ -19,7 +19,11 @@ use semver::VersionReq;
 use serde::{de::DeserializeSeed, Deserialize};
 use ulid::Ulid;
 
+#[allow(unused_imports)]
+use tracing::info;
+
 use crate::prelude::*;
+
 use bones_utils::{
     parking_lot::{MappedMutexGuard, MutexGuard},
     *,
@@ -610,11 +614,29 @@ impl AssetServer {
         let mut dependencies = Vec::new();
 
         let mut cid = Cid::default();
+
+        // NOTE: If changing cid computation logic, please update `CidDebugTrace` impl if possible.
+        //
+        // Tracks inputs to asset cid for debug tracing.
+        #[cfg(feature = "cid_debug_trace")]
+        let mut cid_debug = CidDebugTrace::new(schema.full_name, loc.path);
+
         // Use the schema name and the file contents to create a unique, content-addressed ID for
         // the asset.
         cid.update(schema.full_name.as_bytes());
+
+        #[cfg(feature = "cid_debug_trace")]
+        {
+            cid_debug.cid_after_schema_fullname = cid;
+        }
+
         cid.update(contents);
 
+        #[cfg(feature = "cid_debug_trace")]
+        {
+            cid_debug.cid_after_contents = cid;
+        }
+
         let loader = MetaAssetLoadCtx {
             server: self,
             loc,
@@ -654,6 +676,22 @@ impl AssetServer {
         dep_cids.sort();
         for dep_cid in dep_cids {
             cid.update(dep_cid.0.as_slice());
+
+            #[cfg(feature = "cid_debug_trace")]
+            {
+                // TODO: Get dep_cid asset_loc for cid debug trace,
+                // It is currently None, needs fix / alterative idenifying metadata.
+
+                let asset_loc = self.store.assets.get(&cid).map(|x| x.loc.clone());
+                cid_debug.cid_after_deps.push((dep_cid, cid, asset_loc));
+            }
+        }
+
+        #[cfg(feature = "cid_debug_trace")]
+        {
+            // log asset cid trace
+            cid_debug.final_cid = cid;
+            info!("{cid_debug}");
         }
 
         Ok(PartialAsset {