Skip to content

Commit 5416f25

Browse files
authored
Wrap tracing spans in #[cfg(feature = "trace")] (#23831)
# Objective - Reducing tracing overhead. - Ensure that heavy `info_span!` calls and their associated logic are only compiled and executed when the `trace` feature is enabled. - Fixes a memory leak on web, per #23949. ## Solution - Wrapped `info_span!` entries with `#[cfg(feature = "trace")]`. ## Testing - `cargo check` --- ## Showcase I observed in flamegraph profiling that certain span creations were consuming ~1.5% of total CPU time. <img width="1233" height="464" alt="image" src="https://github.com/user-attachments/assets/85527538-be64-4305-97dd-89c16ff56674" />
1 parent ffd0539 commit 5416f25

6 files changed

Lines changed: 33 additions & 4 deletions

File tree

crates/bevy_core_pipeline/src/schedule.rs

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@ use bevy_ecs::{
1717
prelude::*,
1818
schedule::{InternedScheduleLabel, IntoScheduleConfigs, Schedule, ScheduleLabel, SystemSet},
1919
};
20+
#[cfg(feature = "trace")]
2021
use bevy_log::info_span;
2122
use bevy_reflect::Reflect;
2223
use bevy_render::{
@@ -226,10 +227,12 @@ impl Display for RootView {
226227

227228
pub(crate) fn submit_pending_command_buffers(world: &mut World) {
228229
let mut pending = world.resource_mut::<PendingCommandBuffers>();
230+
#[cfg(feature = "trace")]
229231
let buffer_count = pending.len();
230232
let buffers = pending.take();
231233

232234
if !buffers.is_empty() {
235+
#[cfg(feature = "trace")]
233236
let _span = info_span!("queue_submit", count = buffer_count).entered();
234237
let queue = world.resource::<RenderQueue>();
235238
queue.submit(buffers);

crates/bevy_pbr/src/render/mesh.rs

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -80,7 +80,9 @@ use indexmap::IndexSet;
8080
use material_bind_groups::MaterialBindingId;
8181
use static_assertions::const_assert_eq;
8282
use std::sync::mpsc;
83-
use tracing::{error, info_span, warn};
83+
#[cfg(feature = "trace")]
84+
use tracing::info_span;
85+
use tracing::{error, warn};
8486

8587
use self::irradiance_volume::IRRADIANCE_VOLUMES_ARE_USABLE;
8688
use crate::{
@@ -2482,6 +2484,7 @@ pub fn collect_meshes_for_gpu_building(
24822484
let reextract_tx = reextract_tx.clone();
24832485
let removed_tx = removed_tx.clone();
24842486
scope.spawn(async move {
2487+
#[cfg(feature = "trace")]
24852488
let _span = info_span!("prepared_mesh_producer").entered();
24862489
changed
24872490
.drain(..)
@@ -2520,6 +2523,7 @@ pub fn collect_meshes_for_gpu_building(
25202523
let reextract_tx = reextract_tx.clone();
25212524
let removed_tx = removed_tx.clone();
25222525
scope.spawn(async move {
2526+
#[cfg(feature = "trace")]
25232527
let _span = info_span!("prepared_mesh_producer").entered();
25242528
for (entity, mesh_instance_builder, mesh_culling_builder) in
25252529
changed_cpu_culling

crates/bevy_render/src/batching/gpu_preprocessing.rs

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2341,12 +2341,14 @@ pub fn write_batched_instance_buffers<GFBD>(
23412341

23422342
ComputeTaskPool::get().scope(|scope| {
23432343
scope.spawn(async {
2344+
#[cfg(feature = "trace")]
23442345
let _span = bevy_log::info_span!("write_current_input_buffers").entered();
23452346
current_input_buffer
23462347
.buffer
23472348
.write_buffers(render_device, render_queue);
23482349
});
23492350
scope.spawn(async {
2351+
#[cfg(feature = "trace")]
23502352
let _span = bevy_log::info_span!("write_previous_input_buffers").entered();
23512353
previous_input_buffer.write_buffer(render_device, render_queue);
23522354
});
@@ -2360,6 +2362,7 @@ pub fn write_batched_instance_buffers<GFBD>(
23602362
} = *phase_instance_buffers;
23612363

23622364
scope.spawn(async {
2365+
#[cfg(feature = "trace")]
23632366
let _span = bevy_log::info_span!("write_phase_instance_buffers").entered();
23642367
data_buffer.write_buffer(render_device);
23652368
late_indexed_indirect_parameters_buffer.write_buffer(render_device, render_queue);
@@ -2369,6 +2372,7 @@ pub fn write_batched_instance_buffers<GFBD>(
23692372

23702373
for phase_work_item_buffers in work_item_buffers.values_mut() {
23712374
scope.spawn(async {
2375+
#[cfg(feature = "trace")]
23722376
let _span = bevy_log::info_span!("write_work_item_buffers").entered();
23732377
match *phase_work_item_buffers {
23742378
PreprocessWorkItemBuffers::Direct(ref mut buffer_vec) => {
@@ -2640,13 +2644,15 @@ pub fn write_indirect_parameters_buffers(
26402644
ComputeTaskPool::get().scope(|scope| {
26412645
for phase_indirect_parameters_buffers in indirect_parameters_buffers.values_mut() {
26422646
scope.spawn(async {
2647+
#[cfg(feature = "trace")]
26432648
let _span = bevy_log::info_span!("indexed_data").entered();
26442649
phase_indirect_parameters_buffers
26452650
.indexed
26462651
.indirect_draw_parameters
26472652
.write_buffer(render_device);
26482653
});
26492654
scope.spawn(async {
2655+
#[cfg(feature = "trace")]
26502656
let _span = bevy_log::info_span!("non_indexed_data").entered();
26512657
phase_indirect_parameters_buffers
26522658
.non_indexed
@@ -2655,13 +2661,15 @@ pub fn write_indirect_parameters_buffers(
26552661
});
26562662

26572663
scope.spawn(async {
2664+
#[cfg(feature = "trace")]
26582665
let _span = bevy_log::info_span!("indexed_cpu_metadata").entered();
26592666
phase_indirect_parameters_buffers
26602667
.indexed
26612668
.cpu_metadata
26622669
.write_buffer(render_device, render_queue);
26632670
});
26642671
scope.spawn(async {
2672+
#[cfg(feature = "trace")]
26652673
let _span = bevy_log::info_span!("non_indexed_cpu_metadata").entered();
26662674
phase_indirect_parameters_buffers
26672675
.non_indexed
@@ -2670,13 +2678,15 @@ pub fn write_indirect_parameters_buffers(
26702678
});
26712679

26722680
scope.spawn(async {
2681+
#[cfg(feature = "trace")]
26732682
let _span = bevy_log::info_span!("non_indexed_gpu_metadata").entered();
26742683
phase_indirect_parameters_buffers
26752684
.non_indexed
26762685
.gpu_metadata
26772686
.write_buffer(render_device);
26782687
});
26792688
scope.spawn(async {
2689+
#[cfg(feature = "trace")]
26802690
let _span = bevy_log::info_span!("indexed_gpu_metadata").entered();
26812691
phase_indirect_parameters_buffers
26822692
.indexed
@@ -2685,13 +2695,15 @@ pub fn write_indirect_parameters_buffers(
26852695
});
26862696

26872697
scope.spawn(async {
2698+
#[cfg(feature = "trace")]
26882699
let _span = bevy_log::info_span!("indexed_batch_sets").entered();
26892700
phase_indirect_parameters_buffers
26902701
.indexed
26912702
.batch_sets
26922703
.write_buffer(render_device, render_queue);
26932704
});
26942705
scope.spawn(async {
2706+
#[cfg(feature = "trace")]
26952707
let _span = bevy_log::info_span!("non_indexed_batch_sets").entered();
26962708
phase_indirect_parameters_buffers
26972709
.non_indexed

crates/bevy_render/src/renderer/mod.rs

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,9 @@ use bevy_camera::NormalizedRenderTarget;
1919
use bevy_derive::{Deref, DerefMut};
2020
use bevy_ecs::schedule::ScheduleLabel;
2121
use bevy_ecs::{prelude::*, system::SystemState};
22-
use bevy_log::{debug, info, info_span, warn};
22+
#[cfg(feature = "trace")]
23+
use bevy_log::info_span;
24+
use bevy_log::{debug, info, warn};
2325
use bevy_render::camera::ExtractedCamera;
2426
use bevy_window::RawHandleWrapperHolder;
2527
use wgpu::{
@@ -87,6 +89,7 @@ pub fn render_system(
8789
}
8890

8991
{
92+
#[cfg(feature = "trace")]
9093
let _span = info_span!("present_frames").entered();
9194

9295
world.resource_scope(|world, mut windows: Mut<ExtractedWindows>| {

crates/bevy_render/src/renderer/render_context.rs

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@ use bevy_ecs::system::{
1313
};
1414
use bevy_ecs::world::unsafe_world_cell::UnsafeWorldCell;
1515
use bevy_ecs::world::DeferredWorld;
16+
#[cfg(feature = "trace")]
1617
use bevy_log::info_span;
1718
use core::marker::PhantomData;
1819
use wgpu::CommandBuffer;
@@ -103,8 +104,10 @@ impl RenderContextState {
103104
}
104105

105106
impl SystemBuffer for RenderContextState {
106-
fn queue(&mut self, system_meta: &SystemMeta, mut world: DeferredWorld) {
107-
let _span = info_span!("RenderContextState::apply", system = %system_meta.name()).entered();
107+
fn queue(&mut self, _system_meta: &SystemMeta, mut world: DeferredWorld) {
108+
#[cfg(feature = "trace")]
109+
let _span =
110+
info_span!("RenderContextState::apply", system = %_system_meta.name()).entered();
108111

109112
let inner = &mut *self.0;
110113

crates/bevy_render/src/view/visibility/mod.rs

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@ use bevy_ecs::{
1010
Local, Query, SystemParam,
1111
},
1212
};
13+
#[cfg(feature = "trace")]
1314
use bevy_log::info_span;
1415
use bevy_platform::collections::{HashMap, HashSet};
1516
use bevy_reflect::{prelude::ReflectDefault, Reflect};
@@ -194,6 +195,7 @@ impl RenderVisibleEntitiesClass {
194195
&mut self,
195196
visible_mesh_entities_cpu_culling: &[(Entity, MainEntity)],
196197
) {
198+
#[cfg(feature = "trace")]
197199
let _update_from = info_span!("update_from", name = "update_from").entered();
198200

199201
let old_entities_cpu_culling = mem::take(&mut self.entities_cpu_culling);
@@ -203,6 +205,7 @@ impl RenderVisibleEntitiesClass {
203205
// entities. The lists must be sorted.
204206
let mut old_entity_cpu_culling_iter = old_entities_cpu_culling.iter().peekable();
205207
{
208+
#[cfg(feature = "trace")]
206209
let _old_entity_cpu_culling_span =
207210
info_span!("old_entity_cpu_culling", name = "old_entity_cpu_culling").entered();
208211
for (render_entity, visible_main_entity) in visible_mesh_entities_cpu_culling {
@@ -236,6 +239,7 @@ impl RenderVisibleEntitiesClass {
236239
// Any entities that do CPU culling and that we didn't see yet are
237240
// removed, so drain them.
238241
{
242+
#[cfg(feature = "trace")]
239243
let _old_entity_cpu_culling_removal_span = info_span!(
240244
"old_entity_cpu_culling_removal",
241245
name = "old_entity_cpu_culling_removal"

0 commit comments

Comments
 (0)