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

marcelchampagne commented 11 months ago

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 https://github.com/bevyengine/bevy/issues/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.

Testare commented 11 months ago

I've been getting this error as well

Testare commented 10 months ago

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

mockersf commented 9 months ago

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

marcelchampagne commented 9 months ago

@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 commented 9 months ago

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.

ghost commented 8 months ago

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 commented 8 months ago

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

cornytrace commented 8 months ago

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 commented 6 months ago

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

Aronry commented 5 months ago

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 commented 5 months ago

I would categorize that as a workaround more than a fix, especially since that means that you can no longer just store a handle for the asset you want, you need to store the path to the sub asset with it.

On Mon, May 20, 2024, 11:39 AM Aronry @.***> wrote:

Welp, as far as I'm reading here, this issue can be "fixed" by never doing sub-asset loads, and only loading "Handle"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.

— Reply to this email directly, view it on GitHub https://github.com/bevyengine/bevy/issues/10820#issuecomment-2120997851, or unsubscribe https://github.com/notifications/unsubscribe-auth/AA7EGS34OKL7UMUJCRJHHLLZDI7OTAVCNFSM6AAAAABAB7ILNKVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCMRQHE4TOOBVGE . You are receiving this because you commented.Message ID: @.***>

ricky26 commented 5 months ago

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 commented 5 months ago

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 commented 5 months ago

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 commented 5 months ago

@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 commented 5 months ago

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 commented 5 months ago

Thanks for taking the time to check @Testare. :slightly_smiling_face:

Testare commented 5 months ago

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

bevyengine / bevy