Merge branch 'xMAC94x/clock' into 'master'

massivly switch clock algorithm.

See merge request veloren/veloren!1499
This commit is contained in:
Marcel 2020-11-10 22:12:12 +00:00
commit 696f607a70
17 changed files with 197 additions and 122 deletions

View File

@ -65,6 +65,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
- Switched to a Whittaker map for better tree spawning patterns
- Switched to procedural snow cover on trees
- Significantly improved terrain generation performance
- Significantly stabilized the game clock, to produce more "constant" TPS
### Removed

35
Cargo.lock generated
View File

@ -4091,6 +4091,16 @@ version = "0.5.2"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "6e63cff320ae2c57904679ba7cb63280a3dc4613885beafb148ee7bf9aa9042d"
[[package]]
name = "spin_sleep"
version = "1.0.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "2a98101bdc3833e192713c2af0b0dd2614f50d1cf1f7a97c5221b7aac052acc7"
dependencies = [
"once_cell",
"winapi 0.3.9",
]
[[package]]
name = "static_assertions"
version = "1.1.0"
@ -4593,16 +4603,7 @@ checksum = "6f70411ba0d11c4aee042b1c73e68086322a293f8038c53ac95d36319c91ec19"
dependencies = [
"tracing-core",
"tracing-subscriber",
"tracy-client 0.9.0",
]
[[package]]
name = "tracy-client"
version = "0.8.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "650c280019cd1a841752d50f6a834216a2c8a810aeb18bdd48054be23cacd8a6"
dependencies = [
"tracy-client-sys 0.9.0",
"tracy-client",
]
[[package]]
@ -4611,16 +4612,7 @@ version = "0.9.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "eb214203bffe8cefe9bc0dfc12140f85e8d59b42e1f52f696071fdf8595e066a"
dependencies = [
"tracy-client-sys 0.10.0",
]
[[package]]
name = "tracy-client-sys"
version = "0.9.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "c07e4636dad390858d247cf2633eaea90e67d7e21151cd476bbfd070d321279f"
dependencies = [
"cc",
"tracy-client-sys",
]
[[package]]
@ -4905,9 +4897,10 @@ dependencies = [
"slab",
"specs",
"specs-idvs",
"spin_sleep",
"sum_type",
"tracing",
"tracy-client 0.8.0",
"tracy-client",
"vek 0.12.0",
]

View File

@ -26,7 +26,7 @@ fn main() {
info!("Starting chat-cli...");
// Set up an fps clock.
let mut clock = Clock::start();
let mut clock = Clock::new(Duration::from_millis(1000 / TPS));
println!("Enter your username");
let username = read_input();
@ -71,11 +71,7 @@ fn main() {
client.send_chat(msg)
}
let events = match client.tick(
comp::ControllerInputs::default(),
clock.get_last_delta(),
|_| {},
) {
let events = match client.tick(comp::ControllerInputs::default(), clock.dt(), |_| {}) {
Ok(events) => events,
Err(err) => {
error!("Error: {:?}", err);
@ -104,6 +100,6 @@ fn main() {
client.cleanup();
// Wait for the next tick.
clock.tick(Duration::from_millis(1000 / TPS));
clock.tick();
}
}

View File

@ -38,11 +38,12 @@ sum_type = "0.2.0"
authc = { git = "https://gitlab.com/veloren/auth.git", rev = "b943c85e4a38f5ec60cd18c34c73097640162bfe" }
slab = "0.4.2"
enum-iterator = "0.6"
spin_sleep = "1.0"
num-traits = "0.2"
num-derive = "0.3"
# Tracy
tracy-client = { version = "0.8.0", optional = true }
tracy-client = { version = "0.9.0", optional = true }
[dev-dependencies]
criterion = "0.3"

View File

@ -1,63 +1,142 @@
use crate::span;
use std::{
thread,
collections::VecDeque,
time::{Duration, Instant},
};
const CLOCK_SMOOTHING: f64 = 0.9;
/// This Clock tries to make this tick a constant time by sleeping the rest of
/// the tick
/// - if we actually took less time than we planned: sleep and return planned
/// time
/// - if we ran behind: don't sleep and return actual time
/// We DON'T do any fancy averaging of the deltas for tick for 2 reasons:
/// - all Systems have to work based on `dt` and we cannot assume that this is
/// const through all ticks
/// - when we have a slow tick, a lag, it doesn't help that we have 10 fast
/// ticks directly afterwards
/// We return a smoothed version for display only!
pub struct Clock {
/// This is the dt that the Clock tries to archive with each call of tick.
target_dt: Duration,
/// last time `tick` was called
last_sys_time: Instant,
last_delta: Option<Duration>,
running_average_delta: f64,
compensation: f64,
/// will be calculated in `tick` returns the dt used by the next iteration
/// of the main loop
last_dt: Duration,
/// summed up `last_dt`
total_tick_time: Duration,
// Stats only
// stored as millis in u16 to save space. if it's more than u16::MAX (16s) we have other
// problems
last_dts_millis: VecDeque<u16>,
last_dts_millis_sorted: Vec<u16>,
stats: ClockStats,
}
pub struct ClockStats {
/// busy_dt is the part of the last tick that we didn't sleep.
/// e.g. the total tick is 33ms, including 25ms sleeping. then this returns
/// 8ms
pub last_busy_dt: Duration,
/// avg over the last NUMBER_OF_OLD_DELTAS_KEPT ticks
pub average_tps: f64,
/// = 50% percentile
pub median_tps: f64,
/// lowest 10% of the frames
pub percentile_90_tps: f64,
/// lowest 5% of the frames
pub percentile_95_tps: f64,
/// lowest 1% of the frames
pub percentile_99_tps: f64,
}
const NUMBER_OF_OLD_DELTAS_KEPT: usize = 100;
impl Clock {
pub fn start() -> Self {
pub fn new(target_dt: Duration) -> Self {
Self {
target_dt,
last_sys_time: Instant::now(),
last_delta: None,
running_average_delta: 0.0,
compensation: 1.0,
last_dt: target_dt,
total_tick_time: Duration::default(),
last_dts_millis: VecDeque::with_capacity(NUMBER_OF_OLD_DELTAS_KEPT),
last_dts_millis_sorted: Vec::with_capacity(NUMBER_OF_OLD_DELTAS_KEPT),
stats: ClockStats::new(&Vec::new(), target_dt),
}
}
pub fn get_tps(&self) -> f64 { 1.0 / self.running_average_delta }
pub fn set_target_dt(&mut self, target_dt: Duration) { self.target_dt = target_dt; }
pub fn get_last_delta(&self) -> Duration {
self.last_delta.unwrap_or_else(|| Duration::new(0, 0))
}
pub fn stats(&self) -> &ClockStats { &self.stats }
pub fn get_avg_delta(&self) -> Duration { Duration::from_secs_f64(self.running_average_delta) }
pub fn dt(&self) -> Duration { self.last_dt }
pub fn tick(&mut self, tgt: Duration) {
/// Do not modify without asking @xMAC94x first!
pub fn tick(&mut self) {
span!(_guard, "tick", "Clock::tick");
let delta = Instant::now().duration_since(self.last_sys_time);
let current_sys_time = Instant::now();
let busy_delta = current_sys_time.duration_since(self.last_sys_time);
// Maintain TPS
self.last_dts_millis_sorted = self.last_dts_millis.iter().copied().collect();
self.last_dts_millis_sorted.sort_unstable();
self.stats = ClockStats::new(&self.last_dts_millis_sorted, busy_delta);
// Attempt to sleep to fill the gap.
if let Some(sleep_dur) = tgt.checked_sub(delta) {
if self.running_average_delta != 0.0 {
self.compensation =
(self.compensation + (tgt.as_secs_f64() / self.running_average_delta) - 1.0)
.max(0.0)
}
let sleep_secs = sleep_dur.as_secs_f64() * self.compensation;
if sleep_secs > 0.0 {
thread::sleep(Duration::from_secs_f64(sleep_secs));
}
if let Some(sleep_dur) = self.target_dt.checked_sub(busy_delta) {
spin_sleep::sleep(sleep_dur);
}
let delta = Instant::now().duration_since(self.last_sys_time);
self.last_sys_time = Instant::now();
self.last_delta = Some(delta);
self.running_average_delta = if self.running_average_delta == 0.0 {
delta.as_secs_f64()
} else {
CLOCK_SMOOTHING * self.running_average_delta
+ (1.0 - CLOCK_SMOOTHING) * delta.as_secs_f64()
};
let after_sleep_sys_time = Instant::now();
self.last_dt = after_sleep_sys_time.duration_since(self.last_sys_time);
if self.last_dts_millis.len() >= NUMBER_OF_OLD_DELTAS_KEPT {
self.last_dts_millis.pop_front();
}
self.last_dts_millis
.push_back((self.last_dt.as_millis() as u16).min(std::u16::MAX));
self.total_tick_time += self.last_dt;
self.last_sys_time = after_sleep_sys_time;
}
}
impl ClockStats {
fn new(sorted: &[u16], last_busy_dt: Duration) -> Self {
const NANOS_PER_SEC: f64 = Duration::from_secs(1).as_nanos() as f64;
const NANOS_PER_MILLI: f64 = Duration::from_millis(1).as_nanos() as f64;
let len = sorted.len();
let average_millis = sorted.iter().fold(0, |a, x| a + *x as u32) / len.max(1) as u32;
let average_tps = NANOS_PER_SEC / (average_millis as f64 * NANOS_PER_MILLI);
let (median_tps, percentile_90_tps, percentile_95_tps, percentile_99_tps) = if len
>= NUMBER_OF_OLD_DELTAS_KEPT
{
let median_millis = sorted[len / 2];
let percentile_90_millis = sorted[(NUMBER_OF_OLD_DELTAS_KEPT as f32 * 0.1) as usize];
let percentile_95_millis = sorted[(NUMBER_OF_OLD_DELTAS_KEPT as f32 * 0.05) as usize];
let percentile_99_millis = sorted[(NUMBER_OF_OLD_DELTAS_KEPT as f32 * 0.01) as usize];
let median_tps = NANOS_PER_SEC / (median_millis as f64 * NANOS_PER_MILLI);
let percentile_90_tps = NANOS_PER_SEC / (percentile_90_millis as f64 * NANOS_PER_MILLI);
let percentile_95_tps = NANOS_PER_SEC / (percentile_95_millis as f64 * NANOS_PER_MILLI);
let percentile_99_tps = NANOS_PER_SEC / (percentile_99_millis as f64 * NANOS_PER_MILLI);
(
median_tps,
percentile_90_tps,
percentile_95_tps,
percentile_99_tps,
)
} else {
let avg_tps = NANOS_PER_SEC / last_busy_dt.as_nanos() as f64;
(avg_tps, avg_tps, avg_tps, avg_tps)
};
Self {
last_busy_dt,
average_tps,
median_tps,
percentile_90_tps,
percentile_95_tps,
percentile_99_tps,
}
}
}

View File

@ -140,19 +140,22 @@ fn main() -> io::Result<()> {
let mut shutdown_coordinator = ShutdownCoordinator::new(Arc::clone(&sigusr1_signal));
// Set up an fps clock
let mut clock = Clock::start();
let mut clock = Clock::new(Duration::from_millis(1000 / TPS));
// Wait for a tick so we don't start with a zero dt
// TODO: consider integrating this into Clock::start?
clock.tick(Duration::from_millis(1000 / TPS));
loop {
#[cfg(feature = "tracy")]
common::util::tracy_client::finish_continuous_frame!();
#[cfg(feature = "tracy")]
let frame = common::util::tracy_client::start_noncontinuous_frame!("work");
// Terminate the server if instructed to do so by the shutdown coordinator
if shutdown_coordinator.check(&mut server, &settings) {
break;
}
let events = server
.tick(Input::default(), clock.get_last_delta())
.tick(Input::default(), clock.dt())
.expect("Failed to tick server");
for event in events {
@ -165,8 +168,6 @@ fn main() -> io::Result<()> {
// Clean up the server after a tick.
server.cleanup();
#[cfg(feature = "tracy")]
common::util::tracy_client::finish_continuous_frame!();
if let Some(tui) = tui.as_ref() {
match tui.msg_r.try_recv() {
@ -194,8 +195,10 @@ fn main() -> io::Result<()> {
}
}
#[cfg(feature = "tracy")]
drop(frame);
// Wait for the next tick.
clock.tick(Duration::from_millis(1000 / TPS));
clock.tick();
}
Ok(())

View File

@ -114,7 +114,7 @@ impl MusicChannel {
/// Maintain the fader attached to this channel. If the channel is not
/// fading, no action is taken.
pub fn maintain(&mut self, dt: f32) {
pub fn maintain(&mut self, dt: std::time::Duration) {
if self.state == ChannelState::Fading {
self.fader.update(dt);
self.sink.set_volume(self.fader.get_volume());

View File

@ -1,11 +1,13 @@
//! Controls volume transitions for Audio Channels
use std::time::Duration;
/// Faders are attached to channels with initial and target volumes as well as a
/// transition time.
#[derive(PartialEq, Clone, Copy)]
pub struct Fader {
length: f32,
running_time: f32,
length: Duration,
running_time: Duration,
volume_from: f32,
volume_to: f32,
is_running: bool,
@ -21,19 +23,19 @@ pub enum FadeDirection {
fn lerp(t: f32, a: f32, b: f32) -> f32 { (1.0 - t) * a + t * b }
impl Fader {
pub fn fade(length: f32, volume_from: f32, volume_to: f32) -> Self {
pub fn fade(length: Duration, volume_from: f32, volume_to: f32) -> Self {
Self {
length,
running_time: 0.0,
running_time: Duration::default(),
volume_from,
volume_to,
is_running: true,
}
}
pub fn fade_in(time: f32, volume_to: f32) -> Self { Self::fade(time, 0.0, volume_to) }
pub fn fade_in(time: Duration, volume_to: f32) -> Self { Self::fade(time, 0.0, volume_to) }
pub fn fade_out(time: f32, volume_from: f32) -> Self { Self::fade(time, volume_from, 0.0) }
pub fn fade_out(time: Duration, volume_from: f32) -> Self { Self::fade(time, volume_from, 0.0) }
/// Used to update the `target` volume of the fader when the max or min
/// volume changes. This occurs when the player changes their in-game
@ -62,7 +64,7 @@ impl Fader {
}
/// Called each tick to update the volume and state
pub fn update(&mut self, dt: f32) {
pub fn update(&mut self, dt: std::time::Duration) {
if self.is_running {
self.running_time += dt;
if self.running_time >= self.length {
@ -74,7 +76,7 @@ impl Fader {
pub fn get_volume(&self) -> f32 {
lerp(
self.running_time / self.length,
self.running_time.as_nanos() as f32 / self.length.as_nanos() as f32,
self.volume_from,
self.volume_to,
)
@ -87,8 +89,8 @@ impl Fader {
impl Default for Fader {
fn default() -> Self {
Self {
length: 0.0,
running_time: 0.0,
length: Duration::default(),
running_time: Duration::default(),
volume_from: 0.0,
volume_to: 1.0,
is_running: false,
@ -102,14 +104,14 @@ mod tests {
#[test]
fn fade_direction_in() {
let fader = Fader::fade_in(10.0, 0.0);
let fader = Fader::fade_in(Duration::from_secs(10), 0.0);
assert_eq!(fader.direction(), FadeDirection::In);
}
#[test]
fn fade_direction_out() {
let fader = Fader::fade_out(10.0, 1.0);
let fader = Fader::fade_out(Duration::from_secs(10), 1.0);
assert_eq!(fader.direction(), FadeDirection::Out);
}
@ -117,10 +119,10 @@ mod tests {
#[test]
#[allow(clippy::float_cmp)] // TODO: Pending review in #587
fn fade_out_completes() {
let mut fader = Fader::fade_out(10.0, 1.0);
let mut fader = Fader::fade_out(Duration::from_secs(10), 1.0);
// Run for the full duration
fader.update(10.0);
fader.update(Duration::from_secs(10));
assert_eq!(fader.get_volume(), 0.0);
assert!(fader.is_finished());
@ -128,32 +130,32 @@ mod tests {
#[test]
fn update_target_volume_fading_out_when_currently_above() {
let mut fader = Fader::fade_out(20.0, 1.0);
let mut fader = Fader::fade_out(Duration::from_secs(20), 1.0);
// After 0.1s, the fader should still be close to 1.0
fader.update(0.1);
fader.update(Duration::from_millis(100));
// Reduce volume to 0.4. We are currently above that.
fader.update_target_volume(0.4);
// The volume should immediately reduce to < 0.4 on the next update
fader.update(0.1);
fader.update(Duration::from_millis(100));
assert!(fader.get_volume() < 0.4)
}
#[test]
fn update_target_volume_fading_out_when_currently_below() {
let mut fader = Fader::fade_out(10.0, 0.8);
let mut fader = Fader::fade_out(Duration::from_secs(10), 0.8);
// After 9s, the fader should be close to 0
fader.update(9.0);
fader.update(Duration::from_secs(9));
// Notify of a volume increase to 1.0. We are already far below that.
fader.update_target_volume(1.0);
// The fader should be unaffected by the new value, and continue dropping
fader.update(0.1);
fader.update(Duration::from_millis(100));
assert!(fader.get_volume() < 0.2);
}
@ -161,16 +163,16 @@ mod tests {
#[test]
#[allow(clippy::float_cmp)] // TODO: Pending review in #587
fn update_target_volume_fading_in_when_currently_above() {
let mut fader = Fader::fade_in(10.0, 1.0);
let mut fader = Fader::fade_in(Duration::from_secs(10), 1.0);
// After 9s, the fader should be close to 1.0
fader.update(9.0);
fader.update(Duration::from_secs(9));
// Reduce volume to 0.4. We are currently above that.
fader.update_target_volume(0.4);
// Run out the fader. It's volume should be 0.4
fader.update(1.0);
fader.update(Duration::from_secs(1));
assert_eq!(fader.get_volume(), 0.4);
}
@ -178,10 +180,10 @@ mod tests {
#[test]
#[allow(clippy::float_cmp)] // TODO: Pending review in #587
fn update_target_volume_fading_in_when_currently_below() {
let mut fader = Fader::fade_in(20.0, 1.0);
let mut fader = Fader::fade_in(Duration::from_secs(20), 1.0);
// After 0.1s, the fader should still be close to 0.0
fader.update(0.1);
fader.update(Duration::from_millis(100));
// Reduce volume to 0.4. The volume_to should be reduced accordingly.
fader.update_target_volume(0.4);

View File

@ -9,6 +9,7 @@ pub mod soundcache;
use channel::{MusicChannel, MusicChannelTag, SfxChannel};
use fader::Fader;
use soundcache::SoundCache;
use std::time::Duration;
use tracing::warn;
use common::assets;
@ -84,7 +85,7 @@ impl AudioFrontend {
}
/// Drop any unused music channels, and update their faders
pub fn maintain(&mut self, dt: f32) {
pub fn maintain(&mut self, dt: Duration) {
self.music_channels.retain(|c| !c.is_done());
for channel in self.music_channels.iter_mut() {
@ -124,11 +125,13 @@ impl AudioFrontend {
if existing_channel.get_tag() != next_channel_tag {
// Fade the existing channel out. It will be removed when the fade completes.
existing_channel.set_fader(Fader::fade_out(2.0, self.music_volume));
existing_channel
.set_fader(Fader::fade_out(Duration::from_secs(2), self.music_volume));
let mut next_music_channel = MusicChannel::new(&audio_device);
next_music_channel.set_fader(Fader::fade_in(12.0, self.music_volume));
next_music_channel
.set_fader(Fader::fade_in(Duration::from_secs(12), self.music_volume));
self.music_channels.push(next_music_channel);
}

View File

@ -746,7 +746,7 @@ impl Hud {
// pulse time for pulsating elements
self.pulse = self.pulse + dt.as_secs_f32();
// FPS
let fps = global_state.clock.get_tps();
let fps = global_state.clock.stats().average_tps;
let version = common::util::DISPLAY_VERSION_LONG.clone();
if self.show.ingame {

View File

@ -63,7 +63,7 @@ impl GlobalState {
self.window.needs_refresh_resize();
}
pub fn maintain(&mut self, dt: f32) { self.audio.maintain(dt); }
pub fn maintain(&mut self, dt: std::time::Duration) { self.audio.maintain(dt); }
#[cfg(feature = "singleplayer")]
pub fn paused(&self) -> bool {

View File

@ -185,7 +185,7 @@ fn main() {
profile,
window,
settings,
clock: Clock::start(),
clock: Clock::new(std::time::Duration::from_millis(30)),
info_message: None,
#[cfg(feature = "singleplayer")]
singleplayer: None,

View File

@ -155,7 +155,7 @@ impl PlayState for CharSelectionState {
match self.client.borrow_mut().tick(
comp::ControllerInputs::default(),
global_state.clock.get_last_delta(),
global_state.clock.dt(),
|_| {},
) {
Ok(events) => {

View File

@ -211,7 +211,7 @@ impl PlayState for MainMenuState {
// Maintain the UI.
for event in self
.main_menu_ui
.maintain(global_state, global_state.clock.get_last_delta())
.maintain(global_state, global_state.clock.dt())
{
match event {
MainMenuEvent::LoginAttempt {

View File

@ -168,12 +168,13 @@ fn handle_main_events_cleared(
if !exit {
// Wait for the next tick.
span!(_guard, "Main thread sleep");
global_state.clock.tick(Duration::from_millis(
global_state.clock.set_target_dt(Duration::from_millis(
1000 / global_state.settings.graphics.max_fps as u64,
));
global_state.clock.tick();
span!(_guard, "Maintain global state");
// Maintain global state.
global_state.maintain(global_state.clock.get_last_delta().as_secs_f32());
global_state.maintain(global_state.clock.dt());
}
}

View File

@ -631,7 +631,7 @@ impl PlayState for SessionState {
let right = self.scene.camera().right();
let dir = right * axis_right + forward * axis_up;
let dt = global_state.clock.get_last_delta().as_secs_f32();
let dt = global_state.clock.dt().as_secs_f32();
if self.freefly_vel.magnitude_squared() > 0.01 {
let new_vel = self.freefly_vel
- self.freefly_vel.normalized() * (FREEFLY_DAMPING * dt);
@ -668,11 +668,7 @@ impl PlayState for SessionState {
// Runs if either in a multiplayer server or the singleplayer server is unpaused
if !global_state.paused() {
// Perform an in-game tick.
match self.tick(
global_state.clock.get_avg_delta(),
global_state,
&mut outcomes,
) {
match self.tick(global_state.clock.dt(), global_state, &mut outcomes) {
Ok(TickAction::Continue) => {}, // Do nothing
Ok(TickAction::Disconnect) => return PlayStateResult::Pop, // Go to main menu
Err(err) => {
@ -697,8 +693,8 @@ impl PlayState for SessionState {
.gameplay
.toggle_debug
.then(|| DebugInfo {
tps: global_state.clock.get_tps(),
frame_time: global_state.clock.get_avg_delta(),
tps: global_state.clock.stats().average_tps,
frame_time: global_state.clock.stats().last_busy_dt,
ping_ms: self.client.borrow().get_ping_ms_rolling_avg(),
coordinates: self
.client
@ -741,7 +737,7 @@ impl PlayState for SessionState {
global_state,
&debug_info,
&self.scene.camera(),
global_state.clock.get_last_delta(),
global_state.clock.dt(),
HudInfo {
is_aiming,
is_first_person: matches!(

View File

@ -152,7 +152,7 @@ fn run_server(mut server: Server, rec: Receiver<Msg>, paused: Arc<AtomicBool>) {
info!("Starting server-cli...");
// Set up an fps clock
let mut clock = Clock::start();
let mut clock = Clock::new(Duration::from_millis(1000 / TPS));
loop {
// Check any event such as stopping and pausing
@ -167,7 +167,7 @@ fn run_server(mut server: Server, rec: Receiver<Msg>, paused: Arc<AtomicBool>) {
}
// Wait for the next tick.
clock.tick(Duration::from_millis(1000 / TPS));
clock.tick();
// Skip updating the server if it's paused
if paused.load(Ordering::SeqCst) && server.number_of_players() < 2 {
@ -177,7 +177,7 @@ fn run_server(mut server: Server, rec: Receiver<Msg>, paused: Arc<AtomicBool>) {
}
let events = server
.tick(Input::default(), clock.get_last_delta())
.tick(Input::default(), clock.dt())
.expect("Failed to tick server!");
for event in events {