From e3f55d6dfc22055943e3be7e7f61401c84c3bce9 Mon Sep 17 00:00:00 2001 From: Chris Russell <8494645+chescock@users.noreply.github.com> Date: Tue, 16 Apr 2024 08:02:11 -0400 Subject: [PATCH] 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. --- crates/bevy_asset/Cargo.toml | 1 + crates/bevy_asset/src/processor/mod.rs | 38 +++++++++++++++++++++++++ crates/bevy_asset/src/server/loaders.rs | 37 +++++++++++++++++++++++- crates/bevy_internal/Cargo.toml | 1 + 4 files changed, 76 insertions(+), 1 deletion(-) diff --git a/crates/bevy_asset/Cargo.toml b/crates/bevy_asset/Cargo.toml index 04398df8ec..6d5e3f5fcd 100644 --- a/crates/bevy_asset/Cargo.toml +++ b/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" } diff --git a/crates/bevy_asset/src/processor/mod.rs b/crates/bevy_asset/src/processor/mod.rs index bdcc47fbf0..380b1b2b4f 100644 --- a/crates/bevy_asset/src/processor/mod.rs +++ b/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(&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::

(), Arc::new(processor)); } @@ -1031,6 +1038,37 @@ impl AssetProcessorData { } } +#[cfg(feature = "trace")] +struct InstrumentedAssetProcessor(T); + +#[cfg(feature = "trace")] +impl Process for InstrumentedAssetProcessor { + 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<::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::(), + 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 { diff --git a/crates/bevy_asset/src/server/loaders.rs b/crates/bevy_asset/src/server/loaders.rs index fb161a986a..d853abd9a9 100644 --- a/crates/bevy_asset/src/server/loaders.rs +++ b/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::(); let loader_asset_type_name = std::any::type_name::(); + #[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); + +#[cfg(feature = "trace")] +impl AssetLoader for InstrumentedAssetLoader { + 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> { + let span = info_span!( + "asset loading", + loader = std::any::type_name::(), + 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::{ diff --git a/crates/bevy_internal/Cargo.toml b/crates/bevy_internal/Cargo.toml index 6fe310412f..c5d9c2b0e1 100644 --- a/crates/bevy_internal/Cargo.toml +++ b/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",