Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

DenseAssetStorage<bevy_gltf::Gltf>::insert: 'internal error: entered unreachable code: entries should always be valid after a flush'. #10820

Closed
marcelchampagne opened this issue Nov 30, 2023 · 18 comments · Fixed by #13506
Labels
A-Assets Load files from disk to use for things like images, models, and sounds C-Bug An unexpected or incorrect behavior S-Needs-Review Needs reviewer attention (from anyone!) to move forward

Comments

@marcelchampagne
Copy link
Contributor

Bevy version

0.12.1

Relevant system information

2023-11-30T22:47:50.264801Z  INFO bevy_render::renderer: AdapterInfo { name: "AMD Radeon RX 5700 XT", vendor: 4098, device: 29471, device_type: DiscreteGpu, driver: "AMD proprietary driver", driver_info: "23.9.2 (AMD proprietary shader compiler)", backend: Vulkan }
2023-11-30T22:47:50.510744Z  INFO bevy_diagnostic::system_information_diagnostics_plugin::internal: SystemInfo { os: "Windows 10 Home", kernel: "19045", cpu: "AMD Ryzen 7 3700X 8-Core Processor", core_count: "8", memory: "15.9 GiB" }

What you did

I have a simple asset plugin that loads GLB files and inserts the handles for the scenes and meshes into a resource. In my full application, which loads approximately 200 assets, I encounter a panic immediately after running cargo run after upgrading to Bevy 0.12.1 from 0.11.3.

I've provided an MRE below. Unfortunately, with the below example, the panic only occurs, roughly, 1 out of every 50 times. In my full application, it seems to happen much more frequently, perhaps 1 out of every 10 runs.

use bevy::{prelude::*, utils::HashMap};

#[derive(Debug, Clone, Copy, Default, Eq, PartialEq, Hash, States)]
pub enum GameState {
    #[default]
    LoadingAssets,
}

#[derive(Default, Debug, Clone, Copy, PartialEq, Eq, Hash, Component)]
pub enum Model {
    #[default]
    AlpacaBaby,
    AlpacaAdolescent,
    AlpacaMature,
    CowBaby,
    CowAdolescent,
    CowMature,
    Alligasaur,
    Deer,
    Fox,
    Wolf,
    Player,
    Man,
    Woman,
}

#[derive(Resource, Default)]
pub struct Scenes {
    pub scene_registry: HashMap<Model, Handle<Scene>>,
}

#[derive(Resource, Default)]
pub struct Meshes {
    pub mesh_registry: HashMap<Model, Handle<Mesh>>,
}

fn main() {
    App::new()
        .add_plugins(DefaultPlugins)
        .add_plugins(AssetPlugin)
        .run();
}

struct AssetPlugin;

impl Plugin for AssetPlugin {
    fn build(&self, app: &mut App) {
        app.add_state::<GameState>()
            .init_resource::<Scenes>()
            .init_resource::<Meshes>()
            .add_systems(OnEnter(GameState::LoadingAssets), setup_models_system);
    }
}

pub fn setup_models_system(
    mut scenes: ResMut<Scenes>,
    mut meshes: ResMut<Meshes>,
    asset_server: Res<AssetServer>,
) {
    let entries = [
        (Model::AlpacaBaby, "alpaca_baby.glb"),
        (Model::AlpacaAdolescent, "alpaca_adolescent.glb"),
        (Model::AlpacaMature, "alpaca_mature.glb"),
        (Model::CowBaby, "cow_baby.glb"),
        (Model::CowAdolescent, "cow_adolescent.glb"),
        (Model::CowMature, "cow_mature.glb"),
        (Model::Alligasaur, "alligasaur.glb"),
        (Model::Deer, "deer.glb"),
        (Model::Player, "player.glb"),
        (Model::Man, "man.glb"),
        (Model::Woman, "woman.glb"),
    ];

    let mut scene_registry: HashMap<Model, Handle<Scene>> = HashMap::new();
    let mut mesh_registry: HashMap<Model, Handle<Mesh>> = HashMap::new();
    for (model, path) in entries.iter() {
        scene_registry.insert(*model, asset_server.load(format!("{}#Scene0", path)));
        mesh_registry.insert(
            *model,
            asset_server.load(format!("{}#Mesh0/Primitive0", path)),
        );
    }
    scenes.scene_registry = scene_registry;
    meshes.mesh_registry = mesh_registry;
}

What went wrong

thread 'main' panicked at 'internal error: entered unreachable code: entries should always be valid after a flush', C:\Users\voice\.cargo\registry\src\index.crates.io-6f17d22bba15001f\bevy_asset-0.12.1\src\assets.rs:148:13
stack backtrace:
   0: std::panicking::begin_panic_handler
             at /rustc/d5c2e9c342b358556da91d61ed4133f6f50fc0c3/library\std\src\panicking.rs:593
   1: core::panicking::panic_fmt
             at /rustc/d5c2e9c342b358556da91d61ed4133f6f50fc0c3/library\core\src\panicking.rs:67
   2: bevy_asset::assets::DenseAssetStorage<bevy_gltf::Gltf>::insert
             at C:\Users\voice\.cargo\registry\src\index.crates.io-6f17d22bba15001f\bevy_asset-0.12.1\src\assets.rs:148
   3: bevy_asset::assets::Assets<bevy_gltf::Gltf>::insert_with_index
             at C:\Users\voice\.cargo\registry\src\index.crates.io-6f17d22bba15001f\bevy_asset-0.12.1\src\assets.rs:349
   4: bevy_asset::assets::Assets<bevy_gltf::Gltf>::insert<bevy_gltf::Gltf,enum2$<bevy_asset::id::AssetId<bevy_gltf::Gltf> > >
             at C:\Users\voice\.cargo\registry\src\index.crates.io-6f17d22bba15001f\bevy_asset-0.12.1\src\assets.rs:311
   5: bevy_asset::loader::impl$5::insert<bevy_gltf::Gltf>
             at C:\Users\voice\.cargo\registry\src\index.crates.io-6f17d22bba15001f\bevy_asset-0.12.1\src\loader.rs:240
   6: bevy_asset::server::info::AssetInfos::process_asset_load
             at C:\Users\voice\.cargo\registry\src\index.crates.io-6f17d22bba15001f\bevy_asset-0.12.1\src\server\info.rs:326
   7: bevy_asset::server::handle_internal_asset_events::closure$0
             at C:\Users\voice\.cargo\registry\src\index.crates.io-6f17d22bba15001f\bevy_asset-0.12.1\src\server\mod.rs:940
   8: bevy_ecs::world::World::resource_scope<bevy_asset::server::AssetServer,tuple$<>,bevy_asset::server::handle_internal_asset_events::closure_env$0>
             at C:\Users\voice\.cargo\registry\src\index.crates.io-6f17d22bba15001f\bevy_ecs-0.12.1\src\world\mod.rs:1571
   9: bevy_asset::server::handle_internal_asset_events
             at C:\Users\voice\.cargo\registry\src\index.crates.io-6f17d22bba15001f\bevy_asset-0.12.1\src\server\mod.rs:935
 ...
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
Encountered a panic in exclusive system `bevy_asset::server::handle_internal_asset_events`!
Encountered a panic in system `bevy_app::main_schedule::Main::run_main`!

Additional information

The same panic was investigated in #10444. It seems this same code is also panicking, but it appears to be unrelated to AssetEvent::Removed this time, since assets are not being removed in this case.

For debugging purpose, I've included the assets that are being loaded in the example above here: https://drive.google.com/file/d/1Nq9fBoARR6p9nxXc-aOJt2Lut5-UpZMP/view?usp=sharing. The assets are from Mixamo and Qauternius's Ultimate Animated Animal Pack.

@marcelchampagne marcelchampagne added C-Bug An unexpected or incorrect behavior S-Needs-Triage This issue needs to be labelled labels Nov 30, 2023
@alice-i-cecile alice-i-cecile added A-Assets Load files from disk to use for things like images, models, and sounds and removed S-Needs-Triage This issue needs to be labelled labels Nov 30, 2023
@Testare
Copy link
Contributor

Testare commented Dec 6, 2023

I've been getting this error as well

@cart cart added this to the 0.13 milestone Dec 16, 2023
@Testare
Copy link
Contributor

Testare commented Jan 18, 2024

A little more information about the error on my end (to help with debugging):

First of all, my error isn't occurring for DenseAssetStorage<bevy_gltf::Gltf>::insert specifically, or rather not for that specific generic. In fact, the error trace is just showing generic parameter A. Here's a trace:

thread 'main' panicked at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_asset-0.12.1/src/assets.rs:148:13:
internal error: entered unreachable code: entries should always be valid after a flush
stack backtrace:
   0: rust_begin_unwind
             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/std/src/panicking.rs:597:5
   1: core::panicking::panic_fmt
             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/panicking.rs:72:14
   2: bevy_asset::assets::DenseAssetStorage<A>::insert
             at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_asset-0.12.1/src/assets.rs:148:13
   3: bevy_asset::assets::Assets<A>::insert_with_index
             at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_asset-0.12.1/src/assets.rs:349:24
   4: bevy_asset::assets::Assets<A>::insert
             at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_asset-0.12.1/src/assets.rs:305:17
   5: <A as bevy_asset::loader::AssetContainer>::insert
             at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_asset-0.12.1/src/loader.rs:240:9
   6: bevy_asset::server::info::AssetInfos::process_asset_load
             at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_asset-0.12.1/src/server/info.rs:326:9
   7: bevy_asset::server::handle_internal_asset_events::{{closure}}
             at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_asset-0.12.1/src/server/mod.rs:940:21
   8: bevy_ecs::world::World::resource_scope
             at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_ecs-0.12.1/src/world/mod.rs:1571:22
   9: bevy_asset::server::handle_internal_asset_events
             at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_asset-0.12.1/src/server/mod.rs:935:5

I don't think I even have bevy_gltf compiled in my game, as it's more of a TUI game. In my case, I also have custom asset loaders, including assets that depend on other assets.

Secondly, I also get a second type of error, with this trace:

thread 'main' panicked at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_asset-0.12.1/src/assets.rs:305:54:
called `Result::unwrap()` on an `Err` value: InvalidGenerationError { index: AssetIndex { generation: 0, index: 17 }, current_generation: 1 }
stack backtrace:
   0: rust_begin_unwind
             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/std/src/panicking.rs:597:5
   1: core::panicking::panic_fmt
             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/panicking.rs:72:14
   2: core::result::unwrap_failed
             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/result.rs:1652:5
   3: core::result::Result<T,E>::unwrap
             at /rustc/79e9716c980570bfd1f666e3b16ac583f0168962/library/core/src/result.rs:1077:23
   4: bevy_asset::assets::Assets<A>::insert
             at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_asset-0.12.1/src/assets.rs:305:17
   5: <A as bevy_asset::loader::AssetContainer>::insert
             at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_asset-0.12.1/src/loader.rs:240:9
   6: bevy_asset::server::info::AssetInfos::process_asset_load
             at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_asset-0.12.1/src/server/info.rs:326:9
   7: bevy_asset::server::handle_internal_asset_events::{{closure}}
             at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_asset-0.12.1/src/server/mod.rs:940:21
   8: bevy_ecs::world::World::resource_scope
             at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_ecs-0.12.1/src/world/mod.rs:1571:22
   9: bevy_asset::server::handle_internal_asset_events
             at /Users/logwoo/.cargo/registry/src/index.crates.io-6f17d22bba15001f/bevy_asset-0.12.1/src/server/mod.rs:935:5
  10: core::ops::function::FnMut::call_mut

The result is unwrapped on line 305, but the Err(InvalidGenerationError) actually comes from the same function as the other error, just a few lines up: https://github.com/bevyengine/bevy/blob/v0.12.1/crates/bevy_asset/src/assets.rs#L142

@alice-i-cecile alice-i-cecile removed this from the 0.13 milestone Jan 24, 2024
@mockersf
Copy link
Member

mockersf commented Feb 3, 2024

For the original issue, I think it's because you're only keeping a strong handle to the subassets (#Scene0 and #Mesh0/Primitive0), and the handle to the main asset is dropped too early, before the asset matching is actually inserted. This insertion is what is causing the panic.

It can probably happen every time an asset is loaded with a label and the main asset is ignored, but it seems random and load dependent.

As a workaround in user code, you can keep a strong handle to the main asset (a Gltf here) and drop it once every thing is loaded

@alice-i-cecile alice-i-cecile added this to the 0.14 milestone Feb 3, 2024
@marcelchampagne
Copy link
Contributor Author

marcelchampagne commented Feb 3, 2024

@mockersf Thank you so much for investigating! I tried your suggested workaround and it seems to have resolved the issue (unless I've yet to encounter the panic😅). Your hypothesis makes a lot of sense though and would explain why others may not be encountering it. Still I'm somewhat surprised given that loading a GLTF Scene without the entire Gltf file is probably one of the most common things I'd expect users to do with GLTF files.

But as we observed since it's load dependent but the race condition only really occurs when lots of assets are being loaded.

@marcelchampagne
Copy link
Contributor Author

marcelchampagne commented Feb 8, 2024

Can confirm that the workaround fix is indeed working as I've been running with it for a couple of days without any panics. I also doubled checked and my full application code still panics maybe 1/5 times without it so @mockersf assessment of the issue is accurate at least for my case.

Unrelated but GLTF assets in general take much longer to load in 0.12 than in 0.11.x. Just an FYI but loading 200 assets is taking ~8 seconds for me now and it was maybe ~1 second before, if there isn't an existing issue for that happy to file one, but it's causing iteration time to be a fair bit longer.

@AxiomaticSemantics
Copy link
Contributor

AxiomaticSemantics commented Feb 26, 2024

This may have possibly been resolved by #11986
I'll keep trying to reproduce and follow-up on the results later. To anyone that does get this, could you try on current main? Apparently this is not fixed.

thread 'main' panicked at /home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_asset/src/assets.rs:150:13:
internal error: entered unreachable code: entries should always be valid after a flush
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Encountered a panic in system `bevy_asset::server::handle_internal_asset_events`!
thread 'Compute Task Pool (4)' panicked at thread '/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rsCompute Task Pool (5):' panicked at 477/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rs::thread '17477Compute Task Pool (2):
:thread '' panicked at Resource requested by bevy_asset::assets::Assets<bevy_scene::dynamic_scene::DynamicScene>::track_assets does not exist: bevy_asset::server::AssetServer17Compute Task Pool (6)thread '/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rs
:
' panicked at Compute Task Pool (3):Resource requested by bevy_asset::assets::Assets<bevy_render::mesh::mesh::skinning::SkinnedMeshInverseBindposes>::track_assets does not exist: bevy_asset::server::AssetServer/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rs' panicked at 477thread '
:/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rsthread ':Compute Task Pool (0)477:Compute Task Pool (7)17' panicked at :477' panicked at :
/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rs17:/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rsResource requested by bevy_asset::assets::Assets<bevy_gltf::GltfNode>::track_assets does not exist: bevy_asset::server::AssetServer::
17:Encountered a panic in system `
477Resource requested by bevy_asset::assets::Assets<()>::track_assets does not exist: bevy_asset::server::AssetServer:
477bevy_asset::assets::Assets<bevy_scene::dynamic_scene::DynamicScene>::track_assets:
Resource requested by bevy_asset::assets::Assets<util::assets::json::JsonSource>::track_assets does not exist: bevy_asset::server::AssetServer:`!
17
17:
Encountered a panic in system `:
Resource requested by bevy_asset::assets::Assets<bevy_gltf::GltfPrimitive>::track_assets does not exist: bevy_asset::server::AssetServerbevy_asset::assets::Assets<bevy_gltf::GltfNode>::track_assetsResource requested by bevy_asset::assets::Assets<bevy_asset::folder::LoadedFolder>::track_assets does not exist: bevy_asset::server::AssetServer
`!

thread 'Compute Task Pool (4)' panicked at Encountered a panic in system `/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rsbevy_asset::assets::Assets<bevy_render::mesh::mesh::skinning::SkinnedMeshInverseBindposes>::track_assets:`!
thread '477Compute Task Pool (2):' panicked at 17Encountered a panic in system `/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rsthread ':
bevy_asset::assets::Assets<()>::track_assets:Compute Task Pool (5)Resource requested by bevy_asset::assets::Assets<bevy_scene::scene::Scene>::track_assets does not exist: bevy_asset::server::AssetServer`!
477' panicked at 
:/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rsEncountered a panic in system `17::
bevy_asset::assets::Assets<bevy_asset::folder::LoadedFolder>::track_assetsthread '477Resource requested by bevy_asset::assets::Assets<bevy_audio::pitch::Pitch>::track_assets does not exist: bevy_asset::server::AssetServer`!
Compute Task Pool (6):
' panicked at 17Encountered a panic in system `/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rs:
bevy_asset::assets::Assets<bevy_gltf::GltfPrimitive>::track_assetsthread ':Resource requested by bevy_asset::assets::Assets<bevy_render::texture::image::Image>::track_assets does not exist: bevy_asset::server::AssetServer`!
Compute Task Pool (7)477
Encountered a panic in system `' panicked at :bevy_asset::assets::Assets<bevy_audio::pitch::Pitch>::track_assets/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rs17thread '`!
::
Compute Task Pool (0)477Resource requested by bevy_asset::assets::Assets<bevy_sprite::mesh2d::color_material::ColorMaterial>::track_assets does not exist: bevy_asset::server::AssetServer' panicked at 
:Encountered a panic in system `thread '/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rs17bevy_asset::assets::Assets<bevy_scene::scene::Scene>::track_assetsCompute Task Pool (2)::
`!
' panicked at 477Resource requested by bevy_asset::assets::Assets<bevy_gizmos::LineGizmo>::track_assets does not exist: bevy_asset::server::AssetServer/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rs:
thread 'Encountered a panic in system `:17Compute Task Pool (4)bevy_asset::assets::Assets<util::assets::json::JsonSource>::track_assets477:
' panicked at `!
:Resource requested by bevy_asset::assets::Assets<bevy_gltf::GltfMesh>::track_assets does not exist: bevy_asset::server::AssetServer/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rs17
:thread ':
Encountered a panic in system `477Compute Task Pool (3)Resource requested by bevy_asset::assets::Assets<bevy_gltf::Gltf>::track_assets does not exist: bevy_asset::server::AssetServerbevy_asset::assets::Assets<bevy_render::texture::image::Image>::track_assets:' panicked at 
`!
17/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rs:
:Resource requested by bevy_asset::assets::Assets<bevy_render::render_resource::shader::Shader>::track_assets does not exist: bevy_asset::server::AssetServerEncountered a panic in system `thread '477Compute Task Pool (5)
' panicked at bevy_asset::assets::Assets<bevy_sprite::mesh2d::color_material::ColorMaterial>::track_assets:/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rs`!
17:Encountered a panic in system `:
477bevy_asset::assets::Assets<bevy_render::render_resource::shader::Shader>::track_assetsResource requested by bevy_asset::assets::Assets<bevy_render::mesh::mesh::Mesh>::track_assets does not exist: bevy_asset::server::AssetServerthread ':`!

Compute Task Pool (6)17' panicked at :
/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rsResource requested by bevy_asset::assets::Assets<bevy_sprite::texture_atlas::TextureAtlasLayout>::track_assets does not exist: bevy_asset::server::AssetServerthread 'Encountered a panic in system `:
Compute Task Pool (4)bevy_asset::assets::Assets<bevy_render::mesh::mesh::Mesh>::track_assets477' panicked at `!
:/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rs17::
477Resource requested by bevy_asset::assets::Assets<bevy_asset::assets::LoadedUntypedAsset>::track_assets does not exist: bevy_asset::server::AssetServer:thread '
17Compute Task Pool (3)Encountered a panic in system `:
' panicked at Resource requested by bevy_asset::assets::Assets<bevy_text::font::Font>::track_assets does not exist: bevy_asset::server::AssetServerbevy_asset::assets::Assets<bevy_gltf::Gltf>::track_assets/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rs
`!
:477:17:
Encountered a panic in system `Resource requested by bevy_asset::assets::Assets<bevy_pbr::pbr_material::StandardMaterial>::track_assets does not exist: bevy_asset::server::AssetServerbevy_asset::assets::Assets<bevy_gizmos::LineGizmo>::track_assets
`!
thread 'Compute Task Pool (2)thread '' panicked at Encountered a panic in system `Compute Task Pool (7)/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rsbevy_asset::assets::Assets<bevy_text::font::Font>::track_assets' panicked at :`!
/home/ebola/.cargo/git/checkouts/bevy-c663206fcb0772cc/cdf844f/crates/bevy_ecs/src/system/system_param.rs477Encountered a panic in system `::bevy_asset::assets::Assets<bevy_pbr::pbr_material::StandardMaterial>::track_assets47717`!
::
17Resource requested by bevy_asset::assets::Assets<bevy_animation::AnimationClip>::track_assets does not exist: bevy_asset::server::AssetServerEncountered a panic in system `:

bevy_asset::assets::Assets<bevy_asset::assets::LoadedUntypedAsset>::track_assetsResource requested by bevy_asset::assets::Assets<bevy_audio::audio_source::AudioSource>::track_assets does not exist: bevy_asset::server::AssetServer`!

Encountered a panic in system `bevy_asset::assets::Assets<bevy_gltf::GltfMesh>::track_assets`!
Encountered a panic in system `bevy_asset::assets::Assets<bevy_sprite::texture_atlas::TextureAtlasLayout>::track_assets`!
Encountered a panic in system `bevy_asset::assets::Assets<bevy_audio::audio_source::AudioSource>::track_assets`!
Encountered a panic in system `bevy_asset::assets::Assets<bevy_animation::AnimationClip>::track_assets`!
Encountered a panic in system `bevy_app::main_schedule::Main::run_main`!
ebola@axiomatic:~/projects/rpg/crates/rpg_client$ ^C

@cornytrace
Copy link

@AxiomaticSemantics I can confirm that the issue still exists on main branch

@cornytrace
Copy link

cornytrace commented Mar 4, 2024

For me the error didn't stop occurring until I put both the main asset and the sub-assets in static Mutex<Vec<Handle<_>>>, only the main assets or only the sub assets still produced the issue.

Edit: even that doesn't solve the problem for me, it just makes it more rare.

@Testare
Copy link
Contributor

Testare commented May 8, 2024

I don't suppose any progress has been made on this issue?

@alice-i-cecile alice-i-cecile added the S-Needs-Investigation This issue requires detective work to figure out what's going wrong label May 16, 2024
@Aronry
Copy link

Aronry commented May 20, 2024

Welp, as far as I'm reading here, this issue can be "fixed" by never doing sub-asset loads, and only loading "Handle<< Gltf >>"s, and accessing elements from there. This is how "bevy_gltf_components" loads everything, for example. Seems to be working for me so far, will report back if I happen to see this error again.

@Testare
Copy link
Contributor

Testare commented May 21, 2024 via email

@ricky26
Copy link
Contributor

ricky26 commented May 25, 2024

I've done some investigation into this issue, and I think I know where the problem lies, but it's a tricky one to fix.

I managed to get the reproduction rate up by limiting bevy to handling one asset event per frame (which I don't think invalidates the investigation). I also managed to get it to happen by calling AssetServer::reload.

What I think is happening is this:

  • Loading multiple labelled assets from the same path results in the main asset actually getting loaded multiple times in AssetServer::load_internal, but sharing the same handle. (This is timing-dependent: all load operations have to be started before the first time the main asset finishes loading.) This seems like a bug, however it shouldn't be totally invalid, because it's only as bad as doing some superfluous reload()s.
  • When the loads complete, they race. If one of the Loaded events is handled in a later frame to the others, the crash will occur. All but the last load will be fine, because the loading process holds a copy of the handle. These completed loads will produce events which result in Assets<A>::insert being called with the loaded asset.
  • However, on the last load, once the event is written, the handle will be dropped. For labelled assets, this handle is a handle to the main asset - which we don't keep, and this causes the handle data to be dropped, which in turn removes the asset index from Assets<A>. For most assets, this is inhibited when the asset is in the middle of loading - however, this same grace doesn't apply for assets which have already loaded or failed to load at least once.

I've been pondering it a bit, and I've come up with a couple of semi-sensible solutions:

  • Make InternalAssetEvent::Loaded include a handle for the asset, so that it's kept alive until the insert has completed. This will possibly waste resources, since we're keeping the handle alive whilst loading is ongoing. (If this is done, the code-path that prevents loading assets from being dropped can be removed.)
  • Change the condition for "loading assets" to be a separate atomic integer, which we always increment when we start loading and decrement afterwards, no longer using the LoadState as a metric for when the handle is safe to drop. This will still result in the asset being successfully inserted, but at least the rest of the system considers the handle dead.

Either way, I think it's probably a good idea to remove Loading from LoadState and track it separately, because Loaded and Loading are not mutually-exclusive states.

@ricky26
Copy link
Contributor

ricky26 commented May 25, 2024

Turns out I was probably over-thinking the solution. Since the handle is an asset-server-managed, I can just check whether it's been removed from the list of asset IDs we know about, and skip inserting it into Assets<A>. This probably also removes the need for the workaround when dropping handles.

If anyone has the means and a project which triggers this issue, testing with that fix would be much appreciated.

@Testare
Copy link
Contributor

Testare commented May 25, 2024

I have a project, but with the new release coming up there are bound to be other problems when I switch to targeting main/your PR. But since I don't want to wait until 0.15 for this fix, I'mma give it a shot, maybe try temporarily deleting extraneous plugins until I get a pared down version that still reproduces the error.

@ricky26
Copy link
Contributor

ricky26 commented May 25, 2024

@Testare I've backported the change to 0.13.2, to make it a bit easier to test. You should be able to do:

[dependencies]
bevy = { git = "https://github.com/ricky26/bevy.git", branch = "bugfix/labelled-asset-loading-0.13" }

In your Cargo.toml, if you were using bevy 0.13 before.

@Testare
Copy link
Contributor

Testare commented May 25, 2024

Oh sorry didn't see this XD I appreciate the effort though! Regardless, the migration to main was rather smooth this time, and this'll probably give more accurate results anyways.

So using bevyengine/bevy:main, I was able to reproduce the error after a couple runs. In fact, the error was much longer than before, which would probably be a good thing for debugging. I could include that trace here but...

When I was tracking your PR, I was not able to reproduce the crash! I even had a loop something like for x in {1..40} ; do cargo run ; done , and it never crashed. I'm not doing the math for p < 0.05, but looks pretty likely this PR fixes the issue =]

@ricky26
Copy link
Contributor

ricky26 commented May 25, 2024

Thanks for taking the time to check @Testare. 🙂

@Testare
Copy link
Contributor

Testare commented May 25, 2024

Thanks for taking the time to fix! I would be quite sad to wait until 0.15 for this =]

@alice-i-cecile alice-i-cecile added S-Needs-Review Needs reviewer attention (from anyone!) to move forward and removed S-Needs-Investigation This issue requires detective work to figure out what's going wrong labels May 26, 2024
@alice-i-cecile alice-i-cecile removed this from the 0.14 milestone Jun 4, 2024
github-merge-queue bot pushed a commit that referenced this issue Jun 5, 2024
# Objective

- Fixes #10820.

## Solution

- Check that the asset ID to be inserted is still being managed.
- Since this route is only used by `AssetServer`-tracked handles, if the
`infos` map no longer contains the asset ID, all handles must have been
dropped. In this case, since nobody can be watching for the result,
we're safe to bail out. This avoids the panic when inserting the asset,
because when the handles are dropped, its slot in `Assets<A>` is
poisoned.
- Someone may be waiting for a labelled asset rather than the main
asset, these are handled with separate calls to `process_asset_load`, so
shouldn't cause any issues.
- Removed the workaround keeping asset info alive after the handle has
died, since we should no longer be trying to operate on any assets once
their handles have been dropped.

## Testing

- I added a `break` in `handle_internal_asset_events`
(`crates/bevy_asset/src/server/mod.rs` on line 1152). I don't believe
this should affect correctness, only efficiency, since it is effectively
only allowing one asset event to be handled per frame. This causes
examples like `animated_fox` to produce the issue fairly frequently.
- I wrote a small program which called `AssetServer::reload` and could
trigger it too.

---

## Changelog
- Fixed an issue which could cause a panic when loading an asset which
was no longer referenced.

---

## Remaining Work

~This needs more testing. I don't yet have a complete project that
reliably crashes without changes to bevy.~ We have at least one vote of
confidence so far from @Testare who had a project broken by this bug.

@cart, (sorry for the ping), I believe you added the code which delays
`remove_dropped`. Was there any other reason `track_assets` needed to
keep the dropped assets alive?
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-Assets Load files from disk to use for things like images, models, and sounds C-Bug An unexpected or incorrect behavior S-Needs-Review Needs reviewer attention (from anyone!) to move forward
Projects
None yet
Development

Successfully merging a pull request may close this issue.

9 participants