Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Move event traces to detailed_trace! #7732

Merged
merged 3 commits into from
Apr 11, 2023

Conversation

james7132
Copy link
Member

@james7132 james7132 commented Feb 17, 2023

Objective

Noticed while writing #7728 that we are using trace! logs in our event functions. This has shown to have significant overhead, even trace level logs are disabled globally, as seen in #7639.

Solution

Use the detailed_trace! macro introduced in #7639. Also removed the event_trace function that was only used in one location.


Changelog

Changed: Event trace logs are now feature gated behind the detailed-trace feature.

@james7132 james7132 added A-ECS Entities, components, systems, and events C-Performance A change motivated by improving speed, memory usage or compile times labels Feb 17, 2023
@danchia danchia self-requested a review February 17, 2023 22:10
Copy link
Contributor

@danchia danchia left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This generally seems like a good idea to me - this looks to be deeply engine internals logging that a user won't need to see (and they can always enable the feature flag if they must), and the EventReader seems like the kind of thing that will end up in a hot loop with many iterations.

@james7132 james7132 added this to the 0.11 milestone Feb 27, 2023
@james7132
Copy link
Member Author

This may have an impact outside of just user-facing events. Since #7713, this also impacts component removal:

https://github.com/james7132/bevy_asm_tests/blob/9fd5f20e252f6e4401d352a0b675098d7e010aff/results/entity_remove.s#L2340-L2356

@james7132
Copy link
Member Author

james7132 commented Mar 29, 2023

When setting up the benchmarks for #8251, I found nearly 5x improvements to event sending. Didn't impact event iteration.

events_send/100         time:   [90.729 ns 95.492 ns 101.49 ns]
                        change: [-79.753% -78.836% -77.676%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 9 outliers among 100 measurements (9.00%)
  9 (9.00%) high severe
events_send/1000        time:   [849.67 ns 860.86 ns 872.59 ns]
                        change: [-81.817% -81.597% -81.366%] (p = 0.00 < 0.05)
                        Performance has improved.
events_send/10000       time:   [8.7305 µs 8.8142 µs 8.9191 µs]
                        change: [-81.592% -81.491% -81.366%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 1 outliers among 100 measurements (1.00%)
  1 (1.00%) high severe
events_send/50000       time:   [43.570 µs 43.714 µs 43.883 µs]
                        change: [-81.689% -81.612% -81.532%] (p = 0.00 < 0.05)
                        Performance has improved.
Found 11 outliers among 100 measurements (11.00%)
  7 (7.00%) high mild
  4 (4.00%) high severe

events_iter/100         time:   [113.66 ns 113.78 ns 113.93 ns]
                        change: [-0.1316% +0.0158% +0.1647%] (p = 0.85 > 0.05)
                        No change in performance detected.
Found 10 outliers among 100 measurements (10.00%)
  3 (3.00%) high mild
  7 (7.00%) high severe
events_iter/1000        time:   [1.0906 µs 1.0921 µs 1.0941 µs]
                        change: [-0.0203% +0.1790% +0.4699%] (p = 0.19 > 0.05)
                        No change in performance detected.
Found 13 outliers among 100 measurements (13.00%)
  4 (4.00%) high mild
events_iter/10000       time:   [10.856 µs 10.867 µs 10.881 µs]
                        change: [-0.1066% +0.0310% +0.2378%] (p = 0.76 > 0.05)
                        No change in performance detected.
Found 8 outliers among 100 measurements (8.00%)
  7 (7.00%) high severe
                        change: [-0.5442% -0.1756% +0.0919%] (p = 0.34 > 0.05)
                        No change in performance detected.
Found 12 outliers among 100 measurements (12.00%)
  5 (5.00%) high mild
  7 (7.00%) high severe

@james7132 james7132 marked this pull request as ready for review March 29, 2023 20:33
@danchia
Copy link
Contributor

danchia commented Mar 29, 2023

Yikes (or yay?) 5x improvement!

Copy link
Contributor

@jdm jdm left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Makes sense, and appreciate the benchmarks.

@james7132 james7132 added the S-Ready-For-Final-Review This PR has been approved by the community. It's ready for a maintainer to consider merging it label Apr 11, 2023
@james7132 james7132 added this pull request to the merge queue Apr 11, 2023
Merged via the queue into bevyengine:main with commit d623731 Apr 11, 2023
james7132 added a commit to james7132/bevy_asm_tests that referenced this pull request Apr 11, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-ECS Entities, components, systems, and events C-Performance A change motivated by improving speed, memory usage or compile times S-Ready-For-Final-Review This PR has been approved by the community. It's ready for a maintainer to consider merging it
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

5 participants