bevy icon indicating copy to clipboard operation
bevy copied to clipboard

Events aren't being cleared properly

Open gwafotapa opened this issue 2 years ago • 20 comments

Bevy version 0.12.1

Events are not silently dropped the turn after they're sent but instead accumulate in the EventReader's buffer.

What I did

Here's an example:

use std::cmp::Ordering;

use bevy::prelude::*;

#[derive(Event)]
struct Ev;

fn send(mut evw: EventWriter<Ev>) {
    evw.send(Ev);
}

fn read(mut evr: EventReader<Ev>) {
    println!("{}", evr.iter().count());
}

// Generates a condition returning true on the nth frame
fn nth_frame(n: u32) -> impl FnMut() -> bool + Clone {
    let mut run = 1;
    move || match run.cmp(&n) {
        Ordering::Greater => false,
        Ordering::Equal => {
            run += 1;
            true
        }
        Ordering::Less => {
            run += 1;
            false
        }
    }
}

fn main() {
    App::new()
        .add_event::<Ev>()
        .add_plugins(DefaultPlugins)
        .add_systems(Update, send)
        .add_systems(Update, read.after(send).run_if(nth_frame(10)))
        .run();
}

What went wrong

Under version 0.11.3, this prints 2 as expected but under 0.12.1 I'm getting 10.

gwafotapa avatar Dec 05 '23 11:12 gwafotapa

I think I've found this too and I was confused if I had misunderstood events or if it was a bug.

For me it was this:

  • Some system in frame n generates an event
  • A system that rarely runs because of run conditions still gets the event much later, in e.g. frame n+100

Sounds like this can be caused if events are buffered instead of cleared

torsteingrindvik avatar Dec 05 '23 11:12 torsteingrindvik

https://github.com/bevyengine/bevy/issues/10860

Seems like a decent amount of people stumbled over it, maybe something needs to be done.

5tr1k3r avatar Dec 05 '23 13:12 5tr1k3r

I agree something needs to be done, this is a tremendous footgun, and not just because the behavior changes. I know there was discussion about this being the "right" way to do this in the ecs dev channel somewhere, but at this point I think it's obvious that this isn't what users are expecting.

jnhyatt avatar Dec 05 '23 18:12 jnhyatt

Agreed. Even experienced Bevy devs are struggling to use events correctly, so something must be done.

It is easier said than done, however. EventReaders keep track of which events they've read with a cursor stored in the system. We'll somehow need to update these cursors when the systems aren't even running or change how events are tracked entirely.

tim-blackbird avatar Dec 05 '23 21:12 tim-blackbird

I wish this change in behavior was announced 😔

Now, shall I adopt my code to the new behavior or wait for a final decision on this?

uvizhe avatar Dec 06 '23 09:12 uvizhe

The issue description is a little strange.

Under version 0.11.3, this prints 2 as expected

Wouldn't you expect it to be 1? That is what gets printed with nth_frame(1) i.e reading events every frame.

The example given reads old events in both 0.11.3 and 0.12.1 The difference is that 0.12.1 can buffer events for more than 2 frames but with 0.11.3 you're still getting an outdated event from the previous frame.

tim-blackbird avatar Dec 06 '23 13:12 tim-blackbird

According to the doc, this is the expected behavior.

When an event is generated, some systems may already have run in the current frame. Thus, it's already too late for them to read that event this frame. That's why events persist until the end of the next frame. And this is why 2 is the expected behavior in the example.

gwafotapa avatar Dec 06 '23 14:12 gwafotapa

I see, it was more clearly documented than I thought. fair enough.

tim-blackbird avatar Dec 06 '23 14:12 tim-blackbird

This new behavior synergizes pretty poorly with .run_if :confused: Would it be possible to have a method on EventReader to read events' emission timestamp or frame-count? That way we would be able to easily filter out the older ones.

Azorlogh avatar Dec 14 '23 17:12 Azorlogh

Adding my 2 cents that a change like this should be documented, with suggested workarounds if it is intended to stay this way and not just a bug. I am surprised this isn't talked about more, since problems arise the moment any systems with run conditions read from the same events.

teodosin avatar Dec 18 '23 20:12 teodosin

To add some context, the lifetime change was deliberate and was made in #10077. (In hindsight, it was a mistake to include it in the 0.12.1 release.) I just didn't see that the EventReader docs needed to be changed.

Would it be possible to have a method on EventReader to read events' emission timestamp or frame-count? That way we would be able to easily filter out the older ones.

This was pretty much the plan (see the future work section of #10077).

edit: The specific idea is to control a "visible event timestamp range" globally for all event readers.

  • For systems running in Main, the range would be the virtual timespan of the previous frame.
  • For systems running in FixedMain, the range would be the virtual timespan of the previous tick.
  • EventReader could have a method to override this if users want a few to see different spans of the still-buffered events.

If y'all want a "quick and dirty" workaround, app.remove_resource::<EventUpdateSignal>() (edit: after plugins are added) will recover the <=0.12.0 behavior.

maniwani avatar Jan 10 '24 17:01 maniwani

A small correction that the fix should be app.world.remove_resource::<EventUpdateSignal>();. Without this change I was experience a memory leak even after manually draining all the events I was using.


On a personal note it's a bit disappointing #10077 was merged when it was known it would cause infinite memory usage in some circumstances. The fact this change wasn't even in the patch notes or migration guide just hurt more.

Obviously bevy is still under heavy development so things are expected to break and it is only because it normally does such a good job at making updates feel safe that this issue stands out so much. In the future I hope we can be more careful with such big changes.

MJohnson459 avatar Jan 19 '24 16:01 MJohnson459

I think I've ran into this problem, I have a system that zooms the camera in and out, reading mousewheel events. And I turn it off using run_if when the egui context is active so I don't zoom my main camera if I'm just scrolling an egui scroll area. As soon as egui lets go of my mouse and the system runs again, all the mousewheel events are there and my zoom level snaps to wheverever it would've been if I didn't disable the system

AlexAegis avatar Jan 19 '24 22:01 AlexAegis

Just confirming my understanding here, sorry for the noise. People in this thread are saying that the default behavior of the Events no longer plays nice with run_if after the referenced PR merged.

I want to confirm that, while true, the behavior of Events is now aligned with the behavior of change detection, right? If one prevents a system from running via run_if, and that system relies on Added<_> or Changed<_>, then that change detection is not cleared until the system has a chance to run again in the future. Additionally, when considering that RemovedComponents<_> relies on Events, not change detection, the line between the two concepts for the lifecycle of a mutated Component was already quite blurry.

I'm not trying to be dismissive of the pain caused by this change. I agree things are in a tough spot. I just want to confirm that, from a different perspective, this change was good and brought aspects of Bevy more into alignment with itself. It would be unfortunate if we were to make adjustments to Events, without affecting change detection, that resulted in these behaviors diverging again in the future.

MeoMix avatar Jan 24 '24 16:01 MeoMix

I believe you are almost correct. Consider this snippet:

fn pan_camera(
    mut ev_motion: EventReader<MouseMotion>,
    input_mouse: Res<Input<MouseButton>>,
    query: Query<Entity, Changed<Something>>,
) {
...
    if input_mouse.pressed(pan_button) {
        for ev in ev_motion.read() {
            pan += ev.delta;
        }

        for e in query.iter() {
            // do something
        }
    }

In the case where the mouse is pressed, the behaviour of the query and the event reader are now the same. All of the motion events since the last time the system ran are iterated through, just as all of the changed entities are.

However in the case where the mouse is not pressed, the behaviour differs. For the query, it will be emptied automatically but for the event reader it won't. This means that you need to manually empty the event reader in every system, if you don't care about the events that call (by e.g. adding else { ev_motion.clear();}). If any of these are missed, you can get funky behaviour such as the panning based on all motion since the last mouse click and worse you can have unbounded memory and hit OOM.

...at least, that is my understanding of the issue. I could be wrong w.r.t. the query as I don't used fixed updates but I believe that is how it works based on the docs and some testing.

MJohnson459 avatar Jan 24 '24 17:01 MJohnson459

I believe you are almost correct. Consider this snippet:

fn pan_camera(
    mut ev_motion: EventReader<MouseMotion>,
    input_mouse: Res<Input<MouseButton>>,
    query: Query<Entity, Changed<Something>>,
) {
...
    if input_mouse.pressed(pan_button) {
        for ev in ev_motion.read() {
            pan += ev.delta;
        }

        for e in query.iter() {
            // do something
        }
    }

In the case where the mouse is pressed, the behaviour of the query and the event reader are now the same. All of the motion events since the last time the system ran are iterated through, just as all of the changed entities are.

However in the case where the mouse is not pressed, the behaviour differs. For the query, it will be emptied automatically but for the event reader it won't. This means that you need to manually empty the event reader in every system, if you don't care about the events that call (by e.g. adding else { ev_motion.clear();}). If any of these are missed, you can get funky behaviour such as the panning based on all motion since the last mouse click and worse you can have unbounded memory and hit OOM.

...at least, that is my understanding of the issue. I could be wrong w.r.t. the query as I don't used fixed updates but I believe that is how it works based on the docs and some testing.

Got it. Thanks for the clarification. I agree that additional condition of needing to read events, not simply run the system that declares it is interested in the events, is especially difficult to manage. That isn't something I'd encountered yet with my app, so is good to know.

MeoMix avatar Jan 24 '24 17:01 MeoMix

@MJohnson459 The scenario from your code snippet is different from having a run_if condition on the system.

I've noticed that for queries with filter Changed, change detection happens whenever the system runs regardless of the query being iterated or not. However, change detection does not happen if the system does not run.

This means that if you replace the condition if input_mouse.pressed(pan_button) at the beginning of your code snippet by a run_if condition on the system, I believe you will observe the same behavior for both the query and the event reader. So I would say that @MeoMix is correct that the behaviours of events and change detection are now more aligned.

I don't know about RemovedComponents which I haven't used.

gwafotapa avatar Jan 24 '24 21:01 gwafotapa

@gwafotapa Wait.. you're the Wafo Tapa, aren't you?! I didn't expect to run into an ex-pro MTG player in a Bevy development thread. :) Big fan of you from back in the day. I've been playing for ~20 years, seen you around at a few GPs, and I was watching LSV cube on my lunch break when you chimed in here :)

Anyway. Sorry for the off-topic comment. Just a bit shocked!

MeoMix avatar Jan 24 '24 22:01 MeoMix

@MeoMix The world is small after all :)

gwafotapa avatar Jan 25 '24 08:01 gwafotapa

@gwafotapa right, they are definitely more aligned than previous. The example was just to show the remaining case where they aren't.

It seems if we clean the events at the end of a system call then they would be identical. And add a (configurable) max size to the event queue in case the system isn't called often to avoid unbounded memory.

MJohnson459 avatar Jan 25 '24 11:01 MJohnson459

If y'all want a "quick and dirty" workaround, app.remove_resource::<EventUpdateSignal>() (edit: after plugins are added) will recover the <=0.12.0 behavior.

notes for this fix:

  • as somebody else mentioned, it needs to be app.world.remove_resource::<EventUpdateSignal>()
  • you have to include bevy_ecs to your Cargo.toml to have access to the bevy_ecs::event::EventUpdateSignal struct

CaptainOachkatzl avatar Jan 30 '24 21:01 CaptainOachkatzl

@maniwani is this particular bug fixed now? I know we're not at "ideal final form" yet, but I seem to remember the cache-clearing bug getting fixed in 0.13.

alice-i-cecile avatar Feb 29 '24 22:02 alice-i-cecile

Is this particular bug fixed now? I know we're not at "ideal final form" yet, but I seem to remember the cache-clearing bug getting fixed in 0.13.

I believe so. 0.12.1 had a bug where events weren't getting dropped at all, and that was fixed by #11528, which should be in 0.13. So events still live longer than they did in 0.12, but they shouldn't just accumulate forever.

maniwani avatar Mar 01 '24 22:03 maniwani