Instrument asset loading and processing. (#12988)

# Objective

As described in #12467, Bevy does not have any spans for any of the
tasks scheduled onto the IO and async compute task pools.

## Solution

Instrument all asset loads and asset processing. Since this change is
restricted to asset tasks, it does not completely solve #12467, but it
does mean we can record the asset path in the trace.


![image](https://github.com/bevyengine/bevy/assets/8494645/59faee63-1f69-40af-bf47-312c4d67d1e2)

---

## Changelog

Tracing will now include spans for asset loading and asset processing.

Author: chescock

crates/bevy_asset/Cargo.toml

@@ -16,6 +16,7 @@ embedded_watcher = ["file_watcher"]
 multi-threaded = ["bevy_tasks/multi-threaded"]
 asset_processor = []
 watch = []
+trace = []
 
 [dependencies]
 bevy_app = { path = "../bevy_app", version = "0.14.0-dev" }

crates/bevy_asset/src/processor/mod.rs

@@ -20,6 +20,11 @@ use crate::{
 use bevy_ecs::prelude::*;
 use bevy_tasks::IoTaskPool;
 use bevy_utils::tracing::{debug, error, trace, warn};
+#[cfg(feature = "trace")]
+use bevy_utils::{
+    tracing::{info_span, instrument::Instrument},
+    ConditionalSendFuture,
+};
 use bevy_utils::{HashMap, HashSet};
 use futures_io::ErrorKind;
 use futures_lite::{AsyncReadExt, AsyncWriteExt, StreamExt};
@@ -479,6 +484,8 @@ impl AssetProcessor {
     /// Register a new asset processor.
     pub fn register_processor<P: Process>(&self, processor: P) {
         let mut process_plans = self.data.processors.write();
+        #[cfg(feature = "trace")]
+        let processor = InstrumentedAssetProcessor(processor);
         process_plans.insert(std::any::type_name::<P>(), Arc::new(processor));
     }
 
@@ -1031,6 +1038,37 @@ impl AssetProcessorData {
     }
 }
 
+#[cfg(feature = "trace")]
+struct InstrumentedAssetProcessor<T>(T);
+
+#[cfg(feature = "trace")]
+impl<T: Process> Process for InstrumentedAssetProcessor<T> {
+    type Settings = T::Settings;
+    type OutputLoader = T::OutputLoader;
+
+    fn process<'a>(
+        &'a self,
+        context: &'a mut ProcessContext,
+        meta: AssetMeta<(), Self>,
+        writer: &'a mut crate::io::Writer,
+    ) -> impl ConditionalSendFuture<
+        Output = Result<<Self::OutputLoader as crate::AssetLoader>::Settings, ProcessError>,
+    > {
+        // Change the processor type for the `AssetMeta`, which works because we share the `Settings` type.
+        let meta = AssetMeta {
+            meta_format_version: meta.meta_format_version,
+            processed_info: meta.processed_info,
+            asset: meta.asset,
+        };
+        let span = info_span!(
+            "asset processing",
+            processor = std::any::type_name::<T>(),
+            asset = context.path().to_string(),
+        );
+        self.0.process(context, meta, writer).instrument(span)
+    }
+}
+
 /// The (successful) result of processing an asset
 #[derive(Debug, Clone)]
 pub enum ProcessResult {

crates/bevy_asset/src/server/loaders.rs

@@ -5,6 +5,11 @@ use crate::{
 use async_broadcast::RecvError;
 use bevy_tasks::IoTaskPool;
 use bevy_utils::tracing::{error, warn};
+#[cfg(feature = "trace")]
+use bevy_utils::{
+    tracing::{info_span, instrument::Instrument},
+    ConditionalSendFuture,
+};
 use bevy_utils::{HashMap, TypeIdMap};
 use std::{any::TypeId, sync::Arc};
 use thiserror::Error;
@@ -30,6 +35,8 @@ impl AssetLoaders {
         let loader_asset_type = TypeId::of::<L::Asset>();
         let loader_asset_type_name = std::any::type_name::<L::Asset>();
 
+        #[cfg(feature = "trace")]
+        let loader = InstrumentedAssetLoader(loader);
         let loader = Arc::new(loader);
 
         let (loader_index, is_new) =
@@ -41,7 +48,7 @@ impl AssetLoaders {
 
         if is_new {
             let mut duplicate_extensions = Vec::new();
-            for extension in loader.extensions() {
+            for extension in AssetLoader::extensions(&*loader) {
                 let list = self
                     .extension_to_loaders
                     .entry((*extension).into())
@@ -292,6 +299,34 @@ impl MaybeAssetLoader {
     }
 }
 
+#[cfg(feature = "trace")]
+struct InstrumentedAssetLoader<T>(T);
+
+#[cfg(feature = "trace")]
+impl<T: AssetLoader> AssetLoader for InstrumentedAssetLoader<T> {
+    type Asset = T::Asset;
+    type Settings = T::Settings;
+    type Error = T::Error;
+
+    fn load<'a>(
+        &'a self,
+        reader: &'a mut crate::io::Reader,
+        settings: &'a Self::Settings,
+        load_context: &'a mut crate::LoadContext,
+    ) -> impl ConditionalSendFuture<Output = Result<Self::Asset, Self::Error>> {
+        let span = info_span!(
+            "asset loading",
+            loader = std::any::type_name::<T>(),
+            asset = load_context.asset_path().to_string(),
+        );
+        self.0.load(reader, settings, load_context).instrument(span)
+    }
+
+    fn extensions(&self) -> &[&str] {
+        self.0.extensions()
+    }
+}
+
 #[cfg(test)]
 mod tests {
     use std::{

crates/bevy_internal/Cargo.toml

@@ -12,6 +12,7 @@ categories = ["game-engines", "graphics", "gui", "rendering"]
 [features]
 trace = [
   "bevy_app/trace",
+  "bevy_asset?/trace",
   "bevy_core_pipeline?/trace",
   "bevy_ecs/trace",
   "bevy_log/trace",