Performance Issues in WASM Builds When Refocusing in Firefox #12126
Comments
camblomquist
added
C-Bug
|
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: |
TrialDragon
added
C-Performance
|
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: When using Bevy 0.12.0 I do not get the error. My Cargo.toml: My index.html Bevy main When I click the link printed by the error in the browser devtools it brings me to this line in the javascript: 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! |
|
From the stacktrace in #12126 (comment) my assumption is that this is not an issue from Bevy. The last call that triggers the issue is This should absolutely never cause recursive invocation of the supplied
So it might simply be that some very specific interaction causes Firefox to fire the closure passed into Keep in mind that I'm not familiar with Bevy's codebase at all and might have missed something. |
|
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. 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. |
|
I had some findings from earlier that I forgot to post here. Within 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 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,
})``` |
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:
|
|
Something interesting I found.
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. |
|
@daxpedda This PR addresses the bevy slowdown issue that we were experiencing, however Firefox's console continues to spam errors at us when the window is out of focus. These errors appear to occur when we ControlFlow::WaitUntil(end) => {
let start = Instant::now();
let cloned = self.clone();
if end <= start {
State::Wait {
start,
}
} else {
State::WaitUntil {
start,
end,
timeout: backend::Schedule::new_with_duration(
self.window(),
move || cloned.resume_time_reached(start, end),
end - start,
),
}
}
}This makes sense to me as an overall improvement, but I do not know if there are greater ramifications to this approach. I would like to PR this change to |
Unfortunately this is not really an acceptable solution. This would break
If you follow what "queues a global task" is, you will find that it must yield to the event loop. Nowhere does it specify that if the We could try and fix the bug by not using |
So my initial assumption turned out to be wrong, it was unrelated to the issue. The issue seems to be quite simple: closing the Here is the PR: rust-windowing/winit#3553. Let me know if this indeed fixes the problem. One thing I noticed is that something seems to be wrong with the time passed into |
Thanks for catching that, I'm not used to reading the standard. Knew I had to be missing something. |
|
A new version of Winit with the fix just got released: v0.29.13. I also filed a bug report at Firefox (it might be a bug in Chrome instead, we will see what happens): https://bugzilla.mozilla.org/show_bug.cgi?id=1883187. |
|
Beautiful, thanks much for your help
…On Sat, Mar 2, 2024, 4:08 AM daxpedda ***@***.***> wrote:
A new version of Winit with the fix just got released: v0.29.13
<https://crates.io/crates/winit/0.29.13>.
I also filed a bug report at Firefox (it might be a bug in Chrome instead,
we will see what happens):
https://bugzilla.mozilla.org/show_bug.cgi?id=1883187.
—
Reply to this email directly, view it on GitHub
<#12126 (comment)>,
or unsubscribe
<https://github.com/notifications/unsubscribe-auth/ABCINHWPRCI2OKJF7G4MH7LYWG6K3AVCNFSM6AAAAABD2K2M6OVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTSNZUG43TSMJXGE>
.
You are receiving this because you commented.Message ID:
***@***.***>
|
# Objective Fixes #12126 Notably this does not appear to fix the console error spam that appears to be coming from winit, only the performance bug that occurs when tabbing out and back into the game. ## Solution The winit event loop starts out as `ControlFlow::Wait` by default. When switching to `UpdateMode::Reactive` or `UpdateMode::ReactiveLowPower`, we repeatedly update this to `ControlFlow::WaitUntil(next)`. When switching back to `UpdateMode::Continuous`, the event loop is erroneously stuck at the latest `ControlFlow::WaitUntil(next)` that was issued. I also changed how we handle `Event::NewEvents` since the `StartCause` already tells us enough information to make that decision. This came about my debugging and I left it in as an improvement.
# Objective Fixes #12126 Notably this does not appear to fix the console error spam that appears to be coming from winit, only the performance bug that occurs when tabbing out and back into the game. ## Solution The winit event loop starts out as `ControlFlow::Wait` by default. When switching to `UpdateMode::Reactive` or `UpdateMode::ReactiveLowPower`, we repeatedly update this to `ControlFlow::WaitUntil(next)`. When switching back to `UpdateMode::Continuous`, the event loop is erroneously stuck at the latest `ControlFlow::WaitUntil(next)` that was issued. I also changed how we handle `Event::NewEvents` since the `StartCause` already tells us enough information to make that decision. This came about my debugging and I left it in as an improvement.
# Objective Fixes bevyengine#12126 Notably this does not appear to fix the console error spam that appears to be coming from winit, only the performance bug that occurs when tabbing out and back into the game. ## Solution The winit event loop starts out as `ControlFlow::Wait` by default. When switching to `UpdateMode::Reactive` or `UpdateMode::ReactiveLowPower`, we repeatedly update this to `ControlFlow::WaitUntil(next)`. When switching back to `UpdateMode::Continuous`, the event loop is erroneously stuck at the latest `ControlFlow::WaitUntil(next)` that was issued. I also changed how we handle `Event::NewEvents` since the `StartCause` already tells us enough information to make that decision. This came about my debugging and I left it in as an improvement.
|
For me, the new winit version removed the warning but did not improve the performance issue. For example: the deployed WASM build of bevy_game_template runs with 60 FPS in my Firefox, until I click outside for the first time. Afterwards, the "game" visibly stutters (FPS drop to ~3-10). Edit: for everyone stumbling over this after me. This is expected. #12239 fixed the performance issue, but will only come with the next Bevy release. The winit upgrade only fixed the spamming log message. |
|
The performance drop is a bevy issue and resolved with
#12239
…On Wed, Mar 13, 2024, 9:17 AM Niklas Eicker ***@***.***> wrote:
For me, the new winit version removed the warning but did not improve the
performance issue. For example: the deployed WASM build of
bevy_game_template <https://niklasei.github.io/bevy_game_template/> runs
with 60 FPS in my Firefox, until I click outside for the first time.
Afterwards, the "game" visibly stutters (FPS drop to ~3-10).
—
Reply to this email directly, view it on GitHub
<#12126 (comment)>,
or unsubscribe
<https://github.com/notifications/unsubscribe-auth/ABCINHQJ3IR6V6YOTL6QB2DYYB3XZAVCNFSM6AAAAABD2K2M6OVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTSOJUHA2DGOJZGI>
.
You are receiving this because you commented.Message ID:
***@***.***>
|
# Objective Fixes bevyengine#12126 Notably this does not appear to fix the console error spam that appears to be coming from winit, only the performance bug that occurs when tabbing out and back into the game. ## Solution The winit event loop starts out as `ControlFlow::Wait` by default. When switching to `UpdateMode::Reactive` or `UpdateMode::ReactiveLowPower`, we repeatedly update this to `ControlFlow::WaitUntil(next)`. When switching back to `UpdateMode::Continuous`, the event loop is erroneously stuck at the latest `ControlFlow::WaitUntil(next)` that was issued. I also changed how we handle `Event::NewEvents` since the `StartCause` already tells us enough information to make that decision. This came about my debugging and I left it in as an improvement.
|
EDIT: nope, actually a different bug that looks similar. |
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):
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.
The text was updated successfully, but these errors were encountered: