Performance Issues in WASM Builds When Refocusing in Firefox

[camblomquist]

Bevy 0.13

Firefox (version unknown) tested on Windows 10 and MacOS 13

I had found that frame rate visibly decreases in Firefox, starting at a stable 60fps when first launching and decreasing all the way into the lower teens if the window is put out of focus then back into focus. When the window is put out of focus, the frame rate increases back to nearly reasonable levels. This does not appear to happen in Chrome, only Firefox. Safari has not yet been tested. Seems similar to #7242 but in that case, it was a Chromium browser and there's a lot of conflicting information in there without clear resolution or direction.

When the performance drops, the console repeatedly logs the following error (taken from the breakout example):

Uncaught Error: closure invoked recursively or after being dropped
    __wbindgen_throw https://bevy-webgl2-examples.pages.dev/Games/breakout/wasm_example.js:2035
    __wbg_adapter_51 https://bevy-webgl2-examples.pages.dev/Games/breakout/wasm_example.js:237
    real https://bevy-webgl2-examples.pages.dev/Games/breakout/wasm_example.js:210

I had thought this error popped up during input events but that does not appear to be the case as the error may be logged even without input.

A profile of the game shows long stretches of "Jank" and high levels of GC but other parts of the profile show most of the frame time being JS. I don't really know how to read the profile so I may just be misinterpreting it.

Someone in the Discord recommended changing WinitSetting as a workaround

app
    .insert_resource(WinitSettings {
        focused_mode: UpdateMode::Continuous,
        unfocused_mode: UpdateMode::Continuous,
    })

I haven't had the opportunity to test this yet but if this does work, then it might be an issue with winit. I still felt it was worth documenting here for tracking.

[thebluefish]

Edit: On further investigation, this appears to be caused when the game (or tab?) dies and restarts, and is unrelated to the OP's issue.

I was able to get a better stack trace by enabling debug symbols and breaking on exception:

panicked at C:\Users\s33n\.cargo\registry\src\index.crates.io-6f17d22bba15001f\winit-0.29.11\src\platform_impl\web\event_loop\runner.rs:714:69:
already borrowed: BorrowMutError

Stack:

__wbg_get_imports/imports.wbg.__wbg_new_abda76e883ba8a5f@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:478:21
console_error_panic_hook::hook::he531542cb2a11f4d@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[11917]:0x12226e2
core::ops::function::Fn::call::h1b3a3bd68b7d52c4@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[82402]:0x1b8ec18
std::panicking::rust_panic_with_hook::h1e6ac5d404b8e31b@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[28162]:0x1864bc0
std::panicking::begin_panic_handler::{{closure}}::h24b0f4622f2766a5@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[33497]:0x1971f77
std::sys_common::backtrace::__rust_end_short_backtrace::h19f35d272c126e7c@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[81303]:0x1b8c596
rust_begin_unwind@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[43880]:0x1a97e82
core::panicking::panic_fmt::h87755523850ece9e@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[45132]:0x1aac145
core::cell::panic_already_borrowed::hdfd15bcb019b1598@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[42457]:0x1a7d66f
winit::platform_impl::platform::event_loop::runner::Shared::apply_control_flow::h0a2542bf92d1fda4@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[11987]:0x122d594
winit::platform_impl::platform::event_loop::runner::Shared::set_listener::{{closure}}::h7a2e10b8b744584c@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[29066]:0x18961f3
<dyn core::ops::function::FnMut<(A,)>+Output = R as wasm_bindgen::closure::WasmClosure>::describe::invoke::h2780faf478a86068@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[49860]:0x1ae6010
__wbg_adapter_51@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:237:10
real@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:210:20
regex_automata::nfa::thompson::builder::Builder::patch::hda9f81aa4e2ab4c7@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[15127]:0x13f005c
regex_automata::nfa::thompson::compiler::Compiler::c::ha5cc3249d565ed4e@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[520]:0x18b936
regex_automata::nfa::thompson::compiler::Compiler::c_at_least::ha1ca0da71f7b6e2f@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[817]:0x3ba476
regex_automata::nfa::thompson::compiler::Compiler::c::ha5cc3249d565ed4e@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[520]:0x18923e
regex_automata::nfa::thompson::compiler::Compiler::c_cap::ha5ac77b91b1add35@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[4008]:0xb23374
regex_automata::nfa::thompson::compiler::Compiler::c::ha5cc3249d565ed4e@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[520]:0x18954a
regex_automata::nfa::thompson::compiler::Compiler::c::ha5cc3249d565ed4e@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[520]:0x189628
regex_automata::nfa::thompson::compiler::Compiler::c_cap::ha5ac77b91b1add35@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[4008]:0xb23374
<core::iter::adapters::map::Map<I,F> as core::iter::traits::iterator::Iterator>::next::hbdacfcf900f91786@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[5231]:0xcc330c
regex_automata::nfa::thompson::compiler::Compiler::compile::h4143635c213a721a@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[1242]:0x57ac3d
regex_automata::meta::strategy::new::h09bb82f77c7d9b93@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[476]:0x48dff
regex_automata::meta::regex::Builder::build::h8c055e910a37e48c@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[1451]:0x634e5d
regex::builders::Builder::build_one_string::ha4a066d798839af7@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[4760]:0xc2fad6
regex::regex::string::Regex::new::h3f1e1a4b531a2fb6@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[18378]:0x156acff
<naga_oil::compose::preprocess::Preprocessor as core::default::Default>::default::h05bcda1ea4cf9833@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[4129]:0xb51f90
<naga_oil::compose::Composer as core::default::Default>::default::hb0f7a1f92b90b478@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[2795]:0x93ced1
bevy_render::render_resource::pipeline_cache::PipelineCache::new::h99005de2068fbc46@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[14173]:0x136cb67
<bevy_render::RenderPlugin as bevy_app::plugin::Plugin>::finish::haaa4c77178cdbd71@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[1812]:0x739326
bevy_app::app::App::finish::hcfe8cb00221c68ae@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[18033]:0x1546d18
bevy_winit::handle_winit_event::h3ece59e653fcb5e6@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[626]:0x2a4905
winit::platform_impl::platform::event_loop::EventLoop<T>::run::{{closure}}::h4ddb979efdb0fc26@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[19020]:0x15ade7f
winit::platform_impl::platform::event_loop::runner::Shared::handle_event::h958e3a01f9001cac@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[4253]:0xb7ff7f
winit::platform_impl::platform::event_loop::runner::Shared::request_redraw::he3c836ca676a301a@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[5964]:0xd8b13f
winit::platform_impl::platform::backend::animation_frame::AnimationFrameHandler::on_animation_frame::{{closure}}::h2f927ce8b2864c10@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[49854]:0x1ae5f46
<dyn core::ops::function::FnMut<()>+Output = R as wasm_bindgen::closure::WasmClosure>::describe::invoke::h5449f5c284d5b8bb@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[50126]:0x1ae82a6
__wbg_adapter_39@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:229:10
real@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:210:20
FrameRequestCallback*__wbg_get_imports/imports.wbg.__wbg_requestAnimationFrame_1820a8e6b645ec5a/<@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:1021:37
handleError@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:254:18
__wbg_get_imports/imports.wbg.__wbg_requestAnimationFrame_1820a8e6b645ec5a@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:1020:84
web_sys::features::gen_Window::Window::request_animation_frame::he5a2f9cd1cf6d957@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[42830]:0x1a84778
winit::platform_impl::platform::backend::animation_frame::AnimationFrameHandler::request::h010f975c78fe0941@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[32477]:0x1943109
winit::platform_impl::platform::window::Inner::request_redraw::h69ed68b570a79f34@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[43933]:0x1a98d80
winit::platform_impl::platform::async::dispatcher::Dispatcher<T>::dispatch::h7a1d2b2459c4cb27@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[33950]:0x1985182
bevy_winit::handle_winit_event::h3ece59e653fcb5e6@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[626]:0x2a56f1
winit::platform_impl::platform::event_loop::EventLoop<T>::run::{{closure}}::h4ddb979efdb0fc26@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[19020]:0x15ade7f
winit::platform_impl::platform::event_loop::runner::Shared::handle_event::h3551d95a79de6045@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[4444]:0xbc3f8f
winit::platform_impl::platform::event_loop::runner::Shared::set_listener::h20e5bb3dd9a9a5f5@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[795]:0x39e484
winit::platform_impl::platform::event_loop::window_target::EventLoopWindowTarget<T>::run::h9f1d8c15082519e0@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[53203]:0x1b004c6
winit::platform_impl::platform::event_loop::EventLoop<T>::run::h06e24916922d22d8@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[39865]:0x1a4174b
bevy_winit::winit_runner::h2efeb4dfd46e0702@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[894]:0x414c26
core::ops::function::FnOnce::call_once{{vtable.shim}}::h15ee873e6523aa96@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[47829]:0x1ad1002
bevy_app::app::App::run::h92048922ba290193@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[16298]:0x1484671
bevy_mre::main::h193be164b9592b2d@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[5557]:0xd20281
std::sys_common::backtrace::__rust_begin_short_backtrace::hfca521c36102dbc6@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[81307]:0x1b8c5be
std::rt::lang_start::{{closure}}::hcbfa9f944d499846@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[76428]:0x1b7de19
std::rt::lang_start_internal::h658afcf1f1425f65@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[23156]:0x171f347
main@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[47260]:0x1ac9465
@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:wasm-function[76420]:0x1b7dda5
__wbg_finalize_init@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:2122:10
__wbg_init@http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:2158:12
async*@http://127.0.0.1:8080/:21:5


bevy_mre-60876d34ec8755ff.js:494:21
    __wbg_error_f851667af71bcfc6 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:494
    he531542cb2a11f4d http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:19015626
    h1b3a3bd68b7d52c4 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:28896280
    h1e6ac5d404b8e31b http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:25578432
    h24b0f4622f2766a5 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:26681207
    h19f35d272c126e7c http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:28886422
    rust_begin_unwind http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:27885186
    h87755523850ece9e http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:27967813
    hdfd15bcb019b1598 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:27776623
    h0a2542bf92d1fda4 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:19060116
    h7a2e10b8b744584c http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:25780723
    <dyn core::ops::function::FnMut<(A,)>+Output = R as wasm_bindgen::closure::WasmClosure>::describe::invoke::h2780faf478a86068 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:28205072
    __wbg_adapter_51 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:237
    real http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:210
    hda9f81aa4e2ab4c7 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:20906076
    ha5cc3249d565ed4e http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:1620278
    ha1ca0da71f7b6e2f http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:3908726
    ha5cc3249d565ed4e http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:1610302
    ha5ac77b91b1add35 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:11678580
    ha5cc3249d565ed4e http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:1611082
    ha5cc3249d565ed4e http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:1611304
    ha5ac77b91b1add35 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:11678580
    <core::iter::adapters::map::Map<I,F> as core::iter::traits::iterator::Iterator>::next::hbdacfcf900f91786 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:13382412
    h4143635c213a721a http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:5745725
    h09bb82f77c7d9b93 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:298495
    h8c055e910a37e48c http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:6508125
    ha4a066d798839af7 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:12778198
    h3f1e1a4b531a2fb6 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:22457599
    <naga_oil::compose::preprocess::Preprocessor as core::default::Default>::default::h05bcda1ea4cf9833 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:11870096
    <naga_oil::compose::Composer as core::default::Default>::default::hb0f7a1f92b90b478 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:9686737
    h99005de2068fbc46 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:20368231
    <bevy_render::RenderPlugin as bevy_app::plugin::Plugin>::finish::haaa4c77178cdbd71 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:7574310
    hcfe8cb00221c68ae http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:22310168
    h3ece59e653fcb5e6 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:2771205
    h4ddb979efdb0fc26 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:22732415
    h958e3a01f9001cac http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:12058495
    he3c836ca676a301a http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:14201151
    h2f927ce8b2864c10 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:28204870
    <dyn core::ops::function::FnMut<()>+Output = R as wasm_bindgen::closure::WasmClosure>::describe::invoke::h5449f5c284d5b8bb http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:28213926
    __wbg_adapter_39 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:229
    real http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:210
    (Async: FrameRequestCallback)
    __wbg_requestAnimationFrame_1820a8e6b645ec5a http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:1021
    handleError http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:254
    __wbg_requestAnimationFrame_1820a8e6b645ec5a http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:1020
    he5a2f9cd1cf6d957 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:27805560
    h010f975c78fe0941 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:26489097
    h69ed68b570a79f34 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:27889024
    h7a1d2b2459c4cb27 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:26759554
    h3ece59e653fcb5e6 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:2774769
    h4ddb979efdb0fc26 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:22732415
    h3551d95a79de6045 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:12337039
    h20e5bb3dd9a9a5f5 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:3794052
    h9f1d8c15082519e0 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:28312774
    h06e24916922d22d8 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:27531083
    h2efeb4dfd46e0702 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:4279334
    h15ee873e6523aa96 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:28119042
    h92048922ba290193 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:21513841
    h193be164b9592b2d http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:13763201
    hfca521c36102dbc6 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:28886462
    hcbfa9f944d499846 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:28827161
    h658afcf1f1425f65 http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:24245063
    main http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:28087397
    <anonymous> http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff_bg.wasm:28827045
    __wbg_finalize_init http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:2122
    __wbg_init http://127.0.0.1:8080/bevy_mre-60876d34ec8755ff.js:2158
    <anonymous> http://127.0.0.1:8080/:21

[SnowdenWintermute]

A similar thing is happening for me on Firefox 123.0 on Manjaro Linux. I am using trunk to serve the application. My console continuously prints the error log:

Uncaught Error: closure invoked recursively or after being dropped

When using Bevy 0.12.0 I do not get the error.

My Cargo.toml:

[package]
name = "bevy-yew-test"
version = "0.1.0"
edition = "2021"

[dependencies]
bevy = "0.13.0" 
wasm-bindgen = "0.2.91"

My index.html

<html>
  <body class="h-screen w-screen">
    <link data-trunk rel="copy-dir" href="assets/" />
    <link data-trunk href="./style/output.css" rel="css" />
    <canvas id="bevy" stlye="!w-screen !h-screen"></canvas>
  </body>
</html>

Bevy main

use bevy::prelude::*;
pub fn bevy_main() {
    App::new()
        .add_plugins(DefaultPlugins.set(WindowPlugin {
            primary_window: Some(Window {
                canvas: Some("#bevy".to_string()),
                ..Default::default()
            }),
            ..default()
        }))
        .run();
}

When I click the link printed by the error in the browser devtools it brings me to this line in the javascript:

imports.wbg.__wbindgen_throw = function(arg0, arg1) {
        throw new Error(getStringFromWasm0(arg0, arg1));
    };

If I do not click anywhere outside the Bevy window the error doesn't happen, but as soon as I click out of the window either inside the browser or otherwise, it starts. The issue doesn't happen on Chromium or Brave. Adding the WinitSettings resource as suggested works to fix the problem. Thank you to s33n on the discord for linking me to this issue and providing that fix!

[daxpedda]

From the stacktrace in #12126 (comment) my assumption is that this is not an issue from Bevy.
Considering that the fix seems to be to use unfocused_mode: UpdateMode::Continuous, I have the following theory:

The last call that triggers the issue is winit::platform_impl::platform::event_loop::runner::Shared::apply_control_flow, which schedules the next tick. This is done in Scheduler::new() (which doesn't appear in the stacktrace maybe because its inlined?), which schedules it via setTimeout() (at least on Firefox).

This should absolutely never cause recursive invocation of the supplied Closures, but we have encountered bugs before:

• https://bugzilla.mozilla.org/show_bug.cgi?id=1855409
• https://bugzilla.mozilla.org/show_bug.cgi?id=1451717

So it might simply be that some very specific interaction causes Firefox to fire the closure passed into setTimeout() immediately in place instead of after finishing the current execution. This would be a bug in Firefox!
Unfortunately this is really hard to debug, which is why it would be important to boil this down to a very small reproducible example, one that doesn't involve Bevy.

Keep in mind that I'm not familiar with Bevy's codebase at all and might have missed something.

[camblomquist]

A bisect puts the first bad commit as aeab690 which just changed the default update mode config. I don't know if that pins the issue in bevy or winit. It looks like my MRE needs to be updated to explicitly use ReactiveLowPower to get a better read.
The only place where the wait value is referenced is in run_app_update_if_should within bevy_winit.

match config.update_mode(focused) {
    UpdateMode::Continuous => {
        runner_state.redraw_requested = true;
    }
    UpdateMode::Reactive { wait } | UpdateMode::ReactiveLowPower { wait } => {
        // TODO(bug): this is unexpected behavior.
        // When Reactive, user expects bevy to actually wait that amount of time,
        // and not potentially infinitely depending on plateform specifics (which this does)
        // Need to verify the plateform specifics (whether this can occur in
        // rare-but-possible cases) and replace this with a panic or a log warn!
        if let Some(next) = runner_state.last_update.checked_add(*wait) {
            runner_state.scheduled_update = Some(next);
            event_loop.set_control_flow(ControlFlow::WaitUntil(next));
        } else {
            runner_state.scheduled_update = None;
            event_loop.set_control_flow(ControlFlow::Wait);
        }
    }
}

The default wait time is 1/60th of a second. Adding that to the last update time (which would've been 1/60th of a second ago,) it might end up giving a negative or zero wait time. whatwg requires that negative times are set to zero but as far as I can tell it doesn't outright say that it must yield to the event loop despite implying that it must in a few sections. I'd have a hard time believing that Firefox would go against the grain here.

[thebluefish]

I had some findings from earlier that I forgot to post here.

---

Within apply_control_flow I can make a change that resolves both pieces of this issue:

let delay = if end <= start {
    Duration::from_millis(1)
} else {
    end - start
};

I can also make a change that resolves just the error log spam:

fn apply_control_flow(&self) {
    let new_state = if self.exiting() {
        State::Exit
    } else {
        let cloned = self.clone();
        State::Poll {
            request: backend::Schedule::new(
                self.poll_strategy(),
                self.window(),
                move || cloned.poll(),
            ),
        }
    };

    if let RunnerEnum::Running(ref mut runner) = *self.0.runner.borrow_mut() {
        runner.state = new_state;
    }
}

While reducing bevy's framerate to what we experience with the root behavior. Pretty much any variation of change that causes Bevy's UpdateMode to differ from the underlying ControlFlow representation seems to cause the same slowdown behavior. which leads me to think we have some sort of timing problem. It also leads me to suspect the slowdown issue is only tangentially related to the console error spam.

---

Since aeab690 just changes the default config mode from the one we know works, any chance we could bisect the commit that causes this issue with

    .insert_resource(WinitSettings {
        focused_mode: UpdateMode::Continuous,
        unfocused_mode: UpdateMode::Continuous,
    })```

[thebluefish]

So it might simply be that some very specific interaction causes Firefox to fire the closure passed into setTimeout() immediately in place instead of after finishing the current execution. This would be a bug in Firefox!

I checked this by adding some console logging

fn apply_control_flow(&self) {
    let new_state = if self.exiting() {
        State::Exit
    } else {
        match self.control_flow() {
            ControlFlow::Poll => {
                let cloned = self.clone();
                State::Poll {
                    request: backend::Schedule::new(
                        self.poll_strategy(),
                        self.window(),
                        move || cloned.poll(),
                    ),
                }
            }
            ControlFlow::Wait => State::Wait {
                start: Instant::now(),
            },
            ControlFlow::WaitUntil(end) => {
                let start = Instant::now();

                let delay = if end <= start {
                    Duration::from_millis(0)
                } else {
                    end - start
                };

                let cloned = self.clone();

                warn!("State::WaitUntil");
                State::WaitUntil {
                    start,
                    end,
                    timeout: backend::Schedule::new_with_duration(
                        self.window(),
                        move || {
                            warn!("resume_time_reached");
                            cloned.resume_time_reached(start, end)
                        },
                        delay,
                    ),
                }
            }
        }
    };

    warn!("runner.state = new_state");
    if let RunnerEnum::Running(ref mut runner) = *self.0.runner.borrow_mut() {
        runner.state = new_state;
    }
}

These always come in the order:

• State::WaitUntil
• runner.state = new_state
• resume_time_reached

[camblomquist]

Finished the bisect with the explicit WinitSettings. This time I landed on 79021c7
from #11227

[thebluefish]

Something interesting I found.

Event::AboutToWait is being sent at approximately framerate (~60 times per second on my machine) before the issue starts. This blows up significantly to hundreds per second upon first clicking away.

Normal behavior:

Bad behavior:

Note that there still appears to be "normal" frame times peppered throughout the bad log. I'm yet unsure where these other events are coming from.

Edit: After further measurements, it appears to increase to ~300 times per second while out of focus and ~1200 times per second while in focus.