Lag on initial spawn of SpriteBundle

[jusw85]

Bevy version

0.4

Operating system & version

Arch

What you did

I'm experiencing 200-300ms lag between keypress and appearance on screen when spawning a SpriteBundle for the first time. I can workaround by spawning a SpriteBundle in a startup system.

This occurs on both assets loaded from filesystem (seemingly more pronounced) and code defined colour material.

Tested on cargo run and cargo run --release

Reproducing example

``` use bevy::prelude::*; fn main() { App::build() .add_plugins(DefaultPlugins) .add_startup_system(setup.system()) .add_system(input.system()) .run(); } struct Material { red: Handle, black: Handle, } #[derive(Default)] struct Position(Vec3); fn setup( commands: &mut Commands, mut color_materials: ResMut>, ) { let material = Material { black: color_materials.add(Color::BLACK.into()), red: color_materials.add(Color::RED.into()), }; // Workaround by pre-spawning anything // Doesn't even have to be the same material or onscreen // commands.spawn( // SpriteBundle { // material: material.red.clone(), // transform: Transform::from_translation(Vec3::new(-10000., 0., 0.)), // ..Default::default() // }); commands.spawn(Camera2dBundle::default()); commands .insert_resource(material) .insert_resource(Position::default()); } fn input( input: Res>, commands: &mut Commands, material: Res, mut position: ResMut, ) { if input.just_pressed(KeyCode::Left) { position.0.x -= 32.; } else if input.just_pressed(KeyCode::Right) { position.0.x += 32.; } else if input.just_pressed(KeyCode::Up) { position.0.y += 32.; } else if input.just_pressed(KeyCode::Down) { position.0.y -= 32.; } else if input.just_pressed(KeyCode::Return) { // 200-300ms lag when spawning for the first time commands.spawn( SpriteBundle { material: material.black.clone(), sprite: Sprite::new(Vec2::new(32., 32.)), transform: Transform::from_translation(position.0), ..Default::default() }); } } ```

[tigregalis]

I can't seem to reproduce it on WIndows 10.

Have you checked the frame rate?

You'll need a font for the FPS text. I've put FiraSans-Bold.ttf in PROJECT_ROOT/assets/fonts/.

use bevy::{
    diagnostic::{Diagnostics, FrameTimeDiagnosticsPlugin},
    prelude::*,
};

fn main() {
    App::build()
        .add_plugins(DefaultPlugins)
        .add_plugin(FrameTimeDiagnosticsPlugin::default())
        .add_startup_system(setup.system())
        .add_startup_system(setup_text.system())
        .add_system(input.system())
        .add_system(text_update_system.system())
        .run();
}

struct Material {
    red: Handle<ColorMaterial>,
    black: Handle<ColorMaterial>,
}

#[derive(Default)]
struct Position(Vec3);

fn setup(commands: &mut Commands, mut color_materials: ResMut<Assets<ColorMaterial>>) {
    let material = Material {
        black: color_materials.add(Color::BLACK.into()),
        red: color_materials.add(Color::RED.into()),
    };

    // Workaround by pre-spawning anything
    // Doesn't even have to be the same material or onscreen

    // commands.spawn(
    //     SpriteBundle {
    //         material: material.red.clone(),
    //         transform: Transform::from_translation(Vec3::new(-10000., 0., 0.)),
    //         ..Default::default()
    //     });

    commands.spawn(Camera2dBundle::default());
    commands
        .insert_resource(material)
        .insert_resource(Position::default());
}

fn input(
    input: Res<Input<KeyCode>>,
    commands: &mut Commands,
    material: Res<Material>,
    mut position: ResMut<Position>,
) {
    if input.just_pressed(KeyCode::Left) {
        position.0.x -= 32.;
    } else if input.just_pressed(KeyCode::Right) {
        position.0.x += 32.;
    } else if input.just_pressed(KeyCode::Up) {
        position.0.y += 32.;
    } else if input.just_pressed(KeyCode::Down) {
        position.0.y -= 32.;
    } else if input.just_pressed(KeyCode::Return) {
        // 200-300ms lag when spawning for the first time
        commands.spawn(SpriteBundle {
            material: material.black.clone(),
            sprite: Sprite::new(Vec2::new(32., 32.)),
            transform: Transform::from_translation(position.0),
            ..Default::default()
        });
    }
}

struct FpsText;

fn text_update_system(diagnostics: Res<Diagnostics>, mut query: Query<&mut Text, With<FpsText>>) {
    for mut text in query.iter_mut() {
        if let Some(fps) = diagnostics.get(FrameTimeDiagnosticsPlugin::FPS) {
            if let Some(average) = fps.average() {
                text.value = format!("FPS: {:.2}", average);
            }
        }
    }
}

fn setup_text(commands: &mut Commands, asset_server: Res<AssetServer>) {
    commands
        // 2d camera
        .spawn(CameraUiBundle::default())
        // texture
        .spawn(TextBundle {
            style: Style {
                align_self: AlignSelf::FlexEnd,
                ..Default::default()
            },
            text: Text {
                value: "FPS:".to_string(),
                font: asset_server.load("fonts/FiraSans-Bold.ttf"),
                style: TextStyle {
                    font_size: 60.0,
                    color: Color::WHITE,
                    ..Default::default()
                },
            },
            ..Default::default()
        })
        .with(FpsText);
}

[jusw85]

I have tested on a separate Windows 10 machine and the same issue occurs for me.

I've changed the code slightly to spawn both a png (hat-guy.png) and a colour which seems to make the issue more noticeable.

Without pre-spawning. Notice the slight hitch when I press enter for the first time.

This is if I prespawn in a startup system off screen. However, this seems to cause shift the lag into the initial window open i.e. the window takes 200-300ms longer to open.

View code

``` use bevy::{ diagnostic::{Diagnostics, FrameTimeDiagnosticsPlugin}, prelude::*, }; fn main() { App::build() .add_resource(WindowDescriptor { width: 640., height: 64., vsync: true, ..Default::default() }) .add_plugins(DefaultPlugins) .add_plugin(FrameTimeDiagnosticsPlugin::default()) .add_startup_system(setup.system()) .add_startup_system(setup_text.system()) .add_system(input.system()) .add_system(text_update_system.system()) .run(); } struct Material { red: Handle, black: Handle, png: Handle, } #[derive(Default)] struct Position(Vec3); fn setup(commands: &mut Commands, asset_server: Res, mut color_materials: ResMut>) { let material = Material { black: color_materials.add(Color::BLACK.into()), red: color_materials.add(Color::RED.into()), png: color_materials.add(asset_server.load("textures/rpg/chars/hat-guy/hat-guy.png").into()), }; commands.spawn(Camera2dBundle::default()); commands .insert_resource(material) .insert_resource(Position::default()); } fn input( input: Res>, commands: &mut Commands, material: Res, mut position: ResMut, ) { if input.just_pressed(KeyCode::Return) { // 200-300ms lag when spawning for the first time commands.spawn(SpriteBundle { material: material.black.clone(), sprite: Sprite::new(Vec2::new(32., 32.)), transform: Transform::from_translation(position.0), ..Default::default() }); commands.spawn(SpriteBundle { material: material.png.clone(), transform: Transform::from_translation(position.0), ..Default::default() }); position.0.x += 32.; } } struct FpsText; fn text_update_system(diagnostics: Res, mut query: Query<&mut Text, With>) { for mut text in query.iter_mut() { if let Some(fps) = diagnostics.get(FrameTimeDiagnosticsPlugin::FPS) { if let Some(average) = fps.average() { text.value = format!("FPS: {:.2}", average); } } } } fn setup_text(commands: &mut Commands, asset_server: Res) { commands // 2d camera .spawn(CameraUiBundle::default()) // texture .spawn(TextBundle { style: Style { align_self: AlignSelf::FlexEnd, ..Default::default() }, text: Text { value: "FPS:".to_string(), font: asset_server.load("fonts/FiraSans-Bold.ttf"), style: TextStyle { font_size: 60.0, color: Color::WHITE, ..Default::default() }, }, ..Default::default() }) .with(FpsText); } ```

[tigregalis]

Ah, ok, yes. I definitely see the hitching, and it's consistently only on the first one you spawn (subsequent spawns aren't affected). Bizarre. ~125ms for the first example (I didn't notice it before but it's definitely there), and ~245ms for the second example:

example 1

```rust use bevy::{ diagnostic::{Diagnostics, FrameTimeDiagnosticsPlugin}, prelude::*, }; fn main() { App::build() .add_plugins(DefaultPlugins) .add_plugin(FrameTimeDiagnosticsPlugin::default()) .add_resource(RecordTime(None)) .add_startup_system(setup.system()) .add_startup_system(setup_text.system()) .add_system(input.system()) .add_system(text_update_system.system()) .run(); } struct RecordTime(Option); struct Material { red: Handle, black: Handle, } #[derive(Default)] struct Position(Vec3); fn setup(commands: &mut Commands, mut color_materials: ResMut>) { let material = Material { black: color_materials.add(Color::BLACK.into()), red: color_materials.add(Color::RED.into()), }; // Workaround by pre-spawning anything // Doesn't even have to be the same material or onscreen // commands.spawn( // SpriteBundle { // material: material.red.clone(), // transform: Transform::from_translation(Vec3::new(-10000., 0., 0.)), // ..Default::default() // }); commands.spawn(Camera2dBundle::default()); commands .insert_resource(material) .insert_resource(Position::default()); } fn input( time: Res, mut record_time: ResMut, input: Res>, commands: &mut Commands, material: Res, mut position: ResMut, ) { if let RecordTime(Some(t0)) = *record_time { let t = time.seconds_since_startup(); dbg!(t - t0); record_time.0 = None; } if input.just_pressed(KeyCode::Left) { position.0.x -= 32.; } else if input.just_pressed(KeyCode::Right) { position.0.x += 32.; } else if input.just_pressed(KeyCode::Up) { position.0.y += 32.; } else if input.just_pressed(KeyCode::Down) { position.0.y -= 32.; } else if input.just_pressed(KeyCode::Return) { // 200-300ms lag when spawning for the first time let t = time.seconds_since_startup(); record_time.0 = Some(t); commands.spawn(SpriteBundle { material: material.black.clone(), sprite: Sprite::new(Vec2::new(32., 32.)), transform: Transform::from_translation(position.0), ..Default::default() }); } } struct FpsText; fn text_update_system(diagnostics: Res, mut query: Query<&mut Text, With>) { for mut text in query.iter_mut() { if let Some(fps) = diagnostics.get(FrameTimeDiagnosticsPlugin::FPS) { if let Some(average) = fps.average() { text.value = format!("FPS: {:.2}", average); } } } } fn setup_text(commands: &mut Commands, asset_server: Res) { commands // 2d camera .spawn(CameraUiBundle::default()) // texture .spawn(TextBundle { style: Style { align_self: AlignSelf::FlexEnd, ..Default::default() }, text: Text { value: "FPS:".to_string(), font: asset_server.load("fonts/FiraSans-Bold.ttf"), style: TextStyle { font_size: 60.0, color: Color::WHITE, ..Default::default() }, }, ..Default::default() }) .with(FpsText); } ```

example 2

```rust use bevy::{ diagnostic::{Diagnostics, FrameTimeDiagnosticsPlugin}, prelude::*, }; fn main() { App::build() .add_resource(WindowDescriptor { width: 640., height: 64., vsync: true, ..Default::default() }) .add_resource(RecordTime(None)) .add_plugins(DefaultPlugins) .add_plugin(FrameTimeDiagnosticsPlugin::default()) .add_startup_system(setup.system()) .add_startup_system(setup_text.system()) .add_system(text_update_system.system()) .add_system(input.system()) .run(); } struct RecordTime(Option); struct Material { red: Handle, black: Handle, png: Handle, } #[derive(Default)] struct Position(Vec3); fn setup( commands: &mut Commands, asset_server: Res, mut color_materials: ResMut>, ) { let material = Material { black: color_materials.add(Color::BLACK.into()), red: color_materials.add(Color::RED.into()), png: color_materials.add( asset_server .load("textures/rpg/chars/hat-guy/hat-guy.png") .into(), ), // png: color_materials.add(Color::GREEN.into()), }; commands.spawn(Camera2dBundle::default()); commands .insert_resource(material) .insert_resource(Position::default()); } fn input( time: Res, mut record_time: ResMut, input: Res>, commands: &mut Commands, material: Res, mut position: ResMut, ) { if input.just_pressed(KeyCode::Return) { // 200-300ms lag when spawning for the first time let t = time.seconds_since_startup(); record_time.0 = Some(t); commands.spawn(SpriteBundle { material: material.black.clone(), sprite: Sprite::new(Vec2::new(32., 32.)), transform: Transform::from_translation(position.0), ..Default::default() }); commands.spawn(SpriteBundle { material: material.png.clone(), transform: Transform::from_translation(position.0), ..Default::default() }); position.0.x += 32.; } } struct FpsText; fn text_update_system( time: Res, mut record_time: ResMut, diagnostics: Res, mut query: Query<&mut Text, With>, ) { if let RecordTime(Some(t0)) = *record_time { let t = time.seconds_since_startup(); dbg!(t - t0); record_time.0 = None; } for mut text in query.iter_mut() { if let Some(fps) = diagnostics.get(FrameTimeDiagnosticsPlugin::FPS) { if let Some(average) = fps.average() { text.value = format!("FPS: {:.2}", average); } } } } fn setup_text(commands: &mut Commands, asset_server: Res) { commands // 2d camera .spawn(CameraUiBundle::default()) // texture .spawn(TextBundle { style: Style { align_self: AlignSelf::FlexEnd, ..Default::default() }, text: Text { value: "FPS:".to_string(), font: asset_server.load("fonts/FiraSans-Bold.ttf"), style: TextStyle { font_size: 60.0, color: Color::WHITE, ..Default::default() }, }, ..Default::default() }) .with(FpsText); } ```

Checked master (example 2) and the same issue is present

```rust use bevy::{ diagnostic::{Diagnostics, FrameTimeDiagnosticsPlugin}, prelude::*, }; fn main() { App::build() .insert_resource(WindowDescriptor { width: 640., height: 64., vsync: true, ..Default::default() }) .insert_resource(RecordTime(None)) .add_plugins(DefaultPlugins) .add_plugin(FrameTimeDiagnosticsPlugin::default()) .add_startup_system(setup.system()) .add_startup_system(setup_text.system()) .add_system(input.system()) .add_system(text_update_system.system()) .run(); } struct RecordTime(Option); struct Material { red: Handle, black: Handle, png: Handle, } #[derive(Default)] struct Position(Vec3); fn setup( commands: &mut Commands, asset_server: Res, mut color_materials: ResMut>, ) { let material = Material { black: color_materials.add(Color::BLACK.into()), red: color_materials.add(Color::RED.into()), png: color_materials.add( asset_server .load("textures/rpg/chars/hat-guy/hat-guy.png") .into(), ), // png: color_materials.add(Color::GREEN.into()), }; commands.spawn(OrthographicCameraBundle::new_2d()); commands .insert_resource(material) .insert_resource(Position::default()); } fn input( time: Res, mut record_time: ResMut, input: Res>, commands: &mut Commands, material: Res, mut position: ResMut, ) { if let RecordTime(Some(t0)) = *record_time { let t = time.seconds_since_startup(); dbg!(t - t0); record_time.0 = None; } if input.just_pressed(KeyCode::Return) { // 200-300ms lag when spawning for the first time let t = time.seconds_since_startup(); record_time.0 = Some(t); commands.spawn(SpriteBundle { material: material.black.clone(), sprite: Sprite::new(Vec2::new(32., 32.)), transform: Transform::from_translation(position.0), ..Default::default() }); commands.spawn(SpriteBundle { material: material.png.clone(), transform: Transform::from_translation(position.0), ..Default::default() }); position.0.x += 32.; } } struct FpsText; fn text_update_system(diagnostics: Res, mut query: Query<&mut Text, With>) { for mut text in query.iter_mut() { if let Some(fps) = diagnostics.get(FrameTimeDiagnosticsPlugin::FPS) { if let Some(average) = fps.average() { text.sections[0].value = format!("FPS: {:.2}", average); } } } } fn setup_text(commands: &mut Commands, asset_server: Res) { commands // 2d camera .spawn(UiCameraBundle::default()) // texture .spawn(TextBundle { style: Style { align_self: AlignSelf::FlexEnd, ..Default::default() }, text: Text::with_section( "FPS:", TextStyle { font: asset_server.load("fonts/FiraSans-Bold.ttf"), font_size: 60.0, color: Color::WHITE, }, Default::default(), ), ..Default::default() }) .with(FpsText); } ```

[bjorn3]

I think adding the entity triggers uploading the texture to the gpu. Maybe this uploading is simply slow. Other things I think it triggers are shader compilation and pipeline generation. These could also be slow.

[cart]

Yeah the solution here is probably to identify the code causing the skip and move it to a background thread (which as @bjorn3 mentioned is probably gpu-data-upload-related).

RenderResourceContext is thread safe and cloneable, so there is a world where we can do the transfer across frames.

[cart]

Or rather WgpuRenderResourceContext is thread safe and cloneable. We would need to expose the clone functionality in Box<dyn RenderResourceContext>

[bjorn3]

It did also be nice to compile shaders and things like that in the background as soon as they get added as asset. Basically everything that could benefit from pre-compilation without having to consume space in the ram of the gpu.

[cart]

Agreed. I've seen this done in Distill, so we might just want to focus on that migration first. Then we can do things like "pre-compile glsl to spirv, then when the game starts load the spirv into memory, compile the shader, and immediately drop the spirv on the cpu side".