mirror of
https://github.com/libretro/virtualjaguar-libretro.git
synced 2026-11-07 12:47:58 -10:00
* test(app): VJ_PERF_TRACE frame/take timing trace + evenness model (#967) VJ_PERF_TRACE=<prefix> with --perf-frames writes <prefix>-emu.csv (each emulated frame: due on the pacing grid, start, end, trim, audio queue, serial) and <prefix>-ui.csv (each UI iteration: take time, serial shown, swap begin/return, the late latch's wake/target/budget), all on SDL_GetTicksNS, so frame ends and take points can be placed against the vblank. VJ_PERF_CSV counts frames run between takes, not frames shown. pacing_clock_test --model prints the fake-clock model: the +/-0.5% trim moves the grid's phase ~1 ms per minute even with 5 ms device-pull jitter, while repeats+skips grow ~32/min per ms of frame-end spread. Refs #967 Co-Authored-By: Claude Opus 5.5 <[email protected]> (cherry picked from commit 462c14627faf7940f222f87f1947070e590041b0) * fix(app): late latch: cap late-start exemptions, one long build no longer sets the budget (#967) Two items from the Phase 1 review: - a wait that overran its wake time is excused from the miss rate only kMaxLateExempt (8) times in a row; a wait that always overruns is the latch's own cost and must be able to release it; - the budget is the second-slowest of the last 60 builds: one long build (a window opening, a shader compile) misses its vblank whatever the budget says, and as the max it also gave up the wait, or moved the take point several ms earlier, for the next second. Refs #967 Co-Authored-By: Claude Opus 5.5 <[email protected]> (cherry picked from commit bdc878609859e4f719d1377cb0d4afb882c47343) * fix(app): mode A steers the emulation grid's phase off the UI's take point (#967) The threaded loop repeated and skipped frames 60-160 times a minute where the 60.054-vs-60 Hz beat owes 3-4 skips. A frame ends at its due time plus its wake-up lateness and cost, so while the slowly drifting grid carries a take point through that spread, whether each frame makes the take is decided by its own cost: spread / 15 us frames in a row come out as random repeat + skip pairs. The single-thread loop never sees this: it runs the frame for each vblank inside that iteration. PacingClock now remembers the last 120 frame ends against their due times, and when the next frame's window (p2..p98, plus 0.75 ms) would contain a take point, steps the grid once across it in the direction the beat already moves it. Each crossing is then the one skip (or repeat) it has to be. Only the phase moves, by at most the window once per beat; the rate stays the trimmed audio rate (pacing_clock_test: 3 ppm over 150 s against a 200 ppm sound card, no underrun). The UI publishes its take time and the display period while the latch has the vblank grid locked (with or without the wait); --pace-steer off disables it for A/B. Model (pacing_clock_test --model): 4 ms cost spread, 60 Hz, take 3 ms before the vblank: 133 repeats + 136 skips per minute unsteered, 0 + 3 steered (4 steps); 120 Hz: 577 frames held 1 or 3 refreshes -> 7. Refs #967 Co-Authored-By: Claude Opus 5.5 <[email protected]> (cherry picked from commit a01504788087a0d3160242f0ee13a89699517b94) * docs(app): mode A phase steering in the emulation-thread design (#967) Refs #967 Co-Authored-By: Claude Opus 5.5 <[email protected]> (cherry picked from commit 133ee01a2f4b51f85f83473a060455808465289c) * fix(app): steering holds the end window across cost switches (#967) Measured on the Studio (yarc, VJ_PERF_TRACE): the emulation thread wakes 0.5-3 ms late and the frame cost switches with the content between ~7.5 and ~2.9 ms for seconds at a time. Two faults showed in the first steered run (12 repeats + 35 skips, 29 steps): - the 'not before this frame can end' guard used the window's p98, so after a switch to cheap frames every earlier step was refused while the ends dithered on the take point; the guard is now only 'not before the frame starting now' (a step that lands early just starts late); - the 120-frame window forgot the slow mode within 2 s, so the switch back landed the ends on the take point; the window's edges are now held and shrink back at 0.2 ms/s. pacing_clock_test models both (wake lateness + a switching cost, six take offsets): 18-38 repeats+skips per minute before, 3-5 after. Refs #967 Co-Authored-By: Claude Opus 5.5 <[email protected]> (cherry picked from commit 90643d1e44af0b4de36c95576a28618f3c23849d) * fix(app): steering follows the trimmed drift, at most one step per 30 frames (#967) Studio, Cybermorph, steering v2: 20 repeats + 38 skips and 98 steps. Every step went earlier (the untrimmed 60.054-on-60 Hz direction) and queued its few ms of audio; 55 ms in a minute held the trim at +0.17%, past the beat's 0.09%, so the grid was drifting the other way and each step put the window back in front of the take point. The direction now comes from the trimmed period, which makes the steps self-correcting (a late step drains what an early one queued). A floor of 30 frames between steps keeps any other mistake from becoming a display lock. pacing_clock_test: a grid slower than the panel (a 0.15% slow sound card) went from 5224 steps and 0 repeats (a lock) to 4 repeats and 5 steps in 120 s; a 9 ms window: 6-7 events in 120 s. Refs #967 Co-Authored-By: Claude Opus 5.5 <[email protected]> (cherry picked from commit 395e255eeb49c69171ccf03a64ebc9bae71b8ddf) * docs(app): VJ_PERF_TRACE summary script, --pace-steer in the README (#967) Refs #967 Co-Authored-By: Claude Opus 5.5 <[email protected]> (cherry picked from commit 1cbe57b59b135a0a280d14ca4545742e24897c6f) * fix(app): steer only where the grid creeps along the take grid (#967) At ratios off a whole number (50.08 Hz PAL on 60 Hz, 60.05 on 75 or 144 Hz) successive frames land ~3 ms apart on the take grid, so some frame's end window always holds a take point: that is 5:6-style judder, not a slow crossing. pacing_clock_test showed 99-119 steps a minute there and the rate pulled off the audio clock. Steering now needs the untrimmed creep to be under 0.2 ms a frame (60.05 Hz on 60/120/59.94 Hz: 15-32 us): 0 steps, no underrun, rate kept at all three ratios. Refs #967 Co-Authored-By: Claude Opus 5.5 <[email protected]> (cherry picked from commit 9adae8e4d64c897a6834f4d6e98f4eed6f048a94) * test(app): perf_trace_summary.py computes event -> present exactly from the trace (#967) ~11,000 virtual events per run instead of 120 injected keys, whose run averages moved by up to 3.4 ms between identical runs. Refs #967 Co-Authored-By: Claude Opus 5.5 <[email protected]> (cherry picked from commit 469cf23cbabc1e63b5cce10b52d06d1608dd7873) --------- Co-authored-by: Claude Opus 5.5 <[email protected]>
This commit is contained in:
Joe MattielloandClaude Opus 5.5 authored and GitHub committed
1 parent
df0f6d271b
commit
1b18d49117
13 files changed
+692
-18
No files matched your search
+5
-1
@@ -503,7 +503,11 @@ and lets go by itself if frames keep missing them; the log says `[emu] late latc
|
||||
`--late-latch off` turns it off for a measurement. For a dev measurement, `virtualjaguar --perf-frames N` with
|
||||
`VJ_PERF_CSV=path` writes one row per measured iteration when the run ends, with the `input_lat_ms` (event to the
|
||||
emulation's poll) and `present_lat_ms` (event to the swap that shows it) columns; `--perf-input` injects a key every
|
||||
30 iterations so they have samples.
|
||||
30 iterations so they have samples. `VJ_PERF_TRACE=prefix` adds `prefix-emu.csv` (each emulated frame: due, start, end,
|
||||
trim, audio queue) and `prefix-ui.csv` (each UI take and swap); `python3 app/tests/perf_trace_summary.py prefix` counts
|
||||
the frames really shown and splits their timing. With the latch's vblank grid locked, the emulation steps its pacing
|
||||
grid's phase once whenever frame ends would straddle the take point, so each 60.05-on-60 Hz crossing is one skip rather
|
||||
than a burst of repeats and skips; `--pace-steer off` turns that off for a measurement.
|
||||
|
||||
While it is on, this version switches off RetroAchievements, netplay, the Tools (debugger) windows and the GDB stub
|
||||
option. They move to the emulation thread in later phases. A log line `[core_host] owner violation: ...` means a UI
|
||||
|
||||
@@ -114,6 +114,16 @@ struct App::EmuClient : EmuThread::Client {
|
||||
double framePeriod() override { return 1.0 / std::max(1.0, app.host.fps()); }
|
||||
double audioQueuedMs() override { return app.emuAudioQueuedMs(); }
|
||||
void runFrame() override { app.emuRunOneFrame(); }
|
||||
void framePaced(double lateSec, const PacingClock& clock) override { app.tracePaced(lateSec, clock); }
|
||||
bool takeGrid(double now, double& at, double& period) override {
|
||||
const uint64_t p = app.takePeriodNs_.load(std::memory_order_acquire);
|
||||
const uint64_t t = app.takeNs_.load(std::memory_order_relaxed);
|
||||
if (!p || !t) return false;
|
||||
const uint64_t sdlNow = SDL_GetTicksNS(); // the UI's clock -> this thread's
|
||||
at = now - (double)(int64_t)(sdlNow - t) / 1e9;
|
||||
period = (double)p / 1e9;
|
||||
return true;
|
||||
}
|
||||
void afterCommands() override { app.host.publishSnapshot(); }
|
||||
void commandFailed(const std::string& what) override {
|
||||
app.host.pushMessage("Emulation command failed: " + what, 5000, RETRO_LOG_ERROR);
|
||||
@@ -547,6 +557,12 @@ void App::stopEmuThread() {
|
||||
void App::emuRunOneFrame() {
|
||||
if (!emuFastForward_.load(std::memory_order_relaxed)) audio.update(false); // underruns only: mode A follows the audio clock
|
||||
host.wantVideo = true;
|
||||
PerfTrace::Emu te = tracePaced_;
|
||||
if (trace_.enabled()) {
|
||||
te.startNs = SDL_GetTicksNS();
|
||||
te.dueNs = tracePacedSet_ ? te.startNs - te.dueNs : te.startNs; // tracePaced() left the lateness there
|
||||
tracePacedSet_ = false;
|
||||
}
|
||||
const uint64_t r0 = SDL_GetPerformanceCounter();
|
||||
host.runFrame();
|
||||
retroTicks_.fetch_add(SDL_GetPerformanceCounter() - r0, std::memory_order_relaxed);
|
||||
@@ -564,9 +580,52 @@ void App::emuRunOneFrame() {
|
||||
frames.publish();
|
||||
lastSentSerial_ = f.serial;
|
||||
}
|
||||
if (trace_.enabled()) {
|
||||
te.endNs = SDL_GetTicksNS();
|
||||
te.serial = f.serial;
|
||||
trace_.emu(te);
|
||||
}
|
||||
host.publishSnapshot();
|
||||
}
|
||||
|
||||
// Emulation thread (VJ_PERF_TRACE): the pacing of the frame emuRunOneFrame() runs next.
|
||||
void App::tracePaced(double lateSec, const PacingClock& clock) {
|
||||
if (!trace_.enabled()) return;
|
||||
tracePaced_.dueNs = lateSec > 0 ? (uint64_t)(lateSec * 1e9) : 0; // a lateness until the frame starts
|
||||
tracePaced_.trim = (float)clock.trim();
|
||||
tracePaced_.filtQMs = (float)clock.filteredQueueMs();
|
||||
tracePaced_.queuedMs = (float)emuAudioQueuedMs();
|
||||
tracePaced_.audio = clock.audioLocked() ? 1 : 0;
|
||||
tracePaced_.refill = clock.refilling() ? 1 : 0;
|
||||
tracePacedSet_ = true;
|
||||
}
|
||||
|
||||
// UI thread, threaded: this iteration takes its frame now. While the swaps sit on a tracked vblank grid (vsync on, the
|
||||
// latch's phase locked, whether or not it waits), the takes repeat every refresh, and the emulation thread keeps its
|
||||
// frame ends off them (PacingClock::steer).
|
||||
void App::publishTakeGrid(uint64_t takeNs) {
|
||||
const uint64_t p = (paceSteerOn_ && vsync && latch_.locked()) ? latch_.periodNs() : 0;
|
||||
takeNs_.store(takeNs, std::memory_order_relaxed);
|
||||
takePeriodNs_.store(p, std::memory_order_release);
|
||||
}
|
||||
|
||||
// UI thread (VJ_PERF_TRACE): one row per iteration, right after its swap.
|
||||
void App::traceUi(uint64_t takeNs, uint64_t serial, uint64_t swap0, uint64_t swap1) {
|
||||
if (!trace_.enabled()) return;
|
||||
PerfTrace::Ui u{};
|
||||
u.takeNs = takeNs;
|
||||
u.serial = serial;
|
||||
u.swap0Ns = swap0;
|
||||
u.swap1Ns = swap1;
|
||||
u.wakeNs = traceWakeNs_;
|
||||
u.waitEndNs = threaded() ? latchedAtNs_ : 0;
|
||||
u.budgetNs = latch_.budgetNs();
|
||||
u.targetNs = traceTargetNs_;
|
||||
u.locked = latch_.locked() ? 1 : 0;
|
||||
trace_.ui(u);
|
||||
traceWakeNs_ = traceTargetNs_ = 0;
|
||||
}
|
||||
|
||||
// The audio clock for mode A, or -1 when there is none to follow: no device, a paused stream, mute (nothing is
|
||||
// queued) or fast-forward (the audio is dropped). PacingClock then uses the wall clock.
|
||||
double App::emuAudioQueuedMs() const {
|
||||
@@ -643,6 +702,8 @@ void App::notePresented(uint64_t swapEndNs) {
|
||||
void App::latchWait() {
|
||||
if (latchChecks_++ % 60 == 0) latchUpdatePeriod(); // the window may have moved to another display
|
||||
const uint64_t wake = latch_.wakeAt(SDL_GetTicksNS());
|
||||
traceWakeNs_ = wake;
|
||||
traceTargetNs_ = latch_.targetNs();
|
||||
for (;;) {
|
||||
const uint64_t t = SDL_GetTicksNS();
|
||||
if (t >= wake || quit) return;
|
||||
@@ -1536,7 +1597,16 @@ void App::stepEmulation() {
|
||||
host.wantVideo = (i == frames - 1);
|
||||
if (!fastForward) audio.update();
|
||||
uint64_t r0 = perf.on ? perf.tick() : 0;
|
||||
PerfTrace::Emu te{};
|
||||
if (trace_.enabled()) te.dueNs = te.startNs = SDL_GetTicksNS();
|
||||
host.runFrame();
|
||||
if (trace_.enabled()) {
|
||||
te.endNs = SDL_GetTicksNS();
|
||||
te.serial = host.frame().serial;
|
||||
te.trim = 1.0f;
|
||||
te.filtQMs = te.queuedMs = audio.queuedMs();
|
||||
trace_.emu(te);
|
||||
}
|
||||
if (r0) perf.add(Perf::Retro, 1000.0 * (double)(perf.tick() - r0) / (double)perf.freq);
|
||||
perf.emulated();
|
||||
ach.afterFrame();
|
||||
@@ -1686,6 +1756,7 @@ int App::runInteractive(const CliArgs& a) {
|
||||
audio.open(48043.6);
|
||||
if (emuThreadThisRun_) startEmuThread(); // after the window and the audio device (design section 7)
|
||||
lateLatchOn_ = a.lateLatch != 0;
|
||||
paceSteerOn_ = a.paceSteer != 0;
|
||||
fullscreen = false;
|
||||
if (a.fullscreen) setFullscreen(true);
|
||||
if (a.showWindow.rfind("settings", 0) == 0) {
|
||||
@@ -1735,6 +1806,8 @@ int App::runInteractive(const CliArgs& a) {
|
||||
fpsWindowStart_ = now();
|
||||
lastSramFlush_ = now();
|
||||
perf.init(a.perfFrames, a.perfGpu);
|
||||
trace_.init(a.perfFrames);
|
||||
uint64_t traceSerial = 0;
|
||||
video.shader.reuseOutput = !a.perfNoReuse;
|
||||
perf.forceW = a.perfShaderW;
|
||||
perf.forceH = a.perfShaderH;
|
||||
@@ -1756,7 +1829,11 @@ int App::runInteractive(const CliArgs& a) {
|
||||
std::to_string(latch_.misses()) + ", released " + std::to_string(latch_.released()) +
|
||||
", pad " + std::to_string(latch_.padNs() / 1000000.0).substr(0, 4) + " ms)"
|
||||
: std::string("off"));
|
||||
if (threaded())
|
||||
perf.note += std::string(", pace steering ") + (paceSteerOn_ ? "on" : "off") + " (" +
|
||||
std::to_string(emu.phaseSteps()) + " steps)";
|
||||
perf.report(host.contentName().c_str());
|
||||
trace_.write();
|
||||
break;
|
||||
}
|
||||
if (a.perfPause && perf.seen == 30 && !paused && host.isLoaded()) togglePause(); // after a few real frames
|
||||
@@ -1776,6 +1853,8 @@ int App::runInteractive(const CliArgs& a) {
|
||||
else stepEmulation();
|
||||
perf.lap(Perf::Step);
|
||||
video.setSourceFps((float)host.fps());
|
||||
const Uint64 takeNs = SDL_GetTicksNS();
|
||||
if (threaded()) publishTakeGrid(takeNs);
|
||||
if (!threaded()) video.upload(host.frame());
|
||||
else {
|
||||
adoptFrameEpoch();
|
||||
@@ -1785,6 +1864,10 @@ int App::runInteractive(const CliArgs& a) {
|
||||
shownSeq_ = s->inputSeq;
|
||||
}
|
||||
}
|
||||
if (trace_.enabled()) {
|
||||
const FrameExchange::Slot* cur = threaded() ? frames.current() : nullptr;
|
||||
traceSerial = threaded() ? (cur ? cur->frame.serial : 0) : host.frame().serial;
|
||||
}
|
||||
if (perf.on && perf.gpu) Perf::finish();
|
||||
perf.lap(Perf::Upload);
|
||||
|
||||
@@ -1815,6 +1898,7 @@ int App::runInteractive(const CliArgs& a) {
|
||||
const Uint64 swap1 = SDL_GetTicksNS();
|
||||
const Uint64 swapNs = swap1 - swap0;
|
||||
notePresented(swap1);
|
||||
traceUi(takeNs, traceSerial, swap0, swap1);
|
||||
if (threaded()) {
|
||||
if (latchedAtNs_) latch_.noteBuild(swap0 - latchedAtNs_);
|
||||
latch_.onSwap(swap0, swap1);
|
||||
|
||||
@@ -34,6 +34,7 @@
|
||||
#include "pacing.h"
|
||||
#include "paths.h"
|
||||
#include "perf.h"
|
||||
#include "perf_trace.h"
|
||||
#include "platform/commands.h"
|
||||
#include "theme_custom.h"
|
||||
#include "tv/tv_mode.h"
|
||||
@@ -91,6 +92,7 @@ struct CliArgs {
|
||||
int emuThread = -1; // --emu-thread on|off: the emulation on its own thread for this run (-1 = the setting; headless: off)
|
||||
bool perfInput = false; // dev: with --perf-frames, inject a key event every 30 iterations (input-latency column)
|
||||
int lateLatch = -1; // dev: --late-latch on|off, threaded + vsync only (default on; #967 measurement)
|
||||
int paceSteer = -1; // dev: --pace-steer on|off, threaded + vsync only (default on; #967 evenness)
|
||||
// RetroAchievements (#836): the headless test hooks. There is no way to sign in
|
||||
// headless; the only server is the canned-JSON mock, so a test can never reach
|
||||
// (or authenticate against) the real service.
|
||||
@@ -369,6 +371,11 @@ private:
|
||||
// to the emulation thread as it arrives, then take the newest frame.
|
||||
LateLatch latch_;
|
||||
bool lateLatchOn_ = true;
|
||||
// PacingClock's steering (#967 evenness): the UI publishes where it takes frames; the emulation thread keeps frame
|
||||
// ends off those take points. Period 0 = no take grid (vsync off, swaps not on a tracked vblank grid, steering off).
|
||||
bool paceSteerOn_ = true;
|
||||
std::atomic<uint64_t> takeNs_{0}, takePeriodNs_{0};
|
||||
void publishTakeGrid(uint64_t takeNs);
|
||||
uint64_t latchedAtNs_ = 0; // when this iteration's wait ended: its UI work starts there
|
||||
unsigned latchChecks_ = 0;
|
||||
bool latchLogged_ = false;
|
||||
@@ -401,6 +408,13 @@ private:
|
||||
std::atomic<uint64_t> retroTicks_{0}; // performance-counter ticks inside retro_run, since the UI last read them
|
||||
CoreInput emuInput_; // emulation thread: what the core reads this frame
|
||||
uint64_t lastSentSerial_ = 0; // emulation thread: the last frame handed to FrameExchange
|
||||
// VJ_PERF_TRACE (perf_trace.h, #967 evenness)
|
||||
PerfTrace trace_;
|
||||
PerfTrace::Emu tracePaced_{}; // emulation thread: the pacing of the frame about to run
|
||||
bool tracePacedSet_ = false;
|
||||
uint64_t traceWakeNs_ = 0, traceTargetNs_ = 0; // UI thread: the late latch's last wait (0 = none)
|
||||
void tracePaced(double lateSec, const PacingClock& clock);
|
||||
void traceUi(uint64_t takeNs, uint64_t serial, uint64_t swap0, uint64_t swap1);
|
||||
uint64_t emuFramesSeen_ = 0; // UI thread: EmuThread::framesRun() at the previous iteration
|
||||
uint64_t pendingStateAt_ = 0; // threaded: run the pending state load once framesRun() reaches this
|
||||
uint64_t shownEpoch_ = 0; // UI thread: FrameExchange::epoch() the picture on screen belongs to
|
||||
|
||||
@@ -154,25 +154,30 @@ void EmuThread::loop() {
|
||||
in.audioQueuedMs = client_->audioQueuedMs();
|
||||
in.targetMs = targetMs_.load();
|
||||
in.fastForward = ff_.load();
|
||||
if (!client_->takeGrid(in.now, in.takeAt, in.takePeriod)) in.takeAt = in.takePeriod = 0;
|
||||
if (!pacing) {
|
||||
clock.reset(in.now);
|
||||
pacing = true;
|
||||
}
|
||||
double due = in.now;
|
||||
if (!budget) {
|
||||
const double due = clock.nextDue(in);
|
||||
due = clock.nextDue(in);
|
||||
if (due > in.now + 0.0002) {
|
||||
cmds_.waitUntil(atSec(std::min(due, in.now + 0.1))); // re-checked at least every 100 ms
|
||||
continue;
|
||||
}
|
||||
}
|
||||
clock.frameStarted(in);
|
||||
if (!budget) client_->framePaced(in.now - due, clock);
|
||||
client_->runFrame();
|
||||
clock.frameEnded(nowSec());
|
||||
frames_.fetch_add(1);
|
||||
if (budget) { // done before the budget drops: advance() reads advanceDone_ when the budget hits 0
|
||||
advanceDone_.fetch_add(1);
|
||||
advanceLeft_.fetch_sub(1);
|
||||
}
|
||||
dropped_.store(clock.droppedFrames());
|
||||
steers_.store(clock.steers());
|
||||
notifyFrame();
|
||||
}
|
||||
if (cmds_.closeAndDrain(onError) > 0) client_->afterCommands();
|
||||
|
||||
@@ -42,6 +42,12 @@ public:
|
||||
virtual double framePeriod() = 0; // seconds per emulated frame (1 / the core's fps)
|
||||
virtual double audioQueuedMs() = 0; // the audio clock; < 0 = none usable (wall clock)
|
||||
virtual void runFrame() = 0; // one emulated frame, then publish it
|
||||
// Just before a paced runFrame(): how late it starts against its due time (seconds) and the clock that paced it
|
||||
// (App: VJ_PERF_TRACE). Frames run by advance() are not paced and do not call it.
|
||||
virtual void framePaced(double lateSec, const PacingClock& clock) { (void)lateSec, (void)clock; }
|
||||
// Where the UI takes finished frames, for PacingClock's steering: one take time (seconds, on `now`'s clock:
|
||||
// steady_clock) and the take period. False = no take grid (vsync off, swaps not tracked): no steering.
|
||||
virtual bool takeGrid(double now, double& at, double& period) { (void)now, (void)at, (void)period; return false; }
|
||||
virtual void afterCommands() {} // a batch of commands ran (App: CoreHost::publishSnapshot)
|
||||
virtual void commandFailed(const std::string& what) { (void)what; } // a post()ed command threw
|
||||
};
|
||||
@@ -89,6 +95,7 @@ public:
|
||||
void setAudioTargetMs(double ms) { targetMs_.store(ms); }
|
||||
uint64_t framesRun() const { return frames_.load(); }
|
||||
uint64_t droppedFrames() const { return dropped_.load(); }
|
||||
uint64_t phaseSteps() const { return steers_.load(); } // PacingClock::steers()
|
||||
|
||||
private:
|
||||
enum class State { Inline, Starting, Running, Stopping, Stopped, Abandoned };
|
||||
@@ -105,7 +112,7 @@ private:
|
||||
std::atomic<double> targetMs_{64.0};
|
||||
std::atomic<unsigned> advanceLeft_{0};
|
||||
std::atomic<uint64_t> advanceDone_{0}; // budgeted frames run (bumped before advanceLeft_ drops)
|
||||
std::atomic<uint64_t> frames_{0}, dropped_{0};
|
||||
std::atomic<uint64_t> frames_{0}, dropped_{0}, steers_{0};
|
||||
std::mutex mu_;
|
||||
std::condition_variable cv_; // start and finish handshakes
|
||||
std::condition_variable advanceCv_; // a frame ran
|
||||
|
||||
+22
-5
@@ -31,6 +31,7 @@ public:
|
||||
static constexpr unsigned kOutcomes = 60; // waits whose outcome (made the vblank / missed) is remembered
|
||||
static constexpr unsigned kMinOutcomes = 8; // waits observed before the miss rate can release the lock
|
||||
static constexpr unsigned kCooldownSwaps = 300; // swaps after a release before the lock may be taken again
|
||||
static constexpr unsigned kMaxLateExempt = 8; // consecutive late-start waits excused; after that they count
|
||||
|
||||
// The display's refresh period (SDL_DisplayMode), 0 = unknown: the latch stays off.
|
||||
void setPeriodNs(uint64_t ns) {
|
||||
@@ -53,6 +54,8 @@ public:
|
||||
|
||||
// When the wait that wakeAt() sized really ended. A wait that overran its wake time (a call() or event handling
|
||||
// inside it, a descheduled thread) started the UI late: its swap missing the vblank says nothing about the budget.
|
||||
// Only kMaxLateExempt in a row are excused, though: a wait that overruns every time (event handling that always
|
||||
// takes longer than the wake leaves room for) is the latch's own cost, and must reach the miss rate that releases it.
|
||||
void noteWaitEnd(uint64_t ns) { waitEndNs_ = ns; }
|
||||
|
||||
// Right after SDL_GL_SwapWindow: when the call began and when it returned. A swap that blocked returned at a
|
||||
@@ -63,7 +66,9 @@ public:
|
||||
if (cooldown_) cooldown_--;
|
||||
const bool lateStart = waitEndNs_ && targetNs_ && waitEndNs_ > wakeNs_ + kOverrunNs;
|
||||
waitEndNs_ = 0;
|
||||
if (targetNs_ && lateStart) { // the UI was late before the build began: not a budget miss, not an outcome
|
||||
if (targetNs_) lateRun_ = lateStart ? lateRun_ + 1 : 0;
|
||||
if (targetNs_ && lateStart && lateRun_ <= kMaxLateExempt) { // the UI was late before the build began: not a
|
||||
// budget miss, not an outcome
|
||||
targetNs_ = 0;
|
||||
} else if (targetNs_) { // this iteration waited: did its swap make the vblank it aimed at?
|
||||
const bool miss = (int64_t)(endNs - targetNs_) > P / 2;
|
||||
@@ -132,13 +137,24 @@ public:
|
||||
}
|
||||
|
||||
bool locked() const { return locked_; }
|
||||
uint64_t targetNs() const { return targetNs_; } // the vblank the wait wakeAt() just sized aims at, 0 = none
|
||||
uint64_t padNs() const { return padNs_; }
|
||||
unsigned misses() const { return misses_; }
|
||||
unsigned released() const { return releases_; } // times the miss rate let the lock go
|
||||
uint64_t budgetNs() const { // the slowest recent build, plus the pad
|
||||
uint64_t mx = 0;
|
||||
for (unsigned i = 0; i < std::min(buildAt_, kBuilds); i++) mx = std::max(mx, builds_[i]);
|
||||
return mx + padNs_;
|
||||
// The second-slowest of the last kBuilds builds, plus the pad. One long build (a window opening, a shader compile)
|
||||
// misses its own vblank whatever the budget says; letting it set the budget would also give up the wait (budget near a
|
||||
// whole period) or move the take point several ms earlier for the next second. Two long builds in a second do count.
|
||||
uint64_t budgetNs() const {
|
||||
uint64_t mx = 0, mx2 = 0;
|
||||
for (unsigned i = 0; i < std::min(buildAt_, kBuilds); i++) {
|
||||
if (builds_[i] > mx) {
|
||||
mx2 = mx;
|
||||
mx = builds_[i];
|
||||
} else if (builds_[i] > mx2) {
|
||||
mx2 = builds_[i];
|
||||
}
|
||||
}
|
||||
return (buildAt_ > 1 ? mx2 : mx) + padNs_;
|
||||
}
|
||||
|
||||
private:
|
||||
@@ -160,6 +176,7 @@ private:
|
||||
unsigned releases_ = 0, cooldown_ = 0;
|
||||
uint8_t outcomes_[kOutcomes] = {}; // 1 = that wait's swap missed its vblank
|
||||
unsigned outcomeAt_ = 0, recentMisses_ = 0;
|
||||
unsigned lateRun_ = 0; // consecutive waits that ended late (noteWaitEnd)
|
||||
uint64_t wakeNs_ = 0, waitEndNs_ = 0; // the wake time wakeAt() returned; when the wait really ended (0 = not told)
|
||||
uint64_t targetNs_ = 0; // the vblank the current wait aims at (0 = no wait this iteration)
|
||||
uint64_t builds_[kBuilds] = {};
|
||||
|
||||
@@ -25,6 +25,7 @@ static void usage(const char* argv0) {
|
||||
" --option KEY=VALUE set a core option for this run (not saved)\n"
|
||||
" --emu-thread on|off the emulation on its own thread for this run (default: Settings > Interface; headless: off)\n"
|
||||
" --late-latch on|off dev: with the emulation thread and vsync, take each frame just before the vblank (default on)\n"
|
||||
" --pace-steer on|off dev: with the emulation thread and vsync, keep frame ends off the take point (default on)\n"
|
||||
" --data-dir DIR keep config, saves and states in DIR\n"
|
||||
" (a portable.txt next to the binary does this too)\n"
|
||||
" --verbose log the core's INFO messages\n"
|
||||
@@ -201,6 +202,14 @@ int main(int argc, char** argv) {
|
||||
}
|
||||
a.lateLatch = v == "on" ? 1 : 0;
|
||||
}
|
||||
else if (!std::strcmp(s, "--pace-steer")) {
|
||||
const std::string v = need(s);
|
||||
if (v != "on" && v != "off") {
|
||||
std::fprintf(stderr, "--pace-steer wants on or off, got '%s'\n", v.c_str());
|
||||
return 2;
|
||||
}
|
||||
a.paceSteer = v == "on" ? 1 : 0;
|
||||
}
|
||||
else if (!std::strcmp(s, "--perf-no-reuse")) a.perfNoReuse = true;
|
||||
else if (!std::strcmp(s, "--perf-shader-out")) {
|
||||
unsigned w = 0, h = 0;
|
||||
|
||||
@@ -18,6 +18,7 @@
|
||||
#pragma once
|
||||
|
||||
#include <algorithm>
|
||||
#include <cmath>
|
||||
#include <cstdint>
|
||||
|
||||
namespace vj {
|
||||
@@ -28,6 +29,10 @@ struct PacingInput {
|
||||
double audioQueuedMs = -1; // queued audio; < 0 = no usable audio clock
|
||||
double targetMs = 64; // audio.target_ms
|
||||
bool fastForward = false;
|
||||
// Where the UI takes finished frames (threaded + vsync, while the swaps show the vblank grid): one take time on
|
||||
// in.now's clock and the take period. takePeriod 0 = no grid (vsync off, not tracked yet): no steering.
|
||||
double takeAt = 0;
|
||||
double takePeriod = 0;
|
||||
};
|
||||
|
||||
class PacingClock {
|
||||
@@ -39,6 +44,13 @@ public:
|
||||
static constexpr double kLowWater = 0.25; // below this fraction of the target: refill...
|
||||
static constexpr double kRefillRate = 2.0; // ...at up to this multiple of the core's rate, up to the target
|
||||
static constexpr double kHighWater = 3.0; // above this multiple of the target the device is not draining
|
||||
static constexpr unsigned kEnds = 120; // frame ends remembered (2 s) for the steering window
|
||||
static constexpr unsigned kMinEnds = 30; // ... before the window is trusted
|
||||
static constexpr double kSteerMargin = 0.00075; // room kept on each side of the window (take-time jitter)
|
||||
static constexpr double kWindowDecay = 0.0002; // the held window shrinks back at 0.2 ms per second
|
||||
static constexpr unsigned kStepGap = 30; // frames at least between two steps: never a display lock
|
||||
static constexpr double kMaxDrift = 0.0002; // steer only where the grid creeps along the take grid (60.05 on
|
||||
// 60/120/59.94 Hz: 15-32 us a frame), never at a 5:6-style ratio
|
||||
|
||||
void reset(double now) {
|
||||
next_ = now;
|
||||
@@ -46,6 +58,12 @@ public:
|
||||
haveQ_ = overfull_ = refill_ = audio_ = false;
|
||||
trim_ = 1.0;
|
||||
init_ = true;
|
||||
endAt_ = 0;
|
||||
curDue_ = -1;
|
||||
loHeld_ = 1e9;
|
||||
hiHeld_ = -1e9;
|
||||
lastSteer_ = now;
|
||||
sinceStep_ = kStepGap;
|
||||
}
|
||||
|
||||
// When the next frame should start (absolute, on in.now's clock). At or before in.now: start it now.
|
||||
@@ -68,17 +86,81 @@ public:
|
||||
const double base = basePeriod(in);
|
||||
if (in.now - next_ > kMaxLateFrames * base) next_ = in.now;
|
||||
lastStart_ = in.now;
|
||||
curDue_ = (refill_ || in.fastForward) ? -1 : std::min(next_, in.now); // (early refill frames: no grid time)
|
||||
// While refilling, frames start early; rebase the grid on each one. Advancing the old grid a full period per
|
||||
// early frame would leave it ahead of the clock by the extra audio just queued, and the loop would then sleep
|
||||
// that long, drain the queue below the low-water mark and re-arm the refill (bursts and stalls forever).
|
||||
next_ = (refill_ ? in.now : next_) + base * (audio_ ? trim_ : 1.0);
|
||||
if (!refill_ && !in.fastForward) steer(in, base);
|
||||
}
|
||||
|
||||
// The frame started last has finished (its picture is handed over) now. Feeds the steering window.
|
||||
void frameEnded(double now) {
|
||||
if (curDue_ < 0) return;
|
||||
ends_[endAt_ % kEnds] = now - curDue_;
|
||||
endAt_++;
|
||||
curDue_ = -1;
|
||||
}
|
||||
|
||||
bool audioLocked() const { return audio_; }
|
||||
double trim() const { return audio_ ? trim_ : 1.0; }
|
||||
uint64_t droppedFrames() const { return dropped_; }
|
||||
double filteredQueueMs() const { return haveQ_ ? filtQ_ : -1.0; } // (VJ_PERF_TRACE)
|
||||
bool refilling() const { return refill_; }
|
||||
uint64_t steers() const { return steers_; } // phase steps taken to keep frame ends off the take point
|
||||
|
||||
private:
|
||||
// Keep frame ends off the UI's take point (#967 evenness). A frame ends somewhere in [due + lo, due + hi] (its
|
||||
// wake-up lateness plus its cost, over the last kEnds frames). The grid drifts against the take points at the
|
||||
// core-vs-display beat (15 us per frame for 60.054 Hz on 60 Hz), so while a take point sits inside that window,
|
||||
// whether a frame makes it is decided by its own cost: for spread / 15 us frames in a row the UI shows a repeat,
|
||||
// then a skip, at random -- dozens of pairs per crossing instead of the one skip the beat owes. So when the next
|
||||
// frame's window would contain a take point, the grid steps once across it, in the direction it is drifting (its
|
||||
// trimmed period against the take period): the crossing happens at once, as the single skip (or repeat) it has to
|
||||
// be, and the drift then carries the window away from the take point for the next ~18 s. Only the grid's phase
|
||||
// moves, by at most the window's width once per crossing; its rate stays the trimmed audio rate, and the step's
|
||||
// audio (a few ms early or late) is what the queue absorbs and the trim corrects. This is not a display lock: the
|
||||
// drift is never held back, steps are at least kStepGap frames apart, and it only runs where the grid creeps along
|
||||
// the take grid (kMaxDrift), never at a ratio like 50.08 Hz on 60 Hz where some frame always straddles a take.
|
||||
void steer(const PacingInput& in, double base) {
|
||||
const double P = in.takePeriod;
|
||||
if (sinceStep_ < kStepGap) sinceStep_++;
|
||||
if (P <= 0 || endAt_ < kMinEnds) return;
|
||||
double r0 = std::fmod(base, P); // the untrimmed creep per frame: off a whole ratio (50.08 Hz on 60, 60.05 on
|
||||
if (r0 > P / 2) r0 -= P; // 75 or 144) frames land ~3 ms apart on the take grid -- judder, not a crossing
|
||||
if (std::fabs(r0) > kMaxDrift) return;
|
||||
double sorted[kEnds];
|
||||
const unsigned n = std::min(endAt_, kEnds);
|
||||
std::copy(ends_, ends_ + n, sorted);
|
||||
std::sort(sorted, sorted + n);
|
||||
// ~p2 and ~p98 (one outlier does not move them), held for a while: costs switch with the content (yarc runs
|
||||
// ~7.5 ms frames for a few seconds, then ~2.9 ms), and a window that forgot the slow frames after kEnds would
|
||||
// let the next switch land them on the take point. The held edges come back at kWindowDecay.
|
||||
const double dt = std::max(0.0, in.now - lastSteer_);
|
||||
lastSteer_ = in.now;
|
||||
loHeld_ = std::min(sorted[n / 50], loHeld_ + kWindowDecay * dt);
|
||||
hiHeld_ = std::max(sorted[n - 1 - n / 50], hiHeld_ - kWindowDecay * dt);
|
||||
const double lo = loHeld_ - kSteerMargin;
|
||||
const double hi = hiHeld_ + kSteerMargin;
|
||||
if (hi - lo >= P - 2 * kSteerMargin) return; // no gap between take points wide enough
|
||||
double x = std::fmod(in.takeAt - next_, P); // from the next frame's due to a take point
|
||||
if (x < lo) x += P * std::ceil((lo - x) / P);
|
||||
if (x > hi) return; // (x is now the first candidate >= lo)
|
||||
// How the grid moves against the take points per frame: x changes by -r. The TRIMMED period: the queue error
|
||||
// a step leaves (or a sound card well off nominal) holds the trim past the beat (0.09% at 60.054 on 60 Hz),
|
||||
// and the grid then drifts the other way; stepping against that drift every frame would be a display lock.
|
||||
double r = std::fmod(base * (audio_ ? trim_ : 1.0), P);
|
||||
if (r > P / 2) r -= P;
|
||||
double step;
|
||||
if (r <= 0) step = -(hi - x); // x rising: start earlier, so this frame makes it
|
||||
else step = x - lo; // x falling: start later, so it waits a period
|
||||
if (next_ + step < in.now) return; // (never before the frame starting now)
|
||||
if (sinceStep_ < kStepGap) return;
|
||||
next_ += step;
|
||||
steers_++;
|
||||
sinceStep_ = 0;
|
||||
}
|
||||
|
||||
static double basePeriod(const PacingInput& in) { return in.fastForward ? in.period / kFastForward : in.period; }
|
||||
|
||||
void observe(const PacingInput& in) {
|
||||
@@ -117,6 +199,12 @@ private:
|
||||
double next_ = 0, lastStart_ = 0, filtQ_ = 0, lastObs_ = 0, trim_ = 1.0;
|
||||
bool init_ = false, haveQ_ = false, overfull_ = false, refill_ = false, audio_ = false;
|
||||
uint64_t dropped_ = 0;
|
||||
double ends_[kEnds] = {}; // frame end - due, seconds
|
||||
unsigned endAt_ = 0;
|
||||
double curDue_ = -1; // the running frame's grid time (-1 = none: refill, fast-forward)
|
||||
uint64_t steers_ = 0;
|
||||
double loHeld_ = 1e9, hiHeld_ = -1e9, lastSteer_ = 0; // the held window edges (end - due), seconds
|
||||
unsigned sinceStep_ = kStepGap; // frames since the last step
|
||||
};
|
||||
|
||||
} // namespace vj
|
||||
@@ -0,0 +1,90 @@
|
||||
// Dev-only presentation trace (#967 evenness): VJ_PERF_TRACE=<prefix> with --perf-frames N writes two CSVs when the
|
||||
// perf window ends, on one clock (SDL_GetTicksNS):
|
||||
//
|
||||
// <prefix>-emu.csv one row per emulated frame: when it was due on the pacing grid, when it really started, when its
|
||||
// picture was handed over, the trim and audio queue it was paced with, and its frame serial;
|
||||
// <prefix>-ui.csv one row per UI iteration: when the iteration took a frame, which serial it showed, and the swap
|
||||
// around it (its return is the vblank proxy), plus the late latch's wait.
|
||||
//
|
||||
// Joining the two answers "where in the refresh period did each frame finish, and where did the UI take it", which the
|
||||
// per-iteration VJ_PERF_CSV cannot: it counts frames run between takes, not frames shown. Nothing is recorded unless
|
||||
// the variable is set. The emulation thread is the only writer of the emu rows (a fixed array, published with an
|
||||
// atomic count), the UI thread the only writer of the UI rows and the only reader of both.
|
||||
#pragma once
|
||||
|
||||
#include <atomic>
|
||||
#include <cstdint>
|
||||
#include <cstdio>
|
||||
#include <cstdlib>
|
||||
#include <string>
|
||||
#include <vector>
|
||||
|
||||
namespace vj {
|
||||
|
||||
struct PerfTrace {
|
||||
struct Emu {
|
||||
uint64_t dueNs, startNs, endNs, serial;
|
||||
float trim, filtQMs, queuedMs;
|
||||
unsigned char audio, refill;
|
||||
};
|
||||
struct Ui {
|
||||
uint64_t takeNs, serial, swap0Ns, swap1Ns, wakeNs, waitEndNs, budgetNs, targetNs;
|
||||
unsigned char locked;
|
||||
};
|
||||
|
||||
std::string prefix;
|
||||
bool enabled() const { return on_.load(std::memory_order_acquire); } // (the emulation thread may already run)
|
||||
|
||||
void init(unsigned frames) {
|
||||
const char* p = std::getenv("VJ_PERF_TRACE");
|
||||
if (!p || !*p || !frames) return;
|
||||
prefix = p;
|
||||
emu_.resize((size_t)(frames + 240) * 4);
|
||||
ui_.reserve(frames + 240);
|
||||
on_.store(true, std::memory_order_release);
|
||||
}
|
||||
|
||||
// ---- emulation thread (or the UI thread inline) ----
|
||||
void emu(const Emu& e) {
|
||||
const size_t i = emuN_.load(std::memory_order_relaxed);
|
||||
if (!enabled() || i >= emu_.size()) return;
|
||||
emu_[i] = e;
|
||||
emuN_.store(i + 1, std::memory_order_release);
|
||||
}
|
||||
|
||||
// ---- UI thread ----
|
||||
void ui(const Ui& u) {
|
||||
if (enabled() && ui_.size() < ui_.capacity()) ui_.push_back(u);
|
||||
}
|
||||
void write() const {
|
||||
if (!enabled()) return;
|
||||
const size_t n = emuN_.load(std::memory_order_acquire);
|
||||
if (FILE* f = std::fopen((prefix + "-emu.csv").c_str(), "w")) {
|
||||
std::fprintf(f, "due_ns,start_ns,end_ns,serial,trim,filt_q_ms,queued_ms,audio,refill\n");
|
||||
for (size_t i = 0; i < n; i++) {
|
||||
const Emu& e = emu_[i];
|
||||
std::fprintf(f, "%llu,%llu,%llu,%llu,%.6f,%.3f,%.3f,%d,%d\n", (unsigned long long)e.dueNs,
|
||||
(unsigned long long)e.startNs, (unsigned long long)e.endNs, (unsigned long long)e.serial,
|
||||
(double)e.trim, (double)e.filtQMs, (double)e.queuedMs, (int)e.audio, (int)e.refill);
|
||||
}
|
||||
std::fclose(f);
|
||||
}
|
||||
if (FILE* f = std::fopen((prefix + "-ui.csv").c_str(), "w")) {
|
||||
std::fprintf(f, "take_ns,serial,swap0_ns,swap1_ns,wake_ns,wait_end_ns,budget_ns,target_ns,locked\n");
|
||||
for (const Ui& u : ui_)
|
||||
std::fprintf(f, "%llu,%llu,%llu,%llu,%llu,%llu,%llu,%llu,%d\n", (unsigned long long)u.takeNs,
|
||||
(unsigned long long)u.serial, (unsigned long long)u.swap0Ns, (unsigned long long)u.swap1Ns,
|
||||
(unsigned long long)u.wakeNs, (unsigned long long)u.waitEndNs,
|
||||
(unsigned long long)u.budgetNs, (unsigned long long)u.targetNs, (int)u.locked);
|
||||
std::fclose(f);
|
||||
}
|
||||
}
|
||||
|
||||
private:
|
||||
std::atomic<bool> on_{false};
|
||||
std::vector<Emu> emu_;
|
||||
std::atomic<size_t> emuN_{0};
|
||||
std::vector<Ui> ui_;
|
||||
};
|
||||
|
||||
} // namespace vj
|
||||
@@ -95,8 +95,11 @@ void testNoRoom() {
|
||||
l.setPeriodNs(kP60);
|
||||
uint64_t end = 0;
|
||||
runGrid(l, kP60, 60, end);
|
||||
l.noteBuild(16 * kMs); // one build nearly a whole period long
|
||||
CHECK(l.wakeAt(end + 200000) == end + 200000, "a 16 ms build leaves no room to wait");
|
||||
l.noteBuild(16 * kMs); // one build nearly a whole period long: a one-off (a window opening)
|
||||
CHECK(l.wakeAt(end + 200000) > end + 200000 && l.budgetNs() == 3 * kMs,
|
||||
"one 16 ms build does not set the budget (%llu ns): the wait goes on", (unsigned long long)l.budgetNs());
|
||||
l.noteBuild(16 * kMs); // a second one within the window: the UI really is that slow now
|
||||
CHECK(l.wakeAt(end + 200000) == end + 200000, "two 16 ms builds leave no room to wait");
|
||||
}
|
||||
|
||||
void testMissGrowsPad() {
|
||||
@@ -203,6 +206,32 @@ void testLateStartIsNotAMiss() {
|
||||
}
|
||||
}
|
||||
|
||||
void testLateStartsAreCapped() {
|
||||
// Every wait overruns its wake time by 3 ms (event handling that always takes longer than the room it is given) and
|
||||
// every swap then misses. The first kMaxLateExempt are excused; after that they are outcomes, and the miss rate
|
||||
// must release the latch.
|
||||
LateLatch l;
|
||||
l.setPeriodNs(kP60);
|
||||
uint64_t cur = 0;
|
||||
runGrid(l, kP60, 60, cur);
|
||||
unsigned waits = 0;
|
||||
for (; waits < 200; waits++) {
|
||||
const uint64_t now = cur + 200000;
|
||||
const uint64_t w = l.wakeAt(now);
|
||||
if (w == now) break; // released
|
||||
const uint64_t nextV = cur - 50000 + kP60;
|
||||
l.noteWaitEnd(w + 3 * kMs);
|
||||
l.noteBuild(2 * kMs);
|
||||
l.onSwap(w + 5 * kMs, nextV + kP60 + 50000);
|
||||
cur = nextV + kP60 + 50000;
|
||||
}
|
||||
CHECK(!l.locked() && l.released() == 1, "always-late waits release the latch (after %u waits)", waits);
|
||||
CHECK(waits > LateLatch::kMaxLateExempt && waits <= LateLatch::kMaxLateExempt + 60,
|
||||
"after the excused ones (%u waits)", waits);
|
||||
CHECK(l.misses() == waits - LateLatch::kMaxLateExempt, "the excused waits are not misses (%u of %u)", l.misses(),
|
||||
waits);
|
||||
}
|
||||
|
||||
void testOffNominal() {
|
||||
// A display that really runs at 59.94 Hz while the mode says 60: the tracker follows the drift.
|
||||
LateLatch l;
|
||||
@@ -341,6 +370,7 @@ int main() {
|
||||
testPersistentMissReleases();
|
||||
testJitterHysteresis();
|
||||
testLateStartIsNotAMiss();
|
||||
testLateStartsAreCapped();
|
||||
testOffNominal();
|
||||
testModel();
|
||||
std::printf(g_fail ? "late_latch_test: %d FAILED\n" : "late_latch_test: OK\n", g_fail);
|
||||
|
||||
@@ -9,6 +9,8 @@
|
||||
#include <cstdint>
|
||||
#include <cstdio>
|
||||
#include <functional>
|
||||
#include <memory>
|
||||
#include <string>
|
||||
#include <vector>
|
||||
|
||||
using vj::PacingClock;
|
||||
@@ -41,28 +43,39 @@ struct Device {
|
||||
bool draining = true;
|
||||
double countFrom = 0; // underruns before this time are not counted (start-up)
|
||||
uint64_t underruns = 0;
|
||||
double pullJitter = 0; // each pull lands up to this many seconds off its slot (a late or early audio thread)
|
||||
uint32_t seed = 1;
|
||||
double slot = 0; // the pull's nominal time (pulls stay on the crystal's grid; only their timing jitters)
|
||||
void advanceTo(double t) {
|
||||
while (nextPull <= t) {
|
||||
if (draining) {
|
||||
if (queued < kChunk && nextPull >= countFrom) underruns++;
|
||||
queued = std::max(0.0, queued - kChunk);
|
||||
}
|
||||
nextPull += kChunk / rate;
|
||||
slot += kChunk / rate;
|
||||
nextPull = slot + (pullJitter > 0 ? pullJitter * (2.0 * rnd(seed) - 1.0) : 0.0);
|
||||
}
|
||||
}
|
||||
static double rnd(uint32_t& s) { // a fixed LCG: the same jitter on every run and platform
|
||||
s = s * 1664525u + 1013904223u;
|
||||
return (double)(s >> 8) / 16777216.0;
|
||||
}
|
||||
double ms() const { return 1000.0 * queued / kStreamHz; }
|
||||
void prime() { queued = kTargetMs / 1000.0 * kStreamHz; }
|
||||
};
|
||||
|
||||
struct Run {
|
||||
std::vector<double> starts, ends; // each emulated frame's start and end (= when it can be shown)
|
||||
uint64_t dropped = 0;
|
||||
std::vector<double> trims; // the trim each frame's period was stretched by
|
||||
uint64_t dropped = 0, steers = 0;
|
||||
bool lockedAtEnd = false;
|
||||
};
|
||||
|
||||
// The emulation thread's loop on a fake clock: ask when the next frame is due, "sleep" until then, run a frame of
|
||||
// cost(i) seconds, and queue its audio at its end (fast-forward drops it, as App does).
|
||||
Run simulate(double secs, const std::function<double(size_t)>& cost, bool audio, Device& dev, bool ff = false) {
|
||||
// takeHz > 0: the UI takes frames `lead` before each vblank of a takeHz display and tells the clock (steering).
|
||||
Run simulate(double secs, const std::function<double(size_t)>& cost, bool audio, Device& dev, bool ff = false,
|
||||
double takeHz = 0, double lead = 0, const std::function<double(size_t)>& wakeLate = nullptr) {
|
||||
PacingClock clock;
|
||||
Run r;
|
||||
double t = 0;
|
||||
@@ -76,19 +89,26 @@ Run simulate(double secs, const std::function<double(size_t)>& cost, bool audio,
|
||||
in.audioQueuedMs = audio ? dev.ms() : -1.0;
|
||||
in.targetMs = kTargetMs;
|
||||
in.fastForward = ff;
|
||||
if (takeHz > 0) {
|
||||
in.takePeriod = 1.0 / takeHz;
|
||||
in.takeAt = std::floor((t + lead) * takeHz) / takeHz - lead; // the UI's latest take
|
||||
}
|
||||
const double due = clock.nextDue(in);
|
||||
if (due > t + 1e-12) {
|
||||
t = due;
|
||||
t = due + (wakeLate ? wakeLate(i) : 0.0); // the thread wakes up late (timer slack, scheduling)
|
||||
continue;
|
||||
}
|
||||
clock.frameStarted(in);
|
||||
r.trims.push_back(clock.trim());
|
||||
r.starts.push_back(t);
|
||||
t += cost(i++);
|
||||
dev.advanceTo(t);
|
||||
if (!ff) dev.queued += kBatch;
|
||||
r.ends.push_back(t);
|
||||
clock.frameEnded(t);
|
||||
}
|
||||
r.dropped = clock.droppedFrames();
|
||||
r.steers = clock.steers();
|
||||
r.lockedAtEnd = clock.audioLocked();
|
||||
return r;
|
||||
}
|
||||
@@ -97,13 +117,14 @@ struct Shown {
|
||||
int repeats = 0, skips = 0, vblanks = 0;
|
||||
};
|
||||
|
||||
// A display refreshing at `hz` shows, at each vblank, the newest frame finished by then.
|
||||
Shown present(const Run& r, double hz, double from, double to) {
|
||||
// A display refreshing at `hz` shows, at each vblank, the newest frame finished by then -- or, with `lead`, by that
|
||||
// long before it (the late latch's take point: the UI takes the frame `lead` before the vblank it is shown at).
|
||||
Shown present(const Run& r, double hz, double from, double to, double lead = 0) {
|
||||
Shown s;
|
||||
size_t k = 0;
|
||||
long last = -1;
|
||||
for (long n = (long)std::ceil(from * hz); (double)n / hz < to; n++) {
|
||||
const double v = (double)n / hz;
|
||||
const double v = (double)n / hz - lead;
|
||||
while (k < r.ends.size() && r.ends[k] <= v) k++;
|
||||
const long newest = (long)k - 1;
|
||||
if (last >= 0) {
|
||||
@@ -242,9 +263,227 @@ void testFastForward() {
|
||||
CHECK(!r.lockedAtEnd, "fast-forward ignores the audio clock");
|
||||
}
|
||||
|
||||
// ---- the presentation-evenness model (#967) ----------------------------------------------------------------------
|
||||
// The threaded loop showed 60-160 repeats and as many skips per minute where the 60.05-vs-60 Hz beat alone predicts
|
||||
// 3-4 skips. Two candidate causes, separated here:
|
||||
// * the trim: the +/-0.5% audio trim moving the grid's phase much faster than the 0.054 Hz beat, so frame ends keep
|
||||
// crossing the take point (device pulls jittering is what would drive it);
|
||||
// * the ends' spread: each frame ends at start + cost, so a cost (or wake-up) spread of S ms makes every crossing of
|
||||
// the take point by the slowly drifting grid ambiguous for S / 15 us frames (15 us = the beat's drift per frame),
|
||||
// each of which can come out as a repeat + skip pair.
|
||||
|
||||
// The emulation grid's phase that the trim alone moved (seconds), max - min between two times.
|
||||
double trimWander(const Run& r, double from, double to) {
|
||||
double ph = 0, lo = 0, hi = 0;
|
||||
for (size_t i = 0; i < r.starts.size(); i++) {
|
||||
if (r.starts[i] < from || r.starts[i] >= to) continue;
|
||||
ph += (r.trims[i] - 1.0) * kPeriod;
|
||||
lo = std::min(lo, ph);
|
||||
hi = std::max(hi, ph);
|
||||
}
|
||||
return hi - lo;
|
||||
}
|
||||
|
||||
std::function<double(size_t)> jitteredCost(double base, double spread, uint32_t seed) {
|
||||
auto st = std::make_shared<uint32_t>(seed);
|
||||
return [=](size_t) { return base + spread * (Device::rnd(*st) - 0.5); };
|
||||
}
|
||||
|
||||
void modelTable() {
|
||||
std::printf("model: 70 s, measured 10-70 s, 60 Hz panel; events = repeats + skips\n");
|
||||
for (double pull : {0.0, 0.002, 0.005})
|
||||
for (double spread : {0.0, 0.0005, 0.001, 0.002, 0.004})
|
||||
for (double lead : {0.0, 0.003})
|
||||
for (bool steer : {false, true}) {
|
||||
Device dev;
|
||||
dev.prime();
|
||||
dev.pullJitter = pull;
|
||||
Run r = simulate(70.0, jitteredCost(0.006, spread, 7), true, dev, false, steer ? 60.0 : 0.0, lead);
|
||||
const Shown sh = present(r, 60.0, 10.0, 70.0, lead);
|
||||
std::printf(" pull jitter %.0f ms cost spread %.1f ms take %.0f ms early steer %d: repeats %3d"
|
||||
" skips %3d steps %2llu trim phase wander %.2f ms underruns %llu\n",
|
||||
1000 * pull, 1000 * spread, 1000 * lead, (int)steer, sh.repeats, sh.skips,
|
||||
(unsigned long long)r.steers, 1000 * trimWander(r, 10, 70),
|
||||
(unsigned long long)dev.underruns);
|
||||
}
|
||||
}
|
||||
|
||||
// How many vblanks each frame stayed on screen: hold[n] = frames shown for n refreshes (0 = never shown).
|
||||
std::vector<int> holds(const Run& r, double hz, double from, double to, double lead) {
|
||||
std::vector<int> hold(8, 0);
|
||||
size_t k = 0;
|
||||
long last = -1;
|
||||
int run = 0;
|
||||
for (long n = (long)std::ceil(from * hz); (double)n / hz < to; n++) {
|
||||
const double v = (double)n / hz - lead;
|
||||
while (k < r.ends.size() && r.ends[k] <= v) k++;
|
||||
const long newest = (long)k - 1;
|
||||
if (newest == last) {
|
||||
run++;
|
||||
continue;
|
||||
}
|
||||
if (last >= 0) {
|
||||
hold[std::min(run, 7)]++;
|
||||
hold[0] += (int)(newest - last - 1);
|
||||
}
|
||||
last = newest;
|
||||
run = 1;
|
||||
}
|
||||
return hold;
|
||||
}
|
||||
|
||||
void testSteeringRestoresTheBeat() {
|
||||
// A 6 ms frame whose cost varies by 4 ms, taken 3 ms before each vblank of a 60 Hz panel.
|
||||
Device dev;
|
||||
dev.prime();
|
||||
Run plain = simulate(70.0, jitteredCost(0.006, 0.004, 7), true, dev, false, 0.0, 0.003);
|
||||
const Shown a = present(plain, 60.0, 10.0, 70.0, 0.003);
|
||||
CHECK(a.repeats + a.skips > 100, "the mechanism: unsteered, a 4 ms spread repeats and skips at every crossing "
|
||||
"(%d + %d in 60 s)", a.repeats, a.skips);
|
||||
Device dev2;
|
||||
dev2.prime();
|
||||
Run r = simulate(70.0, jitteredCost(0.006, 0.004, 7), true, dev2, false, 60.0, 0.003);
|
||||
const Shown s = present(r, 60.0, 10.0, 70.0, 0.003);
|
||||
CHECK(s.repeats == 0, "steered: no repeat (%d)", s.repeats);
|
||||
CHECK(s.skips >= 2 && s.skips <= 5, "steered: the beat's one skip per ~18 s (%d in 60 s)", s.skips);
|
||||
CHECK(r.steers >= 3 && r.steers <= 8, "one phase step per crossing, not one per frame (%llu)",
|
||||
(unsigned long long)r.steers);
|
||||
CHECK(dev2.underruns == 0 && r.dropped == 0, "no underrun, nothing dropped");
|
||||
}
|
||||
|
||||
void testSteeringKeepsTheAudioClock() {
|
||||
Device dev;
|
||||
dev.rate = kStreamHz * (1.0 + 200e-6); // a sound card 200 ppm fast
|
||||
dev.prime();
|
||||
Run r = simulate(200.0, jitteredCost(0.006, 0.004, 11), true, dev, false, 60.0, 0.003);
|
||||
const double want = dev.rate / kBatch;
|
||||
const double got = rateBetween(r, 50.0, 200.0);
|
||||
CHECK(std::fabs(got - want) / want < 3e-5, "steered, the long-run rate is still the sound card's: %.5f Hz, want %.5f",
|
||||
got, want);
|
||||
CHECK(dev.underruns == 0, "no underrun (%llu)", (unsigned long long)dev.underruns);
|
||||
CHECK(std::fabs(dev.ms() - kTargetMs) < 25.0, "the queue stays near its target (%.1f ms)", dev.ms());
|
||||
}
|
||||
|
||||
void testSteeringAt120Hz() {
|
||||
// Two refreshes per frame: every frame should stay on screen for exactly two, except at the beat's crossings.
|
||||
for (bool steer : {false, true}) {
|
||||
Device dev;
|
||||
dev.prime();
|
||||
Run r = simulate(70.0, jitteredCost(0.006, 0.004, 5), true, dev, false, steer ? 120.0 : 0.0, 0.002);
|
||||
const std::vector<int> h = holds(r, 120.0, 10.0, 70.0, 0.002);
|
||||
const int odd = h[0] + h[1] + h[3] + h[4];
|
||||
if (steer) CHECK(odd <= 8, "120 Hz, steered: frames held 1 or 3 refreshes only at crossings (%d)", odd);
|
||||
else CHECK(odd > 40, "120 Hz, unsteered: the same mechanism (%d frames held 1 or 3 refreshes)", odd);
|
||||
}
|
||||
}
|
||||
|
||||
void testSteeringFollowsACostThatSwitches() {
|
||||
// Measured on the Mac Studio (yarc, VJ_PERF_TRACE): the thread wakes 0.5-3 ms late and the frame cost switches with
|
||||
// the content between ~7.5 ms and ~2.9 ms for seconds at a time. When it drops, the ends jump 4.5 ms earlier,
|
||||
// possibly onto the take point, while the window still remembers the 7.5 ms frames.
|
||||
auto cost = [](size_t i) { return ((i / 300) % 2 ? 0.0029 : 0.0075) + 0.0004 * (double)((i * 7) % 5) / 4.0; };
|
||||
auto late = [](size_t i) { return 0.0005 + 0.0025 * (double)((i * 13) % 11) / 10.0; };
|
||||
for (double lead : {0.0025, 0.003, 0.004, 0.006, 0.009, 0.012}) {
|
||||
Device dev;
|
||||
dev.prime();
|
||||
Run r = simulate(70.0, cost, true, dev, false, 60.0, lead, late);
|
||||
const Shown s = present(r, 60.0, 10.0, 70.0, lead);
|
||||
CHECK(s.repeats + s.skips <= 12, "a cost that switches 7.5 <-> 2.9 ms every 5 s, take %.1f ms early: %d repeats "
|
||||
"+ %d skips in 60 s (%llu steps)", 1000 * lead, s.repeats, s.skips, (unsigned long long)r.steers);
|
||||
}
|
||||
}
|
||||
|
||||
void testSteeringWithAWideWindow() {
|
||||
// Cybermorph on the Studio: 5-11 ms frames, 0.5-3 ms late, so a ~9 ms window and ~9 ms steps. Each early step
|
||||
// queues that much audio; the trim then slows the grid, and past ~12 ms of queue error (0.09%, the beat) the grid
|
||||
// drifts the other way. Steering must follow the drift it sees, not the untrimmed one.
|
||||
auto cost = [](size_t i) { return 0.005 + 0.006 * (double)((i * 37) % 101) / 100.0; };
|
||||
auto late = [](size_t i) { return 0.0005 + 0.0025 * (double)((i * 13) % 11) / 10.0; };
|
||||
for (double lead : {0.002, 0.004, 0.006}) {
|
||||
Device dev;
|
||||
dev.prime();
|
||||
Run r = simulate(130.0, cost, true, dev, false, 60.0, lead, late);
|
||||
const Shown s = present(r, 60.0, 10.0, 130.0, lead);
|
||||
CHECK(s.repeats + s.skips <= 20, "a 9 ms window, take %.0f ms early: %d repeats + %d skips in 120 s (%llu steps)",
|
||||
1000 * lead, s.repeats, s.skips, (unsigned long long)r.steers);
|
||||
CHECK(dev.underruns == 0, "no underrun (%llu)", (unsigned long long)dev.underruns);
|
||||
}
|
||||
}
|
||||
|
||||
void testSteeringFollowsTheTrimmedDrift() {
|
||||
// The trim held where the grid runs slower than the panel: here a sound card 0.15% slow (59.96 Hz of frames on a
|
||||
// 60 Hz panel), on hardware the queue error the steps themselves leave. The grid now drifts the other way; the
|
||||
// crossings are repeats, about one per 28 s, and steering must step later, not earlier.
|
||||
for (double lead : {0.003, 0.009}) {
|
||||
Device dev;
|
||||
dev.rate = kStreamHz * (1.0 - 0.0015);
|
||||
dev.prime();
|
||||
Run r = simulate(130.0, jitteredCost(0.006, 0.004, 9), true, dev, false, 60.0, lead);
|
||||
const Shown s = present(r, 60.0, 10.0, 130.0, lead);
|
||||
CHECK(s.skips == 0 && s.repeats >= 2 && s.repeats <= 8, "a grid slower than the panel, take %.0f ms early: "
|
||||
"%d repeats + %d skips in 120 s (%llu steps)", 1000 * lead, s.repeats, s.skips,
|
||||
(unsigned long long)r.steers);
|
||||
}
|
||||
}
|
||||
|
||||
void testNoSteeringOffAWholeRatio() {
|
||||
// A PAL game (50.08 Hz) on a 60 Hz panel, or 60.05 Hz on 75 / 144 Hz: each frame lands ~3 ms further along the take
|
||||
// grid, so some frame's window always holds a take point -- that is ordinary 5:6 (4:5, 5:12) judder, not a slow
|
||||
// crossing, and stepping for it would cost production every 30 frames forever. No steps, no underruns, the rate kept.
|
||||
struct Case { double coreHz, panelHz; };
|
||||
for (const Case c : {Case{50.08013, 60.0}, Case{60.05445, 75.0}, Case{60.05445, 144.0}}) {
|
||||
Device dev;
|
||||
const double period = 1.0 / c.coreHz;
|
||||
dev.rate = kBatch / period; // a sound card consuming exactly the core's rate (dev.rate is in stream frames/s)
|
||||
dev.prime();
|
||||
PacingClock clock;
|
||||
Run r;
|
||||
double t = 0;
|
||||
clock.reset(t);
|
||||
uint32_t seed = 3;
|
||||
while (t < 60.0) {
|
||||
dev.advanceTo(t);
|
||||
PacingInput in;
|
||||
in.now = t;
|
||||
in.period = period;
|
||||
in.audioQueuedMs = dev.ms();
|
||||
in.targetMs = kTargetMs;
|
||||
in.takePeriod = 1.0 / c.panelHz;
|
||||
in.takeAt = std::floor((t + 0.003) * c.panelHz) / c.panelHz - 0.003;
|
||||
const double due = clock.nextDue(in);
|
||||
if (due > t + 1e-12) {
|
||||
t = due;
|
||||
continue;
|
||||
}
|
||||
clock.frameStarted(in);
|
||||
r.starts.push_back(t);
|
||||
t += 0.004 + 0.004 * Device::rnd(seed);
|
||||
dev.advanceTo(t);
|
||||
dev.queued += kBatch;
|
||||
clock.frameEnded(t);
|
||||
}
|
||||
const double got = rateBetween(r, 20.0, 60.0);
|
||||
CHECK(clock.steers() == 0, "%.2f Hz on %.0f Hz: no steps (%llu)", c.coreHz, c.panelHz,
|
||||
(unsigned long long)clock.steers());
|
||||
CHECK(dev.underruns == 0, "%.2f Hz on %.0f Hz: no underrun (%llu)", c.coreHz, c.panelHz,
|
||||
(unsigned long long)dev.underruns);
|
||||
CHECK(std::fabs(got - c.coreHz) / c.coreHz < 1e-4, "%.2f Hz on %.0f Hz: the rate is kept (%.4f Hz)", c.coreHz,
|
||||
c.panelHz, got);
|
||||
}
|
||||
}
|
||||
|
||||
void testWindowTooWideDoesNotSteer() {
|
||||
Device dev;
|
||||
dev.prime();
|
||||
Run r = simulate(20.0, jitteredCost(0.008, 0.016, 3), true, dev, false, 60.0, 0.003); // 0-16 ms frames
|
||||
CHECK(r.steers == 0, "a spread of a whole period leaves no gap to steer into (%llu steps)",
|
||||
(unsigned long long)r.steers);
|
||||
}
|
||||
|
||||
} // namespace
|
||||
|
||||
int main() {
|
||||
int main(int argc, char** argv) {
|
||||
if (argc > 1 && std::string(argv[1]) == "--model") modelTable(); // the numbers behind the #967 evenness notes
|
||||
testTrueRateOn60Hz();
|
||||
testFollowsTheCrystal();
|
||||
testNoAudioClock();
|
||||
@@ -253,6 +492,14 @@ int main() {
|
||||
testSpikeCatchesUp();
|
||||
testStallDropsOwedTime();
|
||||
testFastForward();
|
||||
testSteeringRestoresTheBeat();
|
||||
testSteeringKeepsTheAudioClock();
|
||||
testSteeringAt120Hz();
|
||||
testSteeringFollowsACostThatSwitches();
|
||||
testSteeringWithAWideWindow();
|
||||
testSteeringFollowsTheTrimmedDrift();
|
||||
testNoSteeringOffAWholeRatio();
|
||||
testWindowTooWideDoesNotSteer();
|
||||
std::printf(g_fail ? "pacing_clock_test: %d FAILED\n" : "pacing_clock_test: OK\n", g_fail);
|
||||
return g_fail ? 1 : 0;
|
||||
}
|
||||
Executable
+67
@@ -0,0 +1,67 @@
|
||||
#!/usr/bin/env python3
|
||||
# VJ_PERF_TRACE summary (#967 evenness): app/src/perf_trace.h writes <prefix>-emu.csv and <prefix>-ui.csv.
|
||||
#
|
||||
# python3 app/tests/perf_trace_summary.py <prefix>...
|
||||
#
|
||||
# Per run: repeats and skips of the frames really shown (serial deltas between takes, after the 120 warm-up
|
||||
# iterations), bursts (events more than 1 s apart), the emulation thread's wake-up lateness and frame cost, the
|
||||
# spread of frame end - due (what makes a crossing of the take point ambiguous), where the take sits after the
|
||||
# vblank (swap return), how far the trim alone moved the grid's phase, and the exact event -> present: virtual events
|
||||
# every 5.31 ms, each followed to the first frame that polled it and the swap that first showed that frame (or a later
|
||||
# one). An event is visible to the core at once if it arrives in the late latch's wait (swap return .. next take),
|
||||
# else at the swap return (threaded); at the next frame start (single-thread: events are polled right before it runs).
|
||||
import bisect, csv, sys
|
||||
def pct(v, p):
|
||||
v = sorted(v); return v[min(len(v)-1, int(p*len(v)))] if v else float('nan')
|
||||
def exact_latency(emu, ui):
|
||||
thr = any(int(u['wait_end_ns']) for u in ui)
|
||||
st = [int(e['start_ns']) for e in emu]; se = [int(e['serial']) for e in emu]
|
||||
tk = [int(u['take_ns']) for u in ui]; sw = [int(u['swap1_ns']) for u in ui]
|
||||
mx = []; m = 0
|
||||
for u in ui: m = max(m, int(u['serial'])); mx.append(m)
|
||||
lat = []; e = tk[2]
|
||||
while e < tk[-60]:
|
||||
v = e
|
||||
if thr:
|
||||
k = bisect.bisect_right(tk, e) - 1
|
||||
if k >= 0 and e < sw[k]: v = sw[k]
|
||||
j = bisect.bisect_left(st, v)
|
||||
if j >= len(st): break
|
||||
r = bisect.bisect_left(mx, se[j])
|
||||
if r >= len(sw): break
|
||||
lat.append((sw[r] - e) / 1e6)
|
||||
e += 5310000
|
||||
return sum(lat) / len(lat) if lat else float('nan'), len(lat)
|
||||
for pre in sys.argv[1:]:
|
||||
emu = list(csv.DictReader(open(pre + '-emu.csv')))
|
||||
ui = list(csv.DictReader(open(pre + '-ui.csv')))
|
||||
ui = ui[120:] # perf warm-up
|
||||
t0 = int(ui[0]['take_ns']); t1 = int(ui[-1]['take_ns'])
|
||||
lat_avg, lat_n = exact_latency(emu, ui)
|
||||
emu = [e for e in emu if t0 - 50e6 <= int(e['start_ns']) <= t1]
|
||||
# shown sequence: serial deltas between consecutive takes
|
||||
ser = [int(u['serial']) for u in ui]
|
||||
d = [b - a for a, b in zip(ser, ser[1:]) if a and b]
|
||||
rep = sum(1 for x in d if x == 0); skp = sum(x - 1 for x in d if x > 1)
|
||||
late = [(int(e['start_ns']) - int(e['due_ns'])) / 1e6 for e in emu]
|
||||
cost = [(int(e['end_ns']) - int(e['start_ns'])) / 1e6 for e in emu]
|
||||
fin = [(int(e['end_ns']) - int(e['due_ns'])) / 1e6 for e in emu]
|
||||
trim = [float(e['trim']) for e in emu]
|
||||
# take relative to the swap return before it (vblank proxy)
|
||||
tk = [(int(b['take_ns']) - int(a['swap1_ns'])) / 1e6 for a, b in zip(ui, ui[1:])]
|
||||
# trim phase: integral of (trim - 1) * period
|
||||
ph = 0; lo = hi = 0
|
||||
for x in trim:
|
||||
ph += (x - 1) * 16.6516; lo = min(lo, ph); hi = max(hi, ph)
|
||||
# bursts: events separated by > 1 s
|
||||
ev_t = [int(ui[i+1]['take_ns']) for i, x in enumerate(d) if x != 1]
|
||||
bursts = 0; last = None
|
||||
for t in ev_t:
|
||||
if last is None or t - last > 1e9: bursts += 1
|
||||
last = t
|
||||
print(f"{pre.split('/')[-1]:34s} shown-repeats {rep:3d} skips {skp:3d} bursts {bursts:2d} | "
|
||||
f"late p50 {pct(late,.5):.2f} p99 {pct(late,.99):.2f} max {max(late):.2f} | "
|
||||
f"cost p1 {pct(cost,.01):.2f} p50 {pct(cost,.5):.2f} p99 {pct(cost,.99):.2f} | "
|
||||
f"end-due p1-p99 spread {pct(fin,.99)-pct(fin,.01):.2f} ms | take-after-vblank p1 {pct(tk,.01):.2f} p50 {pct(tk,.5):.2f} p99 {pct(tk,.99):.2f} | "
|
||||
f"trim [{min(trim):.4f},{max(trim):.4f}] phase wander {hi-lo:.2f} ms | "
|
||||
f"event->present exact avg {lat_avg:.2f} ms (n={lat_n})")
|
||||
@@ -78,6 +78,18 @@ The UI never waits on emulation.
|
||||
- The sound card's clock is the master, so the game runs at true speed and audio never drifts. On a 60 Hz panel one
|
||||
frame repeats about every 20 s.
|
||||
- No audio device, muted output, or a paused stream: fall back to the wall clock at the core's period.
|
||||
- *Amended 2026-10-17 (#967 evenness): phase steering.* A frame ends at its due time plus its wake-up lateness and
|
||||
cost, so the end times spread over a window (a few ms for Cybermorph). While the slowly drifting grid carries the UI's
|
||||
take point through that window, each frame's own cost decides whether it makes the take. The result is a run of random
|
||||
repeat + skip pairs at every crossing (60-160 a minute) instead of the one skip the beat owes. While the UI has the
|
||||
vblank grid locked, it publishes its take time and the display period. When the next frame's end window would contain
|
||||
a take point, `PacingClock` steps the grid's phase once across it, in the direction the grid is drifting (its trimmed
|
||||
period, so the queue error a step leaves can never turn the steps against the drift). Only the phase moves: at most
|
||||
the window's width, once per crossing, with at least 30 frames between steps. The rate is still the trimmed audio
|
||||
rate, and the display never holds the drift back, so this is not mode B. Steering runs only where the grid creeps
|
||||
along the take grid (under 0.2 ms a frame: 60.05 Hz on 60, 120 or 59.94 Hz panels). At ratios like 50.08 Hz on 60 Hz,
|
||||
every few frames straddle a take point by construction (5:6 judder), and only mode B can change that.
|
||||
`--pace-steer off` turns steering off for A/B runs.
|
||||
|
||||
### Mode B: display lock
|
||||
- The main thread sends a tick after each swap; the emulation thread runs one frame per tick (one per k ticks when the
|
||||
|
||||
Reference in new issue
Block a user