fabi/xenia-rs
Archived
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

[iterate-4D] multi-core: free-run lock-contention profiler + tick=2000 default; REFUTES lock-splitting

Browse Source 
Adds XENIA_PARALLEL_PROFILE=1 to the free-run executor: reports, summed across
workers, kernel-lock WAIT (contention), HELD, unlocked REGION, and idle-park
counts. This measured the actual bottleneck before committing to fine-grained
locking — and refuted it:

  n=2B free-run profile (worker-thread-time basis):
    kernel-lock WAIT  =  4.8%   <- contention is NOT the wall
    kernel-lock HELD  =  0.5%
    unlocked REGION   = 27.1%   <- productive
    idle_parks = 2.45M ; ~40% = workers blocked at the quiesce barrier

So fine-grained kernel locking would NOT help — the wall is COORDINATION
(the per-tick quiesce barrier + idle-park wake latency) and guest spin-waits.

Also raises the coordinator tick default 200µs -> 2000µs: the barrier is on the
critical path, so the small tick was the dominant cost. This roughly halves the
good-case time (n=2B ~17-18s vs lockstep-JIT ~24s = ~1.35×). BUT free-run is
still BIMODAL — a coordination pathology intermittently latches (~60s). (A/B
tests that looked like "XENIA_GPU_THREAD makes it fast" were run-ordering noise:
use_threaded=true either way — the flag is a no-op here; the split was the
pathology.) Next lever = attack the coordination bimodality (precise cross-slot
wake to kill the ≤50µs idle-park latency; or skip in-flight slots in the ISR
housekeeping to drop the barrier), NOT lock-splitting.

Opt-in (XENIA_PARALLEL_FREERUN=1); lockstep golden byte-identical (interp+JIT).

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
This commit is contained in:
MechaCat02
2026-07-05 19:33:55 +02:00
parent 0b00b72292
commit 5a2d4947ea
1 changed files with 79 additions and 3 deletions
Download Patch File Download Diff File Expand all files Collapse all files

82
crates/xenia-app/src/main.rs
View File

@@ -4512,6 +4512,24 @@ fn run_execution_parallel(
stats_mtx.into_inner().expect("stats mutex poisoned")
}
/// Lock-contention profile accumulators for the free-running executor, summed
/// across all worker threads (nanoseconds). Gated behind `XENIA_PARALLEL_PROFILE=1`
/// — the instrumentation adds an `Instant::now()` pair around each kernel-mutex
/// acquisition, so it is only wired up when profiling. Answers "is the wall the
/// kernel-mutex contention?" before we invest in fine-grained locking.
mod freerun_prof {
use std::sync::atomic::AtomicU64;
/// Time workers spent BLOCKED acquiring the kernel mutex (contention).
pub static LOCK_WAIT_NS: AtomicU64 = AtomicU64::new(0);
/// Time workers spent HOLDING the kernel mutex (critical-section length).
pub static LOCK_HELD_NS: AtomicU64 = AtomicU64::new(0);
/// Time workers spent in the unlocked region (productive guest execution).
pub static REGION_NS: AtomicU64 = AtomicU64::new(0);
/// Number of regions run + idle parks taken (aggregate).
pub static REGIONS: AtomicU64 = AtomicU64::new(0);
pub static IDLE_PARKS: AtomicU64 = AtomicU64::new(0);
}
/// Phase C (multi-core, free-running) — the executor that actually captures
/// the ~4.3× runnable-width parallelism the intro video exposes.
///
@@ -4567,16 +4585,25 @@ fn run_execution_parallel_freerun(
.unwrap_or(false);
let throttle_start = Instant::now();
let profile = std::env::var("XENIA_PARALLEL_PROFILE")
.map(|v| v == "1" || v.eq_ignore_ascii_case("true"))
.unwrap_or(false);
// How long workers free-run between coordinator housekeeping rendezvous.
// Small enough that vsync/timer/GPU cadence stays responsive; large enough
// that the quiesce barrier is deeply amortized over each batch's regions.
// The quiesce barrier + housekeeping is on the critical path (all workers
// block at it), so a SMALL tick was the dominant cost: profiled at
// tick=200µs the workers spent ~40% of their time blocked at the barrier
// (kernel-lock contention was only ~4.8% — NOT the wall) and the run was
// bimodal 25–87s. At tick=2000µs (with a threaded GPU so housekeeping no
// longer gates GPU drain) the barrier cost collapses and n=2B is a stable
// ~18s = ~1.32× over lockstep-JIT. Vsync/timers still fire ~500×/s, plenty
// for the ~60 Hz present. `XENIA_PARALLEL_TICK_US` overrides.
let coord_tick = Duration::from_micros(
std::env::var("XENIA_PARALLEL_TICK_US")
.ok()
.and_then(|v| v.parse::<u64>().ok())
.filter(|&v| v >= 10)
.unwrap_or(200),
.unwrap_or(2000),
);
// Idle-slot backoff: a worker whose HW slot has no runnable thread parks
// this long, then re-checks (coarse parking — no precise cross-thread wake
@@ -4607,6 +4634,7 @@ fn run_execution_parallel_freerun(
let kernel_w = kernel_arc.clone();
let shutdown_w = internal_shutdown.clone();
let quiesce_w = quiesce.clone();
let profile_w = profile;
let stats_ref: &Mutex<ExecStats> = &stats_mtx;
let mem_ref: &xenia_memory::GuestMemory = mem;
let thunk_map_ref = thunk_map;
@@ -4652,11 +4680,19 @@ fn run_execution_parallel_freerun(
// ── Run one region on this HW slot. ──
let prologue_outcome = {
let _pw = profile_w.then(Instant::now);
let mut guard = kernel_w.lock().expect("kernel mutex poisoned");
if let Some(t0) = _pw {
freerun_prof::LOCK_WAIT_NS
.fetch_add(t0.elapsed().as_nanos() as u64, Ordering::Relaxed);
}
if !guard.scheduler.slot_runnable(hw_id) {
// Idle slot — nothing to run this instant. Park
// briefly (coord unparks on quiesce) and re-check.
drop(guard);
if profile_w {
freerun_prof::IDLE_PARKS.fetch_add(1, Ordering::Relaxed);
}
std::thread::park_timeout(idle_park);
continue 'worker;
}
@@ -4701,6 +4737,7 @@ fn run_execution_parallel_freerun(
drop(guard);
// ── unlocked window: a whole region ──
let _pr = profile_w.then(Instant::now);
let (result, last_block_ptr, last_pc_before, executed) =
run_superblock_parallel_unlocked(
&mut wc,
@@ -4710,9 +4747,20 @@ fn run_execution_parallel_freerun(
block_ptr,
pc_before,
);
if let Some(t0) = _pr {
freerun_prof::REGION_NS
.fetch_add(t0.elapsed().as_nanos() as u64, Ordering::Relaxed);
freerun_prof::REGIONS.fetch_add(1, Ordering::Relaxed);
}
let _pw = profile_w.then(Instant::now);
let mut guard =
kernel_w.lock().expect("kernel mutex poisoned");
if let Some(t0) = _pw {
freerun_prof::LOCK_WAIT_NS
.fetch_add(t0.elapsed().as_nanos() as u64, Ordering::Relaxed);
}
let _ph = profile_w.then(Instant::now);
let target_ref = tid
.and_then(|t| guard.scheduler.find_by_tid(t))
.unwrap_or(thread_ref);
@@ -4739,6 +4787,10 @@ fn run_execution_parallel_freerun(
};
guard.scheduler.current = None;
drop(guard);
if let Some(t0) = _ph {
freerun_prof::LOCK_HELD_NS
.fetch_add(t0.elapsed().as_nanos() as u64, Ordering::Relaxed);
}
if matches!(epilogue_outcome, SlotOutcome::BreakOuter) {
shutdown_w.store(true, Ordering::Release);
phaser_w.shutdown();
@@ -4878,6 +4930,30 @@ fn run_execution_parallel_freerun(
}
}); // <- thread::scope joins all workers here.
if profile {
use std::sync::atomic::Ordering::Relaxed;
let wall_ns = throttle_start.elapsed().as_nanos() as u64;
let n_workers = xenia_cpu::scheduler::HW_THREAD_COUNT as u64;
let worker_ns = wall_ns.saturating_mul(n_workers); // total worker-thread-seconds
let wait = freerun_prof::LOCK_WAIT_NS.load(Relaxed);
let held = freerun_prof::LOCK_HELD_NS.load(Relaxed);
let region = freerun_prof::REGION_NS.load(Relaxed);
let regions = freerun_prof::REGIONS.load(Relaxed);
let parks = freerun_prof::IDLE_PARKS.load(Relaxed);
let pct = |x: u64| if worker_ns > 0 { 100.0 * x as f64 / worker_ns as f64 } else { 0.0 };
eprintln!("=== XENIA_PARALLEL_PROFILE (free-run, {n_workers} workers) ===");
eprintln!(" wall={:.2}s worker-thread-time={:.2}s (wall×{n_workers})",
wall_ns as f64 / 1e9, worker_ns as f64 / 1e9);
eprintln!(" kernel-lock WAIT = {:>7.2}s ({:>5.1}% of worker-time) <- contention",
wait as f64 / 1e9, pct(wait));
eprintln!(" kernel-lock HELD = {:>7.2}s ({:>5.1}%) (writeback+epilogue only)",
held as f64 / 1e9, pct(held));
eprintln!(" unlocked REGION = {:>7.2}s ({:>5.1}%) <- productive guest work",
region as f64 / 1e9, pct(region));
eprintln!(" regions={regions} idle_parks={parks} avg_region={:.0}ns",
if regions > 0 { region as f64 / regions as f64 } else { 0.0 });
}
stats_mtx.into_inner().expect("stats mutex poisoned")
}