Events aren't being cleared properly

gwafotapa commented 12 months ago

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.

torsteingrindvik commented 12 months ago

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

5tr1k3r commented 12 months ago

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

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

jnhyatt commented 12 months ago

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.

tim-blackbird commented 12 months ago

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.

uvizhe commented 12 months ago

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?

tim-blackbird commented 12 months ago

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.

gwafotapa commented 12 months ago

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.

tim-blackbird commented 12 months ago

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

Azorlogh commented 11 months ago

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.

teodosin commented 11 months ago

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.

maniwani commented 10 months ago

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.

MJohnson459 commented 10 months ago

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.

AlexAegis commented 10 months ago

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

MeoMix commented 10 months ago

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.

MJohnson459 commented 10 months ago

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.

MeoMix commented 10 months ago

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.

gwafotapa commented 10 months ago

@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.

MeoMix commented 10 months ago

@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!

gwafotapa commented 10 months ago

@MeoMix The world is small after all :)

MJohnson459 commented 10 months ago

@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.

CaptainOachkatzl commented 10 months ago

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

alice-i-cecile commented 9 months ago

@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.

maniwani commented 9 months ago

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.

bevyengine / bevy