bevy/crates/bevy_diagnostic/src/log_diagnostics_plugin.rs
Christopher Durham c19aa5939d Add Exponential Moving Average into diagnostics (#4992)
# Objective

- Add Time-Adjusted Rolling EMA-based smoothing to diagnostics.
- Closes #4983; see that issue for more more information.

## Terms

- EMA - [Exponential Moving Average](https://en.wikipedia.org/wiki/Moving_average#Exponential_moving_average)
- SMA - [Simple Moving Average](https://en.wikipedia.org/wiki/Moving_average#Simple_moving_average)

## Solution

- We use a fairly standard approximation of a true EMA where $EMA_{\text{frame}} = EMA_{\text{previous}} + \alpha \left( x_{\text{frame}} - EMA_{\text{previous}} \right)$ where $\alpha = \Delta t / \tau$ and $\tau$ is an arbitrary smoothness factor. (See #4983 for more discussion of the math.)
- The smoothness factor is here defaulted to $2 / 21$; this was chosen fairly arbitrarily as supposedly related to the existing 20-bucket SMA.
- The smoothness factor can be set on a per-diagnostic basis via `Diagnostic::with_smoothing_factor`.

---

## Changelog

### Added

- `Diagnostic::smoothed` - provides an exponentially smoothed view of a recorded diagnostic, to e.g. reduce jitter in frametime readings.

### Changed
- `LogDiagnosticsPlugin` now records the smoothed value rather than the raw value.
  - For diagnostics recorded less often than every 0.1 seconds, this change to defaults will have no visible effect.
  - For discrete diagnostics where this smoothing is not desirable, set a smoothing factor of 0 to disable smoothing.
  - The average of the recent history is still shown when available.
2022-10-24 13:46:37 +00:00

133 lines
4.3 KiB
Rust

use super::{Diagnostic, DiagnosticId, Diagnostics};
use bevy_app::prelude::*;
use bevy_ecs::system::{Res, ResMut, Resource};
use bevy_log::{debug, info};
use bevy_time::{Time, Timer, TimerMode};
use bevy_utils::Duration;
/// An App Plugin that logs diagnostics to the console
pub struct LogDiagnosticsPlugin {
pub debug: bool,
pub wait_duration: Duration,
pub filter: Option<Vec<DiagnosticId>>,
}
/// State used by the [`LogDiagnosticsPlugin`]
#[derive(Resource)]
struct LogDiagnosticsState {
timer: Timer,
filter: Option<Vec<DiagnosticId>>,
}
impl Default for LogDiagnosticsPlugin {
fn default() -> Self {
LogDiagnosticsPlugin {
debug: false,
wait_duration: Duration::from_secs(1),
filter: None,
}
}
}
impl Plugin for LogDiagnosticsPlugin {
fn build(&self, app: &mut App) {
app.insert_resource(LogDiagnosticsState {
timer: Timer::new(self.wait_duration, TimerMode::Repeating),
filter: self.filter.clone(),
});
if self.debug {
app.add_system_to_stage(CoreStage::PostUpdate, Self::log_diagnostics_debug_system);
} else {
app.add_system_to_stage(CoreStage::PostUpdate, Self::log_diagnostics_system);
}
}
}
impl LogDiagnosticsPlugin {
pub fn filtered(filter: Vec<DiagnosticId>) -> Self {
LogDiagnosticsPlugin {
filter: Some(filter),
..Default::default()
}
}
fn log_diagnostic(diagnostic: &Diagnostic) {
if let Some(value) = diagnostic.smoothed() {
if diagnostic.get_max_history_length() > 1 {
if let Some(average) = diagnostic.average() {
info!(
target: "bevy diagnostic",
// Suffix is only used for 's' or 'ms' currently,
// so we reserve two columns for it; however,
// Do not reserve columns for the suffix in the average
// The ) hugging the value is more aesthetically pleasing
"{name:<name_width$}: {value:>11.6}{suffix:2} (avg {average:>.6}{suffix:})",
name = diagnostic.name,
suffix = diagnostic.suffix,
name_width = crate::MAX_DIAGNOSTIC_NAME_WIDTH,
);
return;
}
}
info!(
target: "bevy diagnostic",
"{name:<name_width$}: {value:>.6}{suffix:}",
name = diagnostic.name,
suffix = diagnostic.suffix,
name_width = crate::MAX_DIAGNOSTIC_NAME_WIDTH,
);
}
}
fn log_diagnostics_system(
mut state: ResMut<LogDiagnosticsState>,
time: Res<Time>,
diagnostics: Res<Diagnostics>,
) {
if state.timer.tick(time.raw_delta()).finished() {
if let Some(ref filter) = state.filter {
for diagnostic in filter.iter().flat_map(|id| {
diagnostics
.get(*id)
.filter(|diagnostic| diagnostic.is_enabled)
}) {
Self::log_diagnostic(diagnostic);
}
} else {
for diagnostic in diagnostics
.iter()
.filter(|diagnostic| diagnostic.is_enabled)
{
Self::log_diagnostic(diagnostic);
}
}
}
}
fn log_diagnostics_debug_system(
mut state: ResMut<LogDiagnosticsState>,
time: Res<Time>,
diagnostics: Res<Diagnostics>,
) {
if state.timer.tick(time.raw_delta()).finished() {
if let Some(ref filter) = state.filter {
for diagnostic in filter.iter().flat_map(|id| {
diagnostics
.get(*id)
.filter(|diagnostic| diagnostic.is_enabled)
}) {
debug!("{:#?}\n", diagnostic);
}
} else {
for diagnostic in diagnostics
.iter()
.filter(|diagnostic| diagnostic.is_enabled)
{
debug!("{:#?}\n", diagnostic);
}
}
}
}
}