reload: one VM and no flush storm, 615 ms off every rebuild
Two costs read straight out of the player's own `WOW_UI_HANDLERS=1` session log (2026-10-18 20:33), where a `/reload` blocks the main thread for 7.84 s. **The saved-variables flush, 305 ms.** The reload's first act is to write every loaded addon's saved variables, one file each, and `write_atomic_bytes` ends each with `sync_all()` — a disk round trip per file, 60 of them, inside the one blocked frame. Measured on this project's own btrfs home: **327 ms flushed, 6 ms not**, which is the +27→332 ms the log spends between `ReloadUI — ending the UI session` and the last `wrote …/saved/*.lua`. `write_atomic_bytes_bulk` keeps the temp file and the rename (so a file is whole or absent) and gives up only a power loss in the seconds after; the reference writes these with plain buffered CRT writes and a `.bak` rotation whose result it discards, so this is still the stronger of the two. **A whole VM built and thrown away, 310 ms.** `end_ui_session` installs a fresh boot VM, which is right for the roots that stop there — the character screen runs on it — but `run_pending_reload` then calls `load_ingame_ui_on_world_entry`, which mints its own in `mint_entry_vm`. So every reload ran `UiScript::new`, `GlobalStrings.lua`, the emote table and the font registry twice and let the first one go without running a line: the log prints `GlobalStrings loaded` at +350 ms and again at +662 ms. `end_session` now takes what to leave behind, and the reload leaves the dying VM until the mint replaces it — safe because the two calls are one exclusive system with nothing in between, the old VM is still dropped before any file loads, and `fold_dying_vm_cvars` drains what it folds, so the mint's second fold of the same VM finds nothing. Only when the rebuild is certain to mint: with no UI wanted (a capture) the load returns early and the world would be left with no VM at all. `chunkbench` is the instrument the next item needs, and the one that priced this one's neighbours: it runs a file list three ways — a VM per file, one VM with the stock collector, one with it stopped — so parse, execute and the GC's share are separate numbers. Over his enabled addon set (1,471 files, 70 MiB) the parse is 703 ms against 74 ms to compile the same chunks from bytecode, which is what a bytecode cache would be worth; the collector is not the problem (829 ms against 731 ms stopped), and pfQuest's 23 database files are 417 ms and 110 MiB of heap. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01SgstFWtn1RxEJ5kVrpgYwn
This commit is contained in:
Claude Opus 5
@@ -263,6 +263,35 @@ pub(crate) fn write_atomic(path: &Path, contents: &str) -> std::io::Result<()> {
|
||||
|
||||
/// [`write_atomic`] for bytes: the saved-variables files carry Lua byte strings as they are.
|
||||
pub(crate) fn write_atomic_bytes(path: &Path, contents: &[u8]) -> std::io::Result<()> {
|
||||
write_one(path, contents, Durability::Flushed)
|
||||
}
|
||||
|
||||
/// [`write_atomic_bytes`] without the flush to the platter, for the one write that happens in
|
||||
/// bulk: the rename still publishes the whole file or none of it, and what is given up is only a
|
||||
/// power loss or kernel crash in the seconds after, not a crash of ours.
|
||||
///
|
||||
/// It is here because the flush dominated a `/reload`. Each `fsync` costs a disk round trip, and
|
||||
/// the saved-variables write is one file per addon: **60 files, 327 ms flushed against 6 ms
|
||||
/// unflushed** on this project's own btrfs home, which is 305 ms of the single blocked frame the
|
||||
/// rebuild already is (the player's 2026-10-18 log: `ReloadUI — ending the UI session` at +0 ms,
|
||||
/// the last `wrote …/saved/*.lua` at +332 ms). The reference writes these files with plain
|
||||
/// buffered CRT writes and a `.bak` rotation it ignores the result of, so this is still the
|
||||
/// stronger guarantee of the two.
|
||||
pub(crate) fn write_atomic_bytes_bulk(path: &Path, contents: &[u8]) -> std::io::Result<()> {
|
||||
write_one(path, contents, Durability::Renamed)
|
||||
}
|
||||
|
||||
/// Whether [`write_one`] waits for the bytes to reach the disk before the rename.
|
||||
#[derive(Clone, Copy, PartialEq, Eq)]
|
||||
enum Durability {
|
||||
/// `fsync` before the rename: a power loss after it cannot lose the write.
|
||||
Flushed,
|
||||
/// Rename only: atomic against a crash of ours, not against a power loss.
|
||||
Renamed,
|
||||
}
|
||||
|
||||
/// The shared body of the atomic writes: temp file beside the target, then a rename over it.
|
||||
fn write_one(path: &Path, contents: &[u8], durability: Durability) -> std::io::Result<()> {
|
||||
if let Some(dir) = path.parent() {
|
||||
std::fs::create_dir_all(dir)?;
|
||||
}
|
||||
@@ -270,7 +299,9 @@ pub(crate) fn write_atomic_bytes(path: &Path, contents: &[u8]) -> std::io::Resul
|
||||
{
|
||||
let mut f = std::fs::File::create(&tmp)?;
|
||||
f.write_all(contents)?;
|
||||
f.sync_all()?;
|
||||
if durability == Durability::Flushed {
|
||||
f.sync_all()?;
|
||||
}
|
||||
}
|
||||
std::fs::rename(&tmp, path)
|
||||
}
|
||||
@@ -522,6 +553,32 @@ mod tests {
|
||||
std::fs::remove_dir_all(&tmp).ok();
|
||||
}
|
||||
|
||||
/// The bulk write gives up the flush, not the atomicity: the same bytes land, the temp file
|
||||
/// is renamed away, and a replacement is still whole or absent.
|
||||
#[test]
|
||||
fn the_bulk_write_is_the_same_write_without_the_flush() {
|
||||
let _l = ENV_LOCK
|
||||
.lock()
|
||||
.unwrap_or_else(std::sync::PoisonError::into_inner);
|
||||
let tmp = std::env::temp_dir().join(format!("benilla-wab-{}", std::process::id()));
|
||||
std::fs::remove_dir_all(&tmp).ok();
|
||||
let (bulk, flushed) = (tmp.join("saved/A.lua"), tmp.join("saved/B.lua"));
|
||||
// A Lua byte string as the saved files carry it, embedded NUL and all.
|
||||
let body: &[u8] = b"A = \"x\\0y\"\n";
|
||||
write_atomic_bytes_bulk(&bulk, body).unwrap();
|
||||
write_atomic_bytes(&flushed, body).unwrap();
|
||||
assert_eq!(std::fs::read(&bulk).unwrap(), body);
|
||||
assert_eq!(
|
||||
std::fs::read(&bulk).unwrap(),
|
||||
std::fs::read(&flushed).unwrap(),
|
||||
"the flush changes durability, not content"
|
||||
);
|
||||
assert!(!bulk.with_extension("tmp").exists(), "tmp renamed away");
|
||||
write_atomic_bytes_bulk(&bulk, b"A = nil\n").unwrap();
|
||||
assert_eq!(std::fs::read(&bulk).unwrap(), b"A = nil\n");
|
||||
std::fs::remove_dir_all(&tmp).ok();
|
||||
}
|
||||
|
||||
/// The auto-login store holds a password in plaintext, so the claim that it is owner-only
|
||||
/// is worth asserting rather than trusting the `.mode()` call to have meant it.
|
||||
#[cfg(unix)]
|
||||
|
||||
@@ -6,9 +6,11 @@
|
||||
//! any consumer reads it. It is written only at UI shutdown (`0x490bd0`, after `PLAYER_LOGOUT`):
|
||||
//! the reference has no autosave and no Lua call that forces a write.
|
||||
//!
|
||||
//! Deviation: the write is atomic ([`crate::local_state::write_atomic_bytes`]), because the
|
||||
//! Deviation: the write is atomic ([`crate::local_state::write_atomic_bytes_bulk`]), because the
|
||||
//! reference's `.bak` rotation (`MoveFileW` without `MOVEFILE_REPLACE_EXISTING`, its result
|
||||
//! discarded) protects only the first write, and nothing reads the `.bak`.
|
||||
//! discarded) protects only the first write, and nothing reads the `.bak`. Atomic but unflushed,
|
||||
//! as the per-addon files beside it are: the flush is a disk round trip inside the blocked frame
|
||||
//! a `/reload` already is, and that bought nothing the rename does not.
|
||||
|
||||
use bevy::prelude::*;
|
||||
|
||||
@@ -82,7 +84,7 @@ pub(crate) fn save(script: &mut UiScript) {
|
||||
for w in script.take_warnings() {
|
||||
warn!("saved variables: {w}");
|
||||
}
|
||||
match crate::local_state::write_atomic_bytes(&path, &body) {
|
||||
match crate::local_state::write_atomic_bytes_bulk(&path, &body) {
|
||||
Ok(()) => info!(
|
||||
"saved variables: wrote {} ({} names)",
|
||||
path.display(),
|
||||
|
||||
@@ -683,7 +683,9 @@ pub(super) fn save_addon_variables(script: &mut UiScript, identity: Option<&(Str
|
||||
}
|
||||
let mut body = SAVED_HEADER.as_bytes().to_vec();
|
||||
body.extend(script.saved_variables_bytes_for(names));
|
||||
match crate::local_state::write_atomic_bytes(&path, &body) {
|
||||
// Bulk, so unflushed: one `fsync` per addon cost 305 ms of the reload's blocked
|
||||
// frame ([`crate::local_state::write_atomic_bytes_bulk`]).
|
||||
match crate::local_state::write_atomic_bytes_bulk(&path, &body) {
|
||||
Ok(()) => info!("ui_script: wrote {}", path.display()),
|
||||
Err(e) => warn!("ui_script: cannot write {}: {e}", path.display()),
|
||||
}
|
||||
|
||||
@@ -710,6 +710,21 @@ pub(crate) fn shutdown_ui_state(
|
||||
/// character screen runs on a state of its own. Ours is a fresh boot VM, which also carries the
|
||||
/// font registry the shared glyph atlas needs.
|
||||
pub(crate) fn end_ui_session(world: &mut World) {
|
||||
end_session(world, AfterSession::BootVm);
|
||||
}
|
||||
|
||||
/// What [`end_session`] leaves in the world's VM slot.
|
||||
#[derive(Clone, Copy, PartialEq, Eq)]
|
||||
pub(super) enum AfterSession {
|
||||
/// A fresh boot VM, for the roots that stop here: the character screen runs on it.
|
||||
BootVm,
|
||||
/// The dying VM, for a caller that mints its own in the same call ([`run_pending_reload`]).
|
||||
/// Nothing runs in between, so nothing sees the dead session.
|
||||
CallerMints,
|
||||
}
|
||||
|
||||
/// [`end_ui_session`], with what to leave behind spelled out.
|
||||
pub(super) fn end_session(world: &mut World, after: AfterSession) {
|
||||
// A VM still parked (the load never ran) goes back into the world first.
|
||||
unpark_boot_vm(world);
|
||||
// An entry load still armed means no in-game UI was built, and the tail would overwrite the
|
||||
@@ -753,7 +768,9 @@ pub(crate) fn end_ui_session(world: &mut World) {
|
||||
minimap.0 = None;
|
||||
}
|
||||
|
||||
install_boot_vm(world);
|
||||
if after == AfterSession::BootVm {
|
||||
install_boot_vm(world);
|
||||
}
|
||||
}
|
||||
|
||||
/// A `ReloadUI()` waiting to run: set when [`crate::ui_logout`] drains
|
||||
@@ -782,7 +799,24 @@ pub(crate) fn run_pending_reload(world: &mut World) {
|
||||
return;
|
||||
}
|
||||
info!("ui_script: ReloadUI — ending the UI session and building a new one");
|
||||
end_ui_session(world);
|
||||
// One VM for the reload, not two. The boot VM [`end_ui_session`] leaves is for the roots that
|
||||
// stop there (leaving the world, quitting); here [`load_ingame_ui_on_world_entry`] mints its
|
||||
// own at once in [`mint_entry_vm`], so building one in between only to drop it unused paid for
|
||||
// a whole `GlobalStrings.lua` run, emote table and font registry — **310 ms** of the single
|
||||
// blocked frame a reload is, measured in the player's 2026-10-18 log, where
|
||||
// `ui_script: GlobalStrings loaded` appears twice per `/reload`, at +350 ms and +662 ms.
|
||||
//
|
||||
// Safe because nothing runs between the two calls: this is one exclusive system, the dying VM
|
||||
// stays in the slot until the mint replaces it (so it is still dropped before any file loads),
|
||||
// and [`crate::cvars::fold_dying_vm_cvars`] drains what it folds, so the mint's second fold of
|
||||
// the same VM finds nothing. Only when the rebuild will certainly mint: with no UI wanted
|
||||
// (a capture) the load returns early, and the world would be left with no VM at all.
|
||||
let after = if ui_wanted(world) {
|
||||
AfterSession::CallerMints
|
||||
} else {
|
||||
AfterSession::BootVm
|
||||
};
|
||||
end_session(world, after);
|
||||
load_ingame_ui_on_world_entry(world);
|
||||
}
|
||||
|
||||
|
||||
@@ -112,6 +112,14 @@ fn probe_saw(world: &World) -> Option<String> {
|
||||
.flatten()
|
||||
}
|
||||
|
||||
/// The live VM's session id, which changes with every VM ever built.
|
||||
fn vm_session(world: &World) -> u64 {
|
||||
world
|
||||
.get_non_send_resource::<benilla_ui::script::UiScript>()
|
||||
.expect("a VM in the world")
|
||||
.session()
|
||||
}
|
||||
|
||||
/// Is the named frame present in the live VM?
|
||||
fn frame_exists(world: &World, name: &str) -> bool {
|
||||
world
|
||||
@@ -420,6 +428,61 @@ fn reload_ui_is_a_fresh_login_in_place() {
|
||||
let _ = std::fs::remove_dir_all(&tmp);
|
||||
}
|
||||
|
||||
/// A reload builds **one** VM, not two. The boot VM [`super::end_ui_session`] leaves behind is for
|
||||
/// the roots that stop there (leaving the world, quitting); a reload mints its own at once, and the
|
||||
/// one in between was built and dropped without ever running a line — a whole `GlobalStrings.lua`,
|
||||
/// emote table and font registry, 310 ms of the blocked frame in the player's 2026-10-18 log,
|
||||
/// which logged `GlobalStrings loaded` twice per `/reload`.
|
||||
///
|
||||
/// Asserted on the session id without arithmetic on it: the counter is process-global and another
|
||||
/// test's VM may advance it between two of these lines, but "unchanged" cannot be faked.
|
||||
#[test]
|
||||
fn a_reload_ends_the_session_without_building_a_vm_to_throw_away() {
|
||||
benilla_formats::wow_data_or_skip!();
|
||||
let _l = ENV_LOCK
|
||||
.lock()
|
||||
.unwrap_or_else(std::sync::PoisonError::into_inner);
|
||||
let (tmp, _c, _h) = hermetic_probe("reload-one-vm");
|
||||
let mut world = booted_world();
|
||||
world.insert_resource(State::new(crate::char_select::ClientState::InWorld));
|
||||
|
||||
log_in_as(&mut world, "Onehunter", 1);
|
||||
let live = vm_session(&world);
|
||||
|
||||
// The reload's own first half.
|
||||
super::lifecycle::end_session(&mut world, super::lifecycle::AfterSession::CallerMints);
|
||||
assert_eq!(
|
||||
vm_session(&world),
|
||||
live,
|
||||
"the dying VM is still in the slot — nothing was built to replace it for one call"
|
||||
);
|
||||
|
||||
// The second half mints the one VM the reload needs.
|
||||
super::load_ingame_ui_on_world_entry(&mut world);
|
||||
assert_ne!(vm_session(&world), live, "and the rebuild is a new session");
|
||||
assert_eq!(
|
||||
probe_loads(&world),
|
||||
1,
|
||||
"with the addon's file scope run once, in that fresh VM"
|
||||
);
|
||||
assert!(
|
||||
frame_exists(&world, "PlayerFrame"),
|
||||
"and the in-game UI is up on it"
|
||||
);
|
||||
|
||||
// The other roots still get their boot VM: the character screen runs on one.
|
||||
let in_world = vm_session(&world);
|
||||
super::lifecycle::end_session(&mut world, super::lifecycle::AfterSession::BootVm);
|
||||
assert_ne!(
|
||||
vm_session(&world),
|
||||
in_world,
|
||||
"leaving the world replaces the VM, as the character screen needs it to"
|
||||
);
|
||||
|
||||
drop(world);
|
||||
let _ = std::fs::remove_dir_all(&tmp);
|
||||
}
|
||||
|
||||
/// `DisableAddOn` only marks the live registry; the reload's shutdown tail writes `AddOns.txt`
|
||||
/// (the reference's last write before the state dies) and the rebuild reads it back.
|
||||
#[test]
|
||||
|
||||
@@ -0,0 +1,144 @@
|
||||
//! Where a big addon data file's load cost goes, and what would take it away.
|
||||
//!
|
||||
//! `cargo run --release -p benilla-ui --example chunkbench -- <file.lua>…` runs three passes over
|
||||
//! the same files and prints each:
|
||||
//!
|
||||
//! 1. **fresh VM per file** — the floor: parse, execute, dump to 5.1 bytecode, re-compile that
|
||||
//! bytecode. A bytecode cache can only ever remove the *parse* column, so this says whether
|
||||
//! one is worth building.
|
||||
//! 2. **one VM, stock GC** — the real shape of a load, where every later file allocates against
|
||||
//! the heap the earlier ones left live and Lua's incremental collector walks all of it.
|
||||
//! 3. **one VM, collector stopped** for the whole load and collected once at the end — the same
|
||||
//! work with the GC's share of it named.
|
||||
//!
|
||||
//! Globals autovivify at every depth (`pfDB["items"]["data"] = {…}` reads two levels before it
|
||||
//! writes), so a database file runs outside its addon.
|
||||
|
||||
use std::time::Instant;
|
||||
|
||||
fn ms(t: Instant) -> f64 {
|
||||
t.elapsed().as_secs_f64() * 1000.0
|
||||
}
|
||||
|
||||
/// A VM whose global reads mint tables on demand, so an addon's data file needs no addon.
|
||||
fn vm() -> mlua::Lua {
|
||||
let lua = mlua::Lua::new();
|
||||
lua.load(
|
||||
r#"local mt = {}
|
||||
mt.__index = function(t, k)
|
||||
local v = setmetatable({}, mt); rawset(t, k, v); return v
|
||||
end
|
||||
setmetatable(_G, mt)"#,
|
||||
)
|
||||
.exec()
|
||||
.expect("the autovivify metatable");
|
||||
lua
|
||||
}
|
||||
|
||||
fn main() -> mlua::Result<()> {
|
||||
let files: Vec<String> = std::env::args().skip(1).collect();
|
||||
if files.is_empty() {
|
||||
eprintln!("usage: chunkbench <file.lua>…");
|
||||
return Ok(());
|
||||
}
|
||||
let sources: Vec<(String, Vec<u8>)> = files
|
||||
.iter()
|
||||
.map(|p| (p.clone(), std::fs::read(p).expect("the file")))
|
||||
.collect();
|
||||
let mib: f64 = sources.iter().map(|(_, s)| s.len() as f64).sum::<f64>() / (1024.0 * 1024.0);
|
||||
|
||||
// 1 · a VM per file.
|
||||
println!(
|
||||
"{:>8} {:>9} {:>9} {:>9} {:>9} file",
|
||||
"MiB", "parse ms", "exec ms", "dump ms", "bc ms"
|
||||
);
|
||||
let mut tot = [0.0f64; 5]; // MiB, parse, exec, dump, bytecode-compile
|
||||
for (path, src) in &sources {
|
||||
let lua = vm();
|
||||
let t = Instant::now();
|
||||
// A file the client never compiles as a chunk (a `#!` tool script, say) is counted and
|
||||
// skipped rather than ending the run.
|
||||
let Ok(f) = lua.load(&src[..]).set_name(path.as_str()).into_function() else {
|
||||
println!(
|
||||
"{:8.2} {:>49} {path}",
|
||||
src.len() as f64 / (1024.0 * 1024.0),
|
||||
"[did not parse]"
|
||||
);
|
||||
continue;
|
||||
};
|
||||
let parse = ms(t);
|
||||
// An addon file outside its addon often cannot run (it calls what the client installs);
|
||||
// the parse column is measured either way, and a file that raised is marked.
|
||||
let t = Instant::now();
|
||||
let ran = f.call::<()>(()).is_ok();
|
||||
let exec = if ran { ms(t) } else { 0.0 };
|
||||
let t = Instant::now();
|
||||
let bc = f.dump(true);
|
||||
let dump = ms(t);
|
||||
drop(lua);
|
||||
|
||||
let lua = vm();
|
||||
let t = Instant::now();
|
||||
lua.load(&bc[..])
|
||||
.set_name(path.as_str())
|
||||
.set_mode(mlua::ChunkMode::Binary)
|
||||
.into_function()?;
|
||||
let bcload = ms(t);
|
||||
drop(lua);
|
||||
|
||||
let fmib = src.len() as f64 / (1024.0 * 1024.0);
|
||||
println!(
|
||||
"{fmib:8.2} {parse:9.1} {exec:9.1} {dump:9.1} {bcload:9.1} {path}{}",
|
||||
if ran { "" } else { " [did not run]" }
|
||||
);
|
||||
for (slot, v) in tot.iter_mut().zip([fmib, parse, exec, dump, bcload]) {
|
||||
*slot += v;
|
||||
}
|
||||
}
|
||||
let [mib_sum, parse, exec, dump, bcload] = tot;
|
||||
println!(
|
||||
"{mib_sum:8.2} {parse:9.1} {exec:9.1} {dump:9.1} {bcload:9.1} — a VM per file, {} files",
|
||||
files.len()
|
||||
);
|
||||
println!(
|
||||
" parse+exec {:.0} ms; with the parse served from a bytecode cache {:.0} ms\n",
|
||||
parse + exec,
|
||||
bcload + exec
|
||||
);
|
||||
|
||||
// 2 and 3 · one VM for the whole set, as a load does it.
|
||||
for stop_gc in [false, true] {
|
||||
let lua = vm();
|
||||
if stop_gc {
|
||||
lua.gc_stop();
|
||||
}
|
||||
let before = lua.used_memory();
|
||||
let t0 = Instant::now();
|
||||
let mut worst = (0.0f64, "");
|
||||
for (path, src) in &sources {
|
||||
let t = Instant::now();
|
||||
if let Ok(f) = lua.load(&src[..]).set_name(path.as_str()).into_function() {
|
||||
let _ = f.call::<()>(());
|
||||
}
|
||||
let each = ms(t);
|
||||
if each > worst.0 {
|
||||
worst = (each, path);
|
||||
}
|
||||
}
|
||||
let load = ms(t0);
|
||||
let t = Instant::now();
|
||||
lua.gc_collect()?;
|
||||
let collect = ms(t);
|
||||
let heap = (lua.used_memory() - before) as f64 / (1024.0 * 1024.0);
|
||||
println!(
|
||||
"one VM, GC {:7}: load {load:7.0} ms final collect {collect:6.0} ms \
|
||||
heap {heap:6.1} MiB worst file {:.0} ms ({})",
|
||||
if stop_gc { "stopped" } else { "stock" },
|
||||
worst.0,
|
||||
worst.1,
|
||||
);
|
||||
drop(lua);
|
||||
}
|
||||
println!("{mib:.1} MiB of source in all");
|
||||
Ok(())
|
||||
}
|
||||
Reference in New Issue
Block a user