diff --git a/client/src/frame_scheduler.c b/client/src/frame_scheduler.c index 6d9efc33..d506ffb8 100644 --- a/client/src/frame_scheduler.c +++ b/client/src/frame_scheduler.c @@ -217,7 +217,16 @@ void frameScheduler_update(void) now - l_frameScheduler.lastCadence > FRAME_SCHEDULER_RENEW_NS * 2) { if (sendSchedule(LG_TRANSPORT_FRAME_SCHEDULE_RELEASE, 0)) + { l_frameScheduler.active = false; + l_frameScheduler.period = 0; + LG_LOCK(l_frameScheduler.lock); + l_frameScheduler.phaseError = 0; + l_frameScheduler.feedbackFrameSerial = 0; + l_frameScheduler.feedbackSamples = 0; + l_frameScheduler.feedbackDirty = false; + LG_UNLOCK(l_frameScheduler.lock); + } } return; } @@ -235,6 +244,12 @@ void frameScheduler_update(void) { l_frameScheduler.period = period; ++l_frameScheduler.generation; + LG_LOCK(l_frameScheduler.lock); + l_frameScheduler.phaseError = 0; + l_frameScheduler.feedbackFrameSerial = 0; + l_frameScheduler.feedbackSamples = 0; + l_frameScheduler.feedbackDirty = false; + LG_UNLOCK(l_frameScheduler.lock); } else l_frameScheduler.period = @@ -282,12 +297,11 @@ void frameScheduler_observeRender(uint64_t timestamp) } void frameScheduler_feedback(uint64_t frameSerial, uint32_t generation, - uint64_t queueStart, uint64_t prepareStart) + uint64_t measuredPhase) { - if (!generation || !queueStart || prepareStart < queueStart) + if (!generation) return; - const uint64_t slack = prepareStart - queueStart; LG_LOCK(l_frameScheduler.lock); if (!l_frameScheduler.supported || !l_frameScheduler.active || generation != l_frameScheduler.generation) @@ -296,14 +310,21 @@ void frameScheduler_feedback(uint64_t frameSerial, uint32_t generation, return; } - int64_t error = slack > FRAME_SCHEDULER_TARGET_SLACK_NS ? - (int64_t)(slack - FRAME_SCHEDULER_TARGET_SLACK_NS) : - -(int64_t)(FRAME_SCHEDULER_TARGET_SLACK_NS - slack); - const int64_t limit = (int64_t)(l_frameScheduler.period / 2); - if (error > limit) - error = limit; - else if (error < -limit) - error = -limit; + const int64_t period = (int64_t)l_frameScheduler.period; + if (!period) + { + LG_UNLOCK(l_frameScheduler.lock); + return; + } + + int64_t error = measuredPhase > FRAME_SCHEDULER_TARGET_SLACK_NS ? + (int64_t)(measuredPhase - FRAME_SCHEDULER_TARGET_SLACK_NS) : + -(int64_t)(FRAME_SCHEDULER_TARGET_SLACK_NS - measuredPhase); + error %= period; + if (error > period / 2) + error -= period; + else if (error < -period / 2) + error += period; if (!l_frameScheduler.feedbackSamples) l_frameScheduler.phaseError = error; diff --git a/client/src/frame_scheduler.h b/client/src/frame_scheduler.h index 07107fd9..419920dd 100644 --- a/client/src/frame_scheduler.h +++ b/client/src/frame_scheduler.h @@ -32,6 +32,6 @@ void frameScheduler_stop(void); void frameScheduler_update(void); void frameScheduler_observeRender(uint64_t timestamp); void frameScheduler_feedback(uint64_t frameSerial, uint32_t generation, - uint64_t queueStart, uint64_t prepareStart); + uint64_t measuredPhase); #endif diff --git a/client/src/main.c b/client/src/main.c index 51ff5b82..e90be43e 100644 --- a/client/src/main.c +++ b/client/src/main.c @@ -434,8 +434,18 @@ static void frameTimingFinishRender(const LG_RendererFrameTiming * timing, } LG_UNLOCK(l_frameTiming.lock); - frameScheduler_feedback(feedbackFrameSerial, feedbackGeneration, - feedbackQueueStart, prepareStart); + if (feedbackFrameSerial && feedbackGeneration) + { + uint64_t measuredPhase = timing->swapTime; + if (g_state.jitRender) + { + if (!feedbackQueueStart || prepareStart < feedbackQueueStart) + return; + measuredPhase = prepareStart - feedbackQueueStart; + } + frameScheduler_feedback( + feedbackFrameSerial, feedbackGeneration, measuredPhase); + } } static void frameTimingPublishReady(void) diff --git a/idd/LGIdd/CFrameScheduler.cpp b/idd/LGIdd/CFrameScheduler.cpp index 385697f4..036f907c 100644 --- a/idd/LGIdd/CFrameScheduler.cpp +++ b/idd/LGIdd/CFrameScheduler.cpp @@ -22,13 +22,12 @@ #include "CDebug.h" -#include - -static const uint64_t MIN_PERIOD_NS = 2000000ULL; -static const uint64_t MAX_PERIOD_NS = 1000000000ULL; -static const uint32_t MIN_LEASE_MS = 100; -static const uint32_t MAX_LEASE_MS = 5000; -static const uint64_t MIN_SAFETY_NS = 250000ULL; +static const uint64_t MIN_PERIOD_NS = 2000000ULL; +static const uint64_t MAX_PERIOD_NS = 1000000000ULL; +static const uint32_t MIN_LEASE_MS = 100; +static const uint32_t MAX_LEASE_MS = 5000; +static const uint64_t MIN_SAFETY_NS = 250000ULL; +static const uint64_t LOG_INTERVAL_NS = 5000000000ULL; uint64_t CFrameScheduler::Nanotime() { @@ -112,6 +111,11 @@ void CFrameScheduler::ElectOwner(uint64_t now) m_forceNext = m_scheduling; m_lastPublishedFrameSerial = 0; + m_lastPhaseError = 0; + m_lastLog = now; + m_lastLogAcquired = m_acquiredFrames; + m_lastLogSkipped = m_skippedFrames; + m_lastLogPublished = m_publishedFrames; if (m_scheduling) DEBUG_INFO("Frame timing owner %u generation %u at %.3f Hz", @@ -140,6 +144,15 @@ void CFrameScheduler::Reset() m_timingSamples = 0; m_lastPublishedFrameSerial = 0; + + m_lastPhaseError = 0; + m_acquiredFrames = 0; + m_skippedFrames = 0; + m_publishedFrames = 0; + m_lastLog = 0; + m_lastLogAcquired = 0; + m_lastLogSkipped = 0; + m_lastLogPublished = 0; ReleaseSRWLockExclusive(&m_lock); } @@ -260,9 +273,20 @@ void CFrameScheduler::ApplyFeedback(Client& client, m_nextDeadline = m_nextDeadline > advance ? m_nextDeadline - advance : 0; } + m_lastPhaseError = schedule.phaseError; client.lastFeedbackFrameSerial = schedule.feedbackFrameSerial; } +void CFrameScheduler::AdvanceDeadline(uint64_t now) +{ + if (m_nextDeadline > now) + return; + + const uint64_t periods = + (now - m_nextDeadline) / m_schedule.period + 1; + m_nextDeadline += periods * m_schedule.period; +} + bool CFrameScheduler::GetSchedule(Schedule& schedule) const { AcquireSRWLockShared(&m_lock); @@ -276,6 +300,7 @@ bool CFrameScheduler::GetSchedule(Schedule& schedule) const void CFrameScheduler::ObserveFrame(uint64_t now) { AcquireSRWLockExclusive(&m_lock); + ++m_acquiredFrames; if (m_lastArrival && now > m_lastArrival) { const uint64_t interval = now - m_lastArrival; @@ -311,8 +336,7 @@ bool CFrameScheduler::SelectFrame(uint64_t now, bool force, } generation = m_schedule.generation; - while (m_nextDeadline <= now) - m_nextDeadline += m_schedule.period; + AdvanceDeadline(now); if (force) m_forceNext = true; @@ -324,11 +348,13 @@ bool CFrameScheduler::SelectFrame(uint64_t now, bool force, } const uint64_t safety = - std::max(MIN_SAFETY_NS, - std::max(m_guestJitter * 2, m_workEstimate / 8)); + max(MIN_SAFETY_NS, + max(m_guestJitter * 2, m_workEstimate / 8)); const uint64_t nextArrival = m_lastArrival + m_guestPeriod; const bool process = nextArrival <= now || nextArrival + m_workEstimate + safety > m_nextDeadline; + if (!process) + ++m_skippedFrames; ReleaseSRWLockExclusive(&m_lock); return process; } @@ -341,13 +367,44 @@ void CFrameScheduler::FramePublished(uint32_t generation, { m_forceNext = false; m_lastPublishedFrameSerial = frameSerial; - do - m_nextDeadline += m_schedule.period; - while (m_nextDeadline <= now); + ++m_publishedFrames; + m_nextDeadline += m_schedule.period; + AdvanceDeadline(now); } ReleaseSRWLockExclusive(&m_lock); } +void CFrameScheduler::LogStatistics(uint64_t now) +{ + AcquireSRWLockExclusive(&m_lock); + if (!m_scheduling || now - m_lastLog < LOG_INTERVAL_NS) + { + ReleaseSRWLockExclusive(&m_lock); + return; + } + + const uint64_t acquired = m_acquiredFrames - m_lastLogAcquired; + const uint64_t skipped = m_skippedFrames - m_lastLogSkipped; + const uint64_t published = m_publishedFrames - m_lastLogPublished; + DEBUG_TRACE("Frame schedule owner %u: %.3f Hz client, %.3f Hz guest, " + "%.3f ms work, %.3f ms phase; %llu acquired, %llu skipped, " + "%llu published", + m_schedule.clientID, + 1000000000.0 / m_schedule.period, + m_guestPeriod ? 1000000000.0 / m_guestPeriod : 0.0, + m_workEstimate / 1000000.0, + m_lastPhaseError / 1000000.0, + static_cast(acquired), + static_cast(skipped), + static_cast(published)); + + m_lastLog = now; + m_lastLogAcquired = m_acquiredFrames; + m_lastLogSkipped = m_skippedFrames; + m_lastLogPublished = m_publishedFrames; + ReleaseSRWLockExclusive(&m_lock); +} + void CFrameScheduler::RecordFrameTiming(uint64_t duration) { if (!duration) diff --git a/idd/LGIdd/CFrameScheduler.h b/idd/LGIdd/CFrameScheduler.h index f6b97d8c..899257a2 100644 --- a/idd/LGIdd/CFrameScheduler.h +++ b/idd/LGIdd/CFrameScheduler.h @@ -69,9 +69,19 @@ private: uint32_t m_lastPublishedFrameSerial = 0; + int64_t m_lastPhaseError = 0; + uint64_t m_acquiredFrames = 0; + uint64_t m_skippedFrames = 0; + uint64_t m_publishedFrames = 0; + uint64_t m_lastLog = 0; + uint64_t m_lastLogAcquired = 0; + uint64_t m_lastLogSkipped = 0; + uint64_t m_lastLogPublished = 0; + Client * FindClient(uint32_t clientID); void ElectOwner(uint64_t now); void ApplyFeedback(Client& client, const KVMFRFrameSchedule& schedule); + void AdvanceDeadline(uint64_t now); public: static uint64_t Nanotime(); @@ -86,4 +96,5 @@ public: void FramePublished(uint32_t generation, uint32_t frameSerial, uint64_t now); void RecordFrameTiming(uint64_t duration); + void LogStatistics(uint64_t now); }; diff --git a/idd/LGIdd/CIndirectDeviceContext.cpp b/idd/LGIdd/CIndirectDeviceContext.cpp index 22bb8b89..eb0853bb 100644 --- a/idd/LGIdd/CIndirectDeviceContext.cpp +++ b/idd/LGIdd/CIndirectDeviceContext.cpp @@ -1304,6 +1304,8 @@ void CIndirectDeviceContext::LGMPTimer() lgmpHostAckData(m_pointerQueue); } + m_frameScheduler.LogStatistics(now); + AcquireSRWLockExclusive(&m_framePublishLock); if (lgmpHostQueueNewSubs(m_frameQueue)) m_frameResendPending = true;