diff --git a/Core/HLE/sceDisplay.cpp b/Core/HLE/sceDisplay.cpp index 7d7566c32b..3890eefb59 100644 --- a/Core/HLE/sceDisplay.cpp +++ b/Core/HLE/sceDisplay.cpp @@ -16,6 +16,7 @@ // https://github.com/hrydgard/ppsspp and http://www.ppsspp.org/. #include +#include #include #include #include @@ -129,6 +130,15 @@ static const double LAG_SYNC_BURST_BELOW = 0.10; static const double LAG_SYNC_PACE_ABOVE = 0.25; static const int LAG_SYNC_PACE_WINDOWS = 2; static LagSyncStats lagSyncStats; +// How far emulation recently fell behind the wall clock while pacing, a stall in a busy frame for +// example. The audio buffer needs that much room on top. The most over the last few seconds, so +// stalls that recur keep it up while a single long one (loading a state) is soon forgotten. +// Read from the audio thread. +static const int LAG_SYNC_BEHIND_SECONDS = 5; +static double lagSyncBehind[LAG_SYNC_BEHIND_SECONDS]{}; +static int lagSyncBehindSecond = 0; +static double lagSyncBehindSecondStart = 0.0; +static std::atomic lagSyncBehindPeakUs{}; static int numSkippedFrames; static bool hasSetMode; @@ -228,6 +238,28 @@ static void ResetLagSyncBase() { lagSyncEmuBase = CoreTiming::GetGlobalTimeUs(); } +static void UpdateLagSyncBehind(double behind, double now) { + if (now - lagSyncBehindSecondStart >= 1.0) { + // A long gap (a pause) skips seconds, which all count as quiet. + const int seconds = std::min((int)(now - lagSyncBehindSecondStart), LAG_SYNC_BEHIND_SECONDS); + for (int i = 0; i < seconds; i++) { + lagSyncBehindSecond = (lagSyncBehindSecond + 1) % LAG_SYNC_BEHIND_SECONDS; + lagSyncBehind[lagSyncBehindSecond] = 0.0; + } + lagSyncBehindSecondStart = now; + } + lagSyncBehind[lagSyncBehindSecond] = std::max(lagSyncBehind[lagSyncBehindSecond], behind); + double peak = 0.0; + for (double b : lagSyncBehind) { + peak = std::max(peak, b); + } + lagSyncBehindPeakUs.store((int)(peak * 1000000.0), std::memory_order_relaxed); + lagSyncStats.maxBehind = std::max(lagSyncStats.maxBehind, behind); + if (behind > 0.003) { + lagSyncStats.stalls++; + } +} + static void ResetLagSyncWindow(double now) { lagSyncWindowStart = now; lagSyncWindowIdle = 0.0; @@ -283,6 +315,8 @@ void __DisplayInit() { lagSyncBursting = false; lagSyncWakeLate = 0.0; lagSyncStats = LagSyncStats(); + std::fill(std::begin(lagSyncBehind), std::end(lagSyncBehind), 0.0); + lagSyncBehindPeakUs = 0; ScheduleLagSync(); CoreTiming::ScheduleEvent(msToCycles(frameMs - vblankMs), enterVblankEvent, 0); @@ -677,6 +711,10 @@ void __DisplayGetLagSyncStats(LagSyncStats *stats) { stats->bursting = lagSyncBursting; } +double __DisplayGetLagSyncBehindPeak() { + return lagSyncBehindPeakUs.load(std::memory_order_relaxed) / 1000000.0; +} + LagSyncMode __DisplayGetLagSyncMode() { if (lagSyncScheduled) { return LagSyncMode::PACING; @@ -989,6 +1027,9 @@ void hleLagSync(u64 userdata, int cyclesLate) { lagSyncStats.sleeps++; lagSyncStats.slept += now - before; lagSyncStats.late += now - goal; + UpdateLagSyncBehind(0.0, now); + } else { + UpdateLagSyncBehind(before - goal, before); } lagSyncScheduled = WantLagSyncPacing(); diff --git a/Core/HLE/sceDisplay.h b/Core/HLE/sceDisplay.h index 982fa42a21..a364a41382 100644 --- a/Core/HLE/sceDisplay.h +++ b/Core/HLE/sceDisplay.h @@ -53,6 +53,10 @@ struct LagSyncStats { int resets = 0; // Times it fell back to bursting. int bursts = 0; + // The furthest behind the wall clock it was while pacing, in seconds (usually after loading a + // state), and how many times it was more than 3 ms behind. + double maxBehind = 0.0; + int stalls = 0; bool bursting = false; }; void __DisplayGetLagSyncStats(LagSyncStats *stats); @@ -64,6 +68,8 @@ enum class LagSyncMode { BURSTING, }; LagSyncMode __DisplayGetLagSyncMode(); +// How far emulation recently fell behind the wall clock while pacing, in seconds (a decaying peak). +double __DisplayGetLagSyncBehindPeak(); void Register_sceDisplay_driver(); void __DisplayWaitForVblanks(const char* reason, int vblanks, bool callbacks = false); diff --git a/Core/HW/GranularMixer.cpp b/Core/HW/GranularMixer.cpp index 847f1394aa..e5da3c4f38 100644 --- a/Core/HW/GranularMixer.cpp +++ b/Core/HW/GranularMixer.cpp @@ -14,6 +14,7 @@ #include "Common/Math/math_util.h" #include "Common/Swap.h" #include "Core/Config.h" +#include "Core/HLE/sceDisplay.h" #include "Core/HW/Display.h" #include "Core/HW/StereoResampler.h" #include "Core/Core.h" @@ -110,12 +111,18 @@ void GranularMixer::Mix(s16 *samples, u32 num_samples, int outSampleRate, float // We aim for the same latency as StereoResampler, but must also have room for slow (like 20fps) // games, which generate all their audio in a burst each frame (since we can't force real // clock sync), and keep half the queue above what one output callback reads, or each callback - // runs dry. Bluetooth and other non-fast outputs read in large chunks. + // runs dry. Bluetooth and other non-fast outputs read in large chunks. While lag sync paces, + // audio arrives every millisecond or two instead, so there's no frame burst to make room for, + // only for how far emulation has recently fallen behind (the target includes that too), up to + // a frame, which is what bursting makes room for. Nothing drains an overfull queue but an overrun. // One more granule on top, for the two half-overlapping granules being played. const int targetSamples = StereoResampler::TargetBufferSize(); - const int frameSamples = (int)std::llround(frameTimeEstimate_ * inSampleRate); + const bool pacing = __DisplayGetLagSyncMode() == LagSyncMode::PACING; + const int burstSamples = (int)std::llround(frameTimeEstimate_ * inSampleRate); + const int frameSamples = pacing ? 0 : burstSamples; + const int behindSamples = pacing ? std::min((int)(__DisplayGetLagSyncBehindPeak() * inSampleRate), burstSamples) : 0; const int readSamples = (int)(smoothedReadSize_ * inSampleRate / out_sample_rate); - const u32 buffer_size_samples = std::max({ targetSamples, frameSamples + targetSamples / 2, readSamples * 2 }) + GRANULE_SIZE; + const u32 buffer_size_samples = std::max({ targetSamples, frameSamples + targetSamples / 2, readSamples * 2 + behindSamples }) + GRANULE_SIZE; queuedSamplesTarget_ = buffer_size_samples; // Limit the possible queue sizes to any number between 4 and 64. diff --git a/Core/HW/StereoResampler.cpp b/Core/HW/StereoResampler.cpp index 30529a93bb..f85cced02a 100644 --- a/Core/HW/StereoResampler.cpp +++ b/Core/HW/StereoResampler.cpp @@ -32,7 +32,7 @@ #define TARGET_BUFSIZE_LAG_SYNC_MARGIN 192 // 4.4 ms #define TARGET_BUFSIZE_LAG_SYNC_UNKNOWN 882 // 20 ms -#define TARGET_EXCESS_DROP 441 // 10 ms +#define TARGET_EXCESS_DROP 220 // 5 ms #define MAX_FREQ_SHIFT 600.0f // how far off can we be from 44100 Hz #define CONTROL_FACTOR 0.2f // in freq_shift per fifo size offset @@ -91,9 +91,11 @@ int StereoResampler::TargetBufferSize() { target = std::min(4096, systemBufsize + TARGET_BUFSIZE_MARGIN); } // While lag sync paces, audio arrives every millisecond or two rather than a frame's worth at - // a time, so the buffer only has to cover the output's period and a little jitter. + // a time, so the buffer only has to cover the output's period, a little jitter, and how far + // emulation has recently fallen behind (a slow display list, say). if (__DisplayGetLagSyncMode() == LagSyncMode::PACING) { - const int lagSyncTarget = systemBufsize > 0 ? systemBufsize + TARGET_BUFSIZE_LAG_SYNC_MARGIN : TARGET_BUFSIZE_LAG_SYNC_UNKNOWN; + const int behind = (int)(__DisplayGetLagSyncBehindPeak() * 44100.0); + const int lagSyncTarget = (systemBufsize > 0 ? systemBufsize + TARGET_BUFSIZE_LAG_SYNC_MARGIN : TARGET_BUFSIZE_LAG_SYNC_UNKNOWN) + behind; target = std::min(target, lagSyncTarget); } return target; @@ -343,11 +345,16 @@ void StereoResampler::GetAudioDebugStats(char *buf, size_t bufSize) { double bufferLatencyMs = 1000.0 * (double)lastBufSize_ / (double)inputSampleRateHz_; double targetMs = 1000.0 * (double)targetBufsize_ / (double)inputSampleRateHz_; - const char *lagSync = "off"; + char lagSync[64] = "off"; switch (__DisplayGetLagSyncMode()) { - case LagSyncMode::PACING: lagSync = "pacing (small target)"; break; - case LagSyncMode::BURSTING: lagSync = "on, but bursting (host too busy)"; break; - default: break; + case LagSyncMode::PACING: + snprintf(lagSync, sizeof(lagSync), "pacing (small target, %0.1fms of it for stalls)", __DisplayGetLagSyncBehindPeak() * 1000.0); + break; + case LagSyncMode::BURSTING: + snprintf(lagSync, sizeof(lagSync), "on, but bursting (host too busy)"); + break; + default: + break; } snprintf(buf, bufSize, "Audio buffer: %d/%d (%0.1fms, target: %d = %0.1fms)\n" diff --git a/docs/lag-sync.md b/docs/lag-sync.md index 45615b65e4..70eca25b6a 100644 --- a/docs/lag-sync.md +++ b/docs/lag-sync.md @@ -24,16 +24,30 @@ The code is `hleLagSync` and `UpdateLagSyncMode` in `Core/HLE/sceDisplay.cpp`. a frame of audio at once (33 ms in a 30 fps game), so the default target is 40 ms. While lag sync paces (`__DisplayGetLagSyncMode()`), audio arrives every millisecond or two, and the target is the output's period (`SYSPROP_AUDIO_FRAMES_PER_BUFFER`) plus 192 samples (4.4 ms), or 20 ms where the -platform doesn't report a period. On a fallback to bursting it goes back to the default, with some -underruns while the buffer fills up again. +platform doesn't report a period, plus room for stalls (below). It never goes over the default. On a +fallback to bursting it goes back to the default, with some underruns while the buffer fills up again. + +**Stalls.** Pacing doesn't make every millisecond cost the same: a slow display list can hold up +emulation for several milliseconds on a slow device. Lag sync catches up afterwards (its waits are +measured from a fixed base), but meanwhile the output keeps pulling, so the buffer needs that much +room. Each sync that finds emulation behind the wall clock records by how much, and +`__DisplayGetLagSyncBehindPeak()` is the most over the last five seconds: stalls that recur keep the +room, and the one from loading a state is gone five seconds later. With a fixed 4.4 ms, 6 ms stalls +underran a few times in 15 seconds with the classic resampler and 46 times with granular (3 ms +period); with the room added, neither underran. The resampler's rate adjustment only drains a full buffer slowly, around ten seconds from a startup -fill down to a small target. So when the lowest level over a quarter second stays more than 10 ms +fill down to a small target. So when the lowest level over a quarter second stays more than 5 ms above the target, it drops the excess in one go. Bursting's sawtooth never does that: its troughs are below the target. +The granular mixer has no target as such: its queue is capped, and cut back to half the cap when it +overflows, so the level settles somewhere under the cap. The cap makes room for a frame's burst of +audio, which pacing leaves out; it keeps the room for two output reads and adds the room for stalls +there, up to a frame. + The audio debug overlay (and the ImGui debugger's audio window) shows the target in milliseconds, the -lag sync mode and how much excess was dropped. +lag sync mode with the room for stalls, and how much excess was dropped. ## Benchmarking @@ -51,7 +65,7 @@ branch against a build of `master` from the same commit the branch starts from, ``` Frame stats: 422 flips in 14 emulated seconds, wall 15.1s, per second: 32 30 30 ... -Lag sync: 5092 sleeps, 12.63s slept, 1us late on average, 0 resets, 1 fallbacks to bursting (bursting now) +Lag sync: 5092 sleeps, 12.63s slept, 1us late on average, 4 syncs over 3ms behind (54.0ms at most), 0 resets, 1 fallbacks to bursting (bursting now) ``` The second line only appears with lag sync on, and only from the branch build. @@ -133,6 +147,12 @@ and turns sound on, which changes how the frame throttle waits as it does in the two emulated seconds in. Try a 10 ms period (480, a common WASAPI period) and a short one (144), with and without `--lag-sync`, for 15-20 emulated seconds. A single short pull with a hundred or more frames missing shows up now and then at any target; it's the host stalling, not the buffer. +`--audio-granular` mixes with the granular mixer instead, and the line then gives the queue's level +and cap, and counts underruns. + +The averages include the first five seconds after loading the state, when the room for stalls is +still that of the load, which raises them by a few milliseconds. To simulate a slow device's stalls, +put a temporary `sleep_precise` of a few milliseconds every few hundred calls of `hleLagSync`. ### Reference, Windows @@ -147,7 +167,9 @@ Windows 11, x64 desktop, Vulkan, Release, against `master` from where the branch - **Audio.** Average buffer bursting at the default target against lag sync: with a 10 ms period 38 against 16 ms (GTA) and 35 against 17 ms (God of War), with a 3 ms period 37 against 9 ms and 34 against 10 ms, all without underruns. Bursting with the small target forced on underran on a - pull in twelve. + pull in twelve. These were measured before the room for stalls, which adds a few milliseconds to + the averages (see above). Granular, GTA: about 40 ms bursting; with lag sync 25.5 and 21.7 ms + (10 and 3 ms period) while the cap still held a frame, 21.8 and 8.6 ms without it. ## Still to do @@ -155,3 +177,6 @@ Windows 11, x64 desktop, Vulkan, Release, against `master` from where the branch lag sync should be on by default. - On a fallback to bursting the target goes back up at once, and the buffer underruns for a moment while it fills. Raising the target ahead of the switch would avoid that. +- Check the room for stalls on a slow device: how often it gets behind (`--frame-stats` counts the + syncs more than 3 ms behind; its maximum is usually from loading the state), and whether five + seconds is long enough to remember stalls between. diff --git a/headless/Headless.cpp b/headless/Headless.cpp index 60d397f2c5..ce95253eb0 100644 --- a/headless/Headless.cpp +++ b/headless/Headless.cpp @@ -926,8 +926,8 @@ static bool RunAutoTest(GraphicsContext *graphicsContext, CoreParameter &corePar if (g_Config.bForceLagSync) { LagSyncStats lagSync; __DisplayGetLagSyncStats(&lagSync); - fprintf(stderr, "Lag sync: %d sleeps, %.2fs slept, %.0fus late on average, %d resets, %d fallbacks to bursting%s\n", - lagSync.sleeps, lagSync.slept, lagSync.sleeps ? lagSync.late / lagSync.sleeps * 1e6 : 0.0, lagSync.resets, lagSync.bursts, lagSync.bursting ? " (bursting now)" : ""); + fprintf(stderr, "Lag sync: %d sleeps, %.2fs slept, %.0fus late on average, %d syncs over 3ms behind (%.1fms at most), %d resets, %d fallbacks to bursting%s\n", + lagSync.sleeps, lagSync.slept, lagSync.sleeps ? lagSync.late / lagSync.sleeps * 1e6 : 0.0, lagSync.stalls, lagSync.maxBehind * 1000.0, lagSync.resets, lagSync.bursts, lagSync.bursting ? " (bursting now)" : ""); } } if (g_audioSink.Active()) {