diff --git a/alvr/client_core/src/c_api.rs b/alvr/client_core/src/c_api.rs index a9ba3e2474..0f09fed83e 100644 --- a/alvr/client_core/src/c_api.rs +++ b/alvr/client_core/src/c_api.rs @@ -398,9 +398,14 @@ pub extern "C" fn alvr_get_tracker_prediction_offset_ns() -> u64 { } #[no_mangle] -pub extern "C" fn alvr_report_submit(target_timestamp_ns: u64, vsync_queue_ns: u64) { +pub extern "C" fn alvr_report_submit( + target_timestamp_ns: u64, + frame_interval_ns: u64, + vsync_queue_ns: u64, +) { crate::report_submit( Duration::from_nanos(target_timestamp_ns), + Duration::from_nanos(frame_interval_ns), Duration::from_nanos(vsync_queue_ns), ); } diff --git a/alvr/client_core/src/lib.rs b/alvr/client_core/src/lib.rs index 66bf2a57c1..f1133c4586 100644 --- a/alvr/client_core/src/lib.rs +++ b/alvr/client_core/src/lib.rs @@ -197,9 +197,9 @@ pub fn get_tracker_prediction_offset() -> Duration { } } -pub fn report_submit(target_timestamp: Duration, vsync_queue: Duration) { +pub fn report_submit(target_timestamp: Duration, frame_interval: Duration, vsync_queue: Duration) { if let Some(stats) = &mut *STATISTICS_MANAGER.lock() { - stats.report_submit(target_timestamp, vsync_queue); + stats.report_submit(target_timestamp, frame_interval, vsync_queue); if let Some(sender) = &*STATISTICS_SENDER.lock() { if let Some(stats) = stats.summary(target_timestamp) { diff --git a/alvr/client_core/src/statistics.rs b/alvr/client_core/src/statistics.rs index af9791d06e..0333d9d0e5 100644 --- a/alvr/client_core/src/statistics.rs +++ b/alvr/client_core/src/statistics.rs @@ -95,8 +95,15 @@ impl StatisticsManager { } // vsync_queue is the latency between this call and the vsync. it cannot be measured by ALVR and - // should be reported by the VR runtime - pub fn report_submit(&mut self, target_timestamp: Duration, vsync_queue: Duration) { + // should be reported by the VR runtime. + // predicted_frame_interval is the frame interval returned by the runtime. this is more stable + // any any interval mearued by us. + pub fn report_submit( + &mut self, + target_timestamp: Duration, + predicted_frame_interval: Duration, + vsync_queue: Duration, + ) { let now = Instant::now(); if let Some(frame) = self @@ -118,6 +125,8 @@ impl StatisticsManager { let vsync = now + vsync_queue; frame.client_stats.frame_interval = vsync.saturating_duration_since(self.prev_vsync); self.prev_vsync = vsync; + + frame.client_stats.predicted_frame_interval = predicted_frame_interval } } diff --git a/alvr/client_mock/src/main.rs b/alvr/client_mock/src/main.rs index 4e84dd1404..83938d23aa 100644 --- a/alvr/client_mock/src/main.rs +++ b/alvr/client_mock/src/main.rs @@ -196,7 +196,7 @@ fn tracking_thread(streaming: Arc, fps: f32, input: Arc>; let default_view = xr::View { @@ -692,10 +693,13 @@ pub fn entry_point() { let (sender, reference_space_receiver) = mpsc::channel(); reference_space_sender = Some(sender); + let (sender, frame_interval_receiver) = mpsc::channel(); + frame_interval_sender = Some(sender); streaming_input_thread = Some(thread::spawn(move || { let mut deadline = Instant::now(); - let frame_interval = Duration::from_secs_f32(1.0 / refresh_rate_hint); + let mut frame_interval = + Duration::from_secs_f32(1.0 / refresh_rate_hint); while is_streaming.value() { update_streaming_input(&mut context); @@ -704,7 +708,11 @@ pub fn entry_point() { context.reference_space = reference_space; } - deadline += frame_interval / 3; + if let Ok(interval) = frame_interval_receiver.try_recv() { + frame_interval = interval; + } + + deadline += frame_interval; thread::sleep(deadline.saturating_duration_since(Instant::now())); } })); @@ -832,6 +840,10 @@ pub fn entry_point() { let vsync_time = Duration::from_nanos(frame_state.predicted_display_time.as_nanos() as _); + if let Some(sender) = &frame_interval_sender { + sender.send(frame_interval).ok(); + } + xr_frame_stream.begin().unwrap(); if !frame_state.should_render { @@ -901,7 +913,11 @@ pub fn entry_point() { if !hardware_buffer.is_null() { if let Some(now) = xr_runtime_now(&xr_instance) { - alvr_client_core::report_submit(timestamp, vsync_time.saturating_sub(now)); + alvr_client_core::report_submit( + timestamp, + frame_interval, + vsync_time.saturating_sub(now), + ); } } diff --git a/alvr/common/src/average.rs b/alvr/common/src/average.rs index 9d6d6a2fc6..ab01b6b35d 100644 --- a/alvr/common/src/average.rs +++ b/alvr/common/src/average.rs @@ -1,4 +1,9 @@ -use std::{collections::VecDeque, time::Duration}; +use glam::Vec2; +use std::{ + collections::VecDeque, + f32::consts::PI, + time::{Duration, Instant}, +}; pub struct SlidingWindowAverage { history_buffer: VecDeque, @@ -33,3 +38,83 @@ impl SlidingWindowAverage { self.history_buffer.iter().sum::() / self.history_buffer.len() as u32 } } + +pub enum DurationOffset { + Positive(Duration), + Negative(Duration), +} + +// Calculate average time phase. The average is calulated in the complex domain and returned back as +// the phase time offset. Only the phase samples are stored (as a complex number), not the frame +// interval, since it's useless for these calculations. +pub struct SlidingTimePhaseAverage { + last_time_sample: Instant, + last_sample: Vec2, + history_buffer: VecDeque, + max_history_size: usize, +} + +impl SlidingTimePhaseAverage { + pub fn new(max_history_size: usize) -> Self { + Self { + last_time_sample: Instant::now(), + last_sample: Vec2::new(1.0, 0.0), + history_buffer: [].into_iter().collect(), + max_history_size, + } + } + + // The sample is actually the time of this call. + pub fn submit_sample(&mut self, frame_interval: Duration) { + let time_sample = Instant::now(); + + let phase_sample = ((time_sample - self.last_time_sample).as_secs_f32() + / frame_interval.as_secs_f32()) + .fract() + * 2.0 + * PI; + + let complex_sample = Vec2::new(f32::cos(phase_sample), f32::sin(phase_sample)); + + if self.history_buffer.len() >= self.max_history_size { + self.history_buffer.pop_front(); + } + + self.history_buffer.push_back(complex_sample); + + self.last_time_sample = time_sample; + self.last_sample = complex_sample + } + + // The reference frame of the phase average is an implementation detail. This method returns the + // phase offset wrt the time of this call. + pub fn get_average_diff(&self, frame_interval: Duration) -> DurationOffset { + let now = Instant::now(); + + let current_phase = + ((now - self.last_time_sample).as_secs_f32() / frame_interval.as_secs_f32()).fract() + * 2.0 + * PI; + + // let current_complex_phase = Vec2::new(f32::cos(current_phase), f32::sin(current_phase)); + + // Note: no need to normalize + let average_complex = self.history_buffer.iter().sum::(); + let average_phase = f32::atan2(average_complex.y, average_complex.x); + + let phase_diff = current_phase - average_phase; + + // Nomalized between -PI and +PI + let normalized_phase_diff = (phase_diff + PI).rem_euclid(2.0 * PI) - PI; + + if normalized_phase_diff.is_sign_positive() { + DurationOffset::Positive(Duration::from_secs_f32( + normalized_phase_diff * frame_interval.as_secs_f32(), + )) + } else { + DurationOffset::Negative(Duration::from_secs_f32( + -normalized_phase_diff * frame_interval.as_secs_f32(), + )) + } + } +} diff --git a/alvr/packets/src/lib.rs b/alvr/packets/src/lib.rs index 3076cb40ad..3648523d4d 100644 --- a/alvr/packets/src/lib.rs +++ b/alvr/packets/src/lib.rs @@ -205,6 +205,7 @@ pub struct ClientStatistics { pub rendering: Duration, pub vsync_queue: Duration, pub total_pipeline_latency: Duration, + pub predicted_frame_interval: Duration, } #[derive(Serialize, Deserialize, Clone, Debug)] diff --git a/alvr/server/cpp/alvr_server/alvr_server.cpp b/alvr/server/cpp/alvr_server/alvr_server.cpp index c82e20276c..7673e02397 100644 --- a/alvr/server/cpp/alvr_server/alvr_server.cpp +++ b/alvr/server/cpp/alvr_server/alvr_server.cpp @@ -226,14 +226,17 @@ void DeinitializeStreaming() { } } -void SendVSync() { vr::VRServerDriverHost()->VsyncEvent(0.0); } - void RequestIDR() { if (g_driver_provider.hmd && g_driver_provider.hmd->m_encoder) { g_driver_provider.hmd->m_encoder->InsertIDR(); } } +// Linux-only +void NotifyVsync() { + // todo +} + void SetTracking(unsigned long long targetTimestampNs, float controllerPoseTimeOffsetS, const FfiDeviceMotion *deviceMotions, diff --git a/alvr/server/cpp/alvr_server/bindings.h b/alvr/server/cpp/alvr_server/bindings.h index d5567f210f..cfbe8c8f87 100644 --- a/alvr/server/cpp/alvr_server/bindings.h +++ b/alvr/server/cpp/alvr_server/bindings.h @@ -127,8 +127,8 @@ extern "C" void (*WaitForVSync)(); extern "C" void *CppEntryPoint(const char *pInterfaceName, int *pReturnCode); extern "C" void InitializeStreaming(); extern "C" void DeinitializeStreaming(); -extern "C" void SendVSync(); extern "C" void RequestIDR(); +extern "C" void NotifyVsync(); extern "C" void SetTracking(unsigned long long targetTimestampNs, float controllerPoseTimeOffsetS, const FfiDeviceMotion *deviceMotions, diff --git a/alvr/server/src/connection.rs b/alvr/server/src/connection.rs index 0dc3edc7e9..471a8b1b33 100644 --- a/alvr/server/src/connection.rs +++ b/alvr/server/src/connection.rs @@ -2,13 +2,13 @@ use crate::{ bitrate::BitrateManager, buttons::BUTTON_PATH_FROM_ID, face_tracking::FaceTrackingSink, - haptics, + haptics, openvr_props, sockets::WelcomeSocket, statistics::StatisticsManager, tracking::{self, TrackingManager}, FfiButtonValue, FfiFov, FfiViewsConfig, VideoPacket, BITRATE_MANAGER, CONTROL_CHANNEL_SENDER, - DECODER_CONFIG, DISCONNECT_CLIENT_NOTIFIER, HAPTICS_SENDER, RESTART_NOTIFIER, - SERVER_DATA_MANAGER, STATISTICS_MANAGER, VIDEO_RECORDING_FILE, VIDEO_SENDER, + DECODER_CONFIG, DISCONNECT_CLIENT_NOTIFIER, HAPTICS_SENDER, PHASE_SYNC_MANAGER, + RESTART_NOTIFIER, SERVER_DATA_MANAGER, STATISTICS_MANAGER, VIDEO_RECORDING_FILE, VIDEO_SENDER, }; use alvr_audio::AudioDevice; use alvr_common::{ @@ -24,7 +24,10 @@ use alvr_packets::{ ButtonValue, ClientConnectionResult, ClientControlPacket, ClientListAction, ClientStatistics, ServerControlPacket, StreamConfigPacket, Tracking, AUDIO, HAPTICS, STATISTICS, TRACKING, VIDEO, }; -use alvr_session::{CodecType, ConnectionState, ControllersEmulationMode, FrameSize, OpenvrConfig}; +use alvr_session::{ + CodecType, ConnectionState, ControllersEmulationMode, FrameSize, OpenvrConfig, OpenvrPropValue, + OpenvrPropertyKey, +}; use alvr_sockets::{ spawn_cancelable, ControlSocketReceiver, ControlSocketSender, PeerType, ProtoControlSocket, StreamSocketBuilder, KEEPALIVE_INTERVAL, @@ -652,8 +655,8 @@ async fn connection_pipeline( crate::SetOpenvrProperty( *alvr_common::HEAD_ID, crate::openvr_props::to_ffi_openvr_prop( - alvr_session::OpenvrPropertyKey::AudioDefaultPlaybackDeviceId, - alvr_session::OpenvrPropValue::String(id), + OpenvrPropertyKey::AudioDefaultPlaybackDeviceId, + OpenvrPropValue::String(id), ), ) } @@ -676,8 +679,8 @@ async fn connection_pipeline( crate::SetOpenvrProperty( *alvr_common::HEAD_ID, crate::openvr_props::to_ffi_openvr_prop( - alvr_session::OpenvrPropertyKey::AudioDefaultPlaybackDeviceId, - alvr_session::OpenvrPropValue::String(id), + OpenvrPropertyKey::AudioDefaultPlaybackDeviceId, + OpenvrPropValue::String(id), ), ) } @@ -701,8 +704,8 @@ async fn connection_pipeline( crate::SetOpenvrProperty( *alvr_common::HEAD_ID, crate::openvr_props::to_ffi_openvr_prop( - alvr_session::OpenvrPropertyKey::AudioDefaultRecordingDeviceId, - alvr_session::OpenvrPropValue::String(id), + OpenvrPropertyKey::AudioDefaultRecordingDeviceId, + OpenvrPropValue::String(id), ), ) } @@ -932,6 +935,7 @@ async fn connection_pipeline( if let Some(stats) = &mut *STATISTICS_MANAGER.lock() { let timestamp = client_stats.target_timestamp; let decoder_latency = client_stats.video_decode; + let predicted_frame_interval = client_stats.predicted_frame_interval; let network_latency = stats.report_statistics(client_stats); BITRATE_MANAGER.lock().report_frame_latencies( @@ -940,6 +944,17 @@ async fn connection_pipeline( network_latency, decoder_latency, ); + + let mut phase_sync_lock = PHASE_SYNC_MANAGER.lock(); + phase_sync_lock.report_predicted_frame_interval(predicted_frame_interval); + + openvr_props::set_prop( + *HEAD_ID, + OpenvrPropertyKey::DisplayFrequency, + OpenvrPropValue::Float( + 1.0 / phase_sync_lock.frame_interval_average().as_secs_f32(), + ), + ); } } } diff --git a/alvr/server/src/lib.rs b/alvr/server/src/lib.rs index 5e841620a7..b296d7f903 100644 --- a/alvr/server/src/lib.rs +++ b/alvr/server/src/lib.rs @@ -5,6 +5,7 @@ mod face_tracking; mod haptics; mod logging_backend; mod openvr_props; +mod phase_sync; mod sockets; mod statistics; mod tracking; @@ -38,9 +39,11 @@ use alvr_server_io::ServerDataManager; use alvr_session::CodecType; use bitrate::BitrateManager; use connection::SHOULD_CONNECT_TO_CLIENTS; +use phase_sync::PhaseSyncManager; use statistics::StatisticsManager; use std::{ collections::HashMap, + env::consts::OS, ffi::{c_char, c_void, CStr, CString}, fs::File, io::Write, @@ -79,6 +82,14 @@ static BITRATE_MANAGER: Lazy> = Lazy::new(|| { settings.video.preferred_fps, )) }); +static PHASE_SYNC_MANAGER: Lazy> = Lazy::new(|| { + let data_lock = SERVER_DATA_MANAGER.read(); + let settings = data_lock.settings(); + Mutex::new(PhaseSyncManager::new( + settings.connection.statistics_history_size as usize, + Duration::from_secs_f32(1.0 / settings.video.preferred_fps), + )) +}); pub struct VideoPacket { pub header: VideoPacketHeader, @@ -426,6 +437,20 @@ pub unsafe extern "C" fn HmdDriverFactory( warn!("Connection thread closed: {e}"); } }); + + if OS == "linux" { + thread::spawn(|| { + while SHOULD_CONNECT_TO_CLIENTS.value() { + unsafe { NotifyVsync() }; + + // Make sure to wait at least 1ms, to avoid double notify because of timing + // jitter + thread::sleep(Duration::from_millis(1)); + + thread::sleep(PHASE_SYNC_MANAGER.lock().duration_until_next_vsync()); + } + }); + } } unsafe extern "C" fn path_string_to_hash(path: *const c_char) -> u64 { @@ -472,14 +497,7 @@ pub unsafe extern "C" fn HmdDriverFactory( .video .optimize_game_render_latency { - let wait_duration = STATISTICS_MANAGER - .lock() - .as_mut() - .map(|stats| stats.duration_until_next_vsync()); - - if let Some(duration) = wait_duration { - thread::sleep(duration); - } + thread::sleep(PHASE_SYNC_MANAGER.lock().duration_until_next_vsync()); } } diff --git a/alvr/server/src/openvr_props.rs b/alvr/server/src/openvr_props.rs index f1db5be3c1..6858918797 100644 --- a/alvr/server/src/openvr_props.rs +++ b/alvr/server/src/openvr_props.rs @@ -2,7 +2,7 @@ // todo: fill out more properties for headset and controllers // todo: add more emulation modes -use crate::{FfiOpenvrProperty, FfiOpenvrPropertyValue, SERVER_DATA_MANAGER}; +use crate::{openvr_props, FfiOpenvrProperty, FfiOpenvrPropertyValue, SERVER_DATA_MANAGER}; use alvr_common::{prelude::*, settings_schema::Switch, HEAD_ID, LEFT_HAND_ID, RIGHT_HAND_ID}; use alvr_session::{ ControllersEmulationMode, HeadsetEmulationMode, OpenvrPropValue, @@ -13,6 +13,10 @@ use std::{ ptr, }; +pub fn set_prop(device_id: u64, key: OpenvrPropertyKey, value: OpenvrPropValue) { + unsafe { crate::SetOpenvrProperty(device_id, to_ffi_openvr_prop(key, value)) } +} + pub fn to_ffi_openvr_prop(key: OpenvrPropertyKey, value: OpenvrPropValue) -> FfiOpenvrProperty { let type_ = match value { OpenvrPropValue::Bool(_) => crate::FfiOpenvrPropertyType_Bool, @@ -113,9 +117,7 @@ pub extern "C" fn set_device_openvr_props(device_id: u64) { if device_id == *HEAD_ID { fn set_prop(key: OpenvrPropertyKey, value: OpenvrPropValue) { info!("Setting head OpenVR prop: {key:?} => {value:?}"); - unsafe { - crate::SetOpenvrProperty(*HEAD_ID, to_ffi_openvr_prop(key, value)); - } + openvr_props::set_prop(*HEAD_ID, key, value); } fn set_string(key: OpenvrPropertyKey, value: &str) { set_prop(key, OpenvrPropValue::String(value.into())); diff --git a/alvr/server/src/phase_sync.rs b/alvr/server/src/phase_sync.rs new file mode 100644 index 0000000000..4c33416a3a --- /dev/null +++ b/alvr/server/src/phase_sync.rs @@ -0,0 +1,45 @@ +//! Server phase sync +//! Phase sync on the server is concerned with vsync cycle handling and tracking timing. + +use alvr_common::SlidingWindowAverage; +use std::time::{Duration, Instant}; + +pub struct PhaseSyncManager { + predicted_frame_interval_average: SlidingWindowAverage, + last_vsync_time: Instant, +} + +impl PhaseSyncManager { + pub fn new(max_history_size: usize, initial_frame_interval: Duration) -> Self { + Self { + predicted_frame_interval_average: SlidingWindowAverage::new( + initial_frame_interval, + max_history_size, + ), + last_vsync_time: Instant::now(), + } + } + + pub fn report_predicted_frame_interval(&mut self, interval: Duration) { + self.predicted_frame_interval_average + .submit_sample(interval); + } + + pub fn frame_interval_average(&self) -> Duration { + self.predicted_frame_interval_average.get_average() + } + + // NB: this call is non-blocking, waiting should be done externally + pub fn duration_until_next_vsync(&mut self) -> Duration { + let now = Instant::now(); + + let frame_interval = self.predicted_frame_interval_average.get_average(); + + // update the last vsync if it's too old + while self.last_vsync_time + frame_interval < now { + self.last_vsync_time += frame_interval; + } + + (self.last_vsync_time + frame_interval).saturating_duration_since(now) + } +} diff --git a/alvr/server/src/statistics.rs b/alvr/server/src/statistics.rs index 427ba2f759..bdaeb7fc97 100644 --- a/alvr/server/src/statistics.rs +++ b/alvr/server/src/statistics.rs @@ -46,8 +46,6 @@ pub struct StatisticsManager { battery_gauges: HashMap, steamvr_pipeline_latency: Duration, total_pipeline_latency_average: SlidingWindowAverage, - last_vsync_time: Instant, - frame_interval: Duration, } impl StatisticsManager { @@ -77,8 +75,6 @@ impl StatisticsManager { Duration::ZERO, max_history_size, ), - last_vsync_time: Instant::now(), - frame_interval: nominal_server_frame_interval, } } @@ -283,16 +279,4 @@ impl StatisticsManager { self.steamvr_pipeline_latency .saturating_sub(self.total_pipeline_latency_average.get_average()) } - - // NB: this call is non-blocking, waiting should be done externally - pub fn duration_until_next_vsync(&mut self) -> Duration { - let now = Instant::now(); - - // update the last vsync if it's too old - while self.last_vsync_time + self.frame_interval < now { - self.last_vsync_time += self.frame_interval; - } - - (self.last_vsync_time + self.frame_interval).saturating_duration_since(now) - } } diff --git a/alvr/session/src/settings.rs b/alvr/session/src/settings.rs index 81843d10bc..097c970da0 100644 --- a/alvr/session/src/settings.rs +++ b/alvr/session/src/settings.rs @@ -762,6 +762,37 @@ pub enum SocketBufferSize { Custom(#[schema(suffix = "B")] u32), } +#[derive(SettingsSchema, Serialize, Deserialize, Clone)] +pub struct TrackingSubmissionPhaseSyncConfig { + #[schema(strings( + display_name = "Streamer send buffer size", + help = "Backward shift done per submission miss" + ))] + #[schema(gui(slider(min = 0.01, max = 0.5, step = 0.01)), suffix = "rad")] + pub phase_shift_per_miss_rad: f32, + + #[schema( + strings(help = "This is the expected number of sumission misses per minute. +Other misses unrelated to this algorithm are not taken into account. +A higher value will keep the latency low but it will be more stuttery.") + )] + #[schema(gui(slider(min = 1, max = 10)), suffix = "rad")] + pub misses_per_minute: usize, +} + +#[derive(SettingsSchema, Serialize, Deserialize, Clone)] +pub struct PhaseSyncConfig { + #[schema(strings(help = "Identify the best phase to submit tracking data to SteamVR."))] + pub tracking_submission: TrackingSubmissionPhaseSyncConfig, + //todo: + // tracking_polling: used to reduce tracking queue + // server_vsync: used to reduce client decoder queue. + // client_phase_offset: off by default, waiting time used for clients that don't implement phase sync. + + #[schema(suffix = " frames")] + pub history_size: usize, +} + #[derive(SettingsSchema, Serialize, Deserialize, Clone)] pub struct ConnectionConfig { #[schema(strings( @@ -820,8 +851,14 @@ For now works only on Windows+Nvidia"# #[schema(gui(slider(min = 1024, max = 65507, logarithmic)), suffix = "B")] pub packet_size: i32, + #[schema(strings( + help = "History size used in client+server StatisticsManager. +It affects the head and controller latency calculations." + ))] #[schema(suffix = " frames")] pub statistics_history_size: usize, + + pub phase_sync: PhaseSyncConfig, } #[derive(SettingsSchema, Serialize, Deserialize, Clone)] @@ -1233,6 +1270,13 @@ pub fn session_settings_default() -> SettingsDefault { on_disconnect_script: "".into(), packet_size: 1400, statistics_history_size: 256, + phase_sync: PhaseSyncConfigDefault { + tracking_submission: TrackingSubmissionPhaseSyncConfigDefault { + phase_shift_per_miss_rad: 0.1, + misses_per_minute: 2, + }, + history_size: 256, + }, }, logging: LoggingConfigDefault { log_to_disk: cfg!(debug_assertions),