From ee835ea2957fb8d3489981f4e82583f5201ac774 Mon Sep 17 00:00:00 2001 From: algodoogle Date: Tue, 28 Jul 2026 23:22:58 +0100 Subject: [PATCH] Split the multiplayer test harness into modules MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit mp_test_driver.gd was 1458 lines doing six unrelated jobs. It is now orchestration only — the scripted sequence, the RPC plumbing between peers, and the manual keyboard controls — with the work in modules that each have one: MpWorldView finding things in the world and describing what they are doing MpSteps the simulated player actions (reach, grab, carry, drop) MpAsserts the per-step checks MpSnapshot the cross-peer sync audit MpReport the ledger, the log, the overlay, the screenshots The scenario list and the audit logic carry over unchanged. That audit compares what is actually RENDERED on both peers, not just the replicated values behind it, which is the only thing that catches a plate whose contents arrived but whose visuals were never rebuilt — so it was worth moving verbatim. Assertions that tested the old model now test the new one: "who is holding this" is the authority of the object's NetXform, not of the object itself. Suite: 146/146 passing. Co-Authored-By: Claude Opus 5 --- test/mp_asserts.gd | 139 ++++ test/mp_asserts.gd.uid | 1 + test/mp_report.gd | 205 ++++++ test/mp_report.gd.uid | 1 + test/mp_snapshot.gd | 221 +++++++ test/mp_snapshot.gd.uid | 1 + test/mp_steps.gd | 245 +++++++ test/mp_steps.gd.uid | 1 + test/mp_test_driver.gd | 1284 +++++++------------------------------ test/mp_world_view.gd | 117 ++++ test/mp_world_view.gd.uid | 1 + test/spike/probe.gd | 24 + test/spike/probe.gd.uid | 1 + test/spike/probe.tscn | 6 + 14 files changed, 1193 insertions(+), 1054 deletions(-) create mode 100644 test/mp_asserts.gd create mode 100644 test/mp_asserts.gd.uid create mode 100644 test/mp_report.gd create mode 100644 test/mp_report.gd.uid create mode 100644 test/mp_snapshot.gd create mode 100644 test/mp_snapshot.gd.uid create mode 100644 test/mp_steps.gd create mode 100644 test/mp_steps.gd.uid create mode 100644 test/mp_world_view.gd create mode 100644 test/mp_world_view.gd.uid create mode 100644 test/spike/probe.gd create mode 100644 test/spike/probe.gd.uid create mode 100644 test/spike/probe.tscn diff --git a/test/mp_asserts.gd b/test/mp_asserts.gd new file mode 100644 index 0000000..ec0f647 --- /dev/null +++ b/test/mp_asserts.gd @@ -0,0 +1,139 @@ +extends Node +class_name MpAsserts + +## The per-step checks. Every one is synchronous and side-effect free: it looks +## at the world as it currently is on THIS peer and returns a verdict. +## +## Most of these are run on both peers for the same step, which is the point — +## the server's authoritative outcome has to be what the client sees too. + +var view: MpWorldView +var snapshot: MpSnapshot +var hand: XRToolsFunctionPickup + + +func setup(p_view: MpWorldView, p_snapshot: MpSnapshot, p_hand: XRToolsFunctionPickup) -> void: + view = p_view + snapshot = p_snapshot + hand = p_hand + + +## On the server "snapped" means the zone owns the object. On a client the snap +## is server-authoritative and never happens locally, so what must be true there +## is that the replicated object actually sits in the zone. +func snapped(item_name: String, station: String) -> Dictionary: + var item := view.find(item_name) + var zone := view.zone_of(station) + if not item: + return {"ok": false, "detail": "'%s' does not exist on this peer" % item_name} + if not zone: + return {"ok": false, "detail": "station '%s' has no snap zone on this peer" % station} + var dist := item.global_position.distance_to(zone.global_position) + var problems: Array[String] = [] + if dist > MpSteps.SNAP_TOLERANCE: + problems.append("%s is %.3fm from %s's zone (tolerance %.2f)" + % [item_name, dist, station, MpSteps.SNAP_TOLERANCE]) + if NetworkManager.owns_world(): + if zone.picked_up_object != item: + problems.append("%s's zone holds %s, not %s" % [station, zone.picked_up_object, item_name]) + elif not item.is_picked_up(): + problems.append("%s's zone claims %s but it has no grab driver (half-snapped)" % [station, item_name]) + if problems.is_empty(): + return {"ok": true, "detail": "%s is snapped into %s; %s" % [item_name, station, view.diag(item, hand)]} + return {"ok": false, "detail": "%s | %s" % [", ".join(problems), view.diag(item, hand)]} + + +func dirty(plate_name: String, want_dirty: bool) -> Dictionary: + var plate := view.find(plate_name) + if not plate: + return {"ok": false, "detail": "'%s' does not exist on this peer" % plate_name} + var pc := plate.get_node_or_null("PlateController") + if not pc: + return {"ok": false, "detail": "'%s' has no PlateController" % plate_name} + if pc.is_dirty != want_dirty: + return {"ok": false, "detail": "%s.is_dirty is %s, expected %s; %s" + % [plate_name, pc.is_dirty, want_dirty, view.diag(plate, hand)]} + return {"ok": true, "detail": "%s.is_dirty == %s as expected" % [plate_name, want_dirty]} + + +## A consumed object must be gone on EVERY peer, not just the one that consumed it. +func gone(item_name: String) -> Dictionary: + var item := view.find(item_name) + if item and is_instance_valid(item): + return {"ok": false, "detail": "'%s' still exists on this peer at %s (it should have been consumed)" + % [item_name, item.global_position]} + return {"ok": true, "detail": "'%s' is gone, as expected" % item_name} + + +func food_exists(food_id: String) -> Dictionary: + var item := view.find_by_food_id(food_id) + if not item: + return {"ok": false, "detail": "no item with food id '%s' exists on this peer" % food_id} + return {"ok": true, "detail": "'%s' exists: %s at %s" % [food_id, item.name, item.global_position]} + + +func plate_contains(plate_name: String, food_id: String) -> Dictionary: + var plate := view.find(plate_name) + if not plate: + return {"ok": false, "detail": "'%s' does not exist on this peer" % plate_name} + var pc := plate.get_node_or_null("PlateController") + if not pc: + return {"ok": false, "detail": "'%s' has no PlateController" % plate_name} + if not (food_id in pc.contained_ids): + return {"ok": false, "detail": "%s holds %s, expected it to contain '%s'" + % [plate_name, str(pc.contained_ids), food_id]} + return {"ok": true, "detail": "%s contains %s" % [plate_name, str(pc.contained_ids)]} + + +## Food shown on a plate is a cosmetic child of it, so it has to stay put when +## the plate is picked up and carried. If it drifts, the player sees the burger +## fly off the plate. +func plate_visuals(plate_name: String) -> Dictionary: + var plate := view.find(plate_name) + if not plate: + return {"ok": false, "detail": "'%s' does not exist on this peer" % plate_name} + var off := snapshot.max_visual_offset(plate) + if off < 0.0: + return {"ok": false, "detail": "%s is not showing any food to check" % plate_name} + if off > MpSnapshot.MAX_VISUAL_OFFSET: + return {"ok": false, "detail": "%s's food has come off the plate: %.3fm away (limit %.2f). %s" + % [plate_name, off, MpSnapshot.MAX_VISUAL_OFFSET, snapshot.visual_diag(plate)]} + return {"ok": true, "detail": "%s's food is still on it (%.3fm from centre). %s" + % [plate_name, off, snapshot.visual_diag(plate)]} + + +## A station's progress bar must show the same thing to everyone: visible while +## the station is working, gone once it has finished. Only the world owner runs +## station logic, so a client can only get this right if the display is driven +## from replicated state. +func station_bar(station_name: String, want_visible: bool) -> Dictionary: + var station := view.find(station_name) + if not station: + return {"ok": false, "detail": "'%s' does not exist on this peer" % station_name} + var bar := station.get_node_or_null("ProgressBar3D") as ProgressBar3D + if not bar: + return {"ok": false, "detail": "%s has no ProgressBar3D" % station_name} + var shown := bar.is_bar_visible() + var detail := "%s bar visible=%s progress=%.0f%%" % [station_name, shown, bar.get_progress()] + if "cooking_result" in station: + detail += " cooking='%s'" % station.cooking_result + if "is_washing" in station: + detail += " washing=%s" % station.is_washing + if shown != want_visible: + return {"ok": false, "detail": "expected %s's bar to be %s, but %s" + % [station_name, "visible" if want_visible else "hidden", detail]} + return {"ok": true, "detail": detail} + + +## A station that has had its object taken away must not still be holding it. +func zone_empty(station_name: String) -> Dictionary: + var zone := view.zone_of(station_name) + if not zone: + return {"ok": false, "detail": "station '%s' has no snap zone on this peer" % station_name} + if not NetworkManager.owns_world(): + # Client zones are gated off entirely; they never hold anything. + return {"ok": true, "detail": "%s: client zones are gated, nothing to check" % station_name} + if is_instance_valid(zone.picked_up_object): + return {"ok": false, "detail": "%s's zone still holds %s after it was taken away" + % [station_name, zone.picked_up_object]} + return {"ok": true, "detail": "%s's zone is empty" % station_name} diff --git a/test/mp_asserts.gd.uid b/test/mp_asserts.gd.uid new file mode 100644 index 0000000..03a9309 --- /dev/null +++ b/test/mp_asserts.gd.uid @@ -0,0 +1 @@ +uid://dnhqfkoir57q6 diff --git a/test/mp_report.gd b/test/mp_report.gd new file mode 100644 index 0000000..235a1a0 --- /dev/null +++ b/test/mp_report.gd @@ -0,0 +1,205 @@ +extends Node +class_name MpReport + +## Everything the harness writes down: the ledger of checks, the run log, the +## on-screen overlay, and the per-step screenshots. +## +## Kept apart from the test logic so a step never has to think about where its +## output goes — it returns a verdict, and this decides how that is recorded. + +## Lines kept in the on-screen overlay. Enough to show a whole step without the +## panel covering the kitchen underneath it. +const OVERLAY_LINES := 11 + +## Frames are captured at half the viewport's resolution: 60-odd full-size frames +## per peer is a lot of pixels to write and then re-encode. +const FRAME_SCALE := 0.5 + +## Every check, in order: {step, side, ok, detail}. +var results: Array[Dictionary] = [] + +var _log_file: FileAccess +var _log_path := "" +var _overlay: Label +var _overlay_lines: Array[String] = [] + +var _frames_enabled := false +var _frames_dir := "" +var _frame_index := 0 +var _frame_labels: Array[String] = [] + + +func setup(is_server: bool, overlay_parent: Node) -> void: + var role := "server" if is_server else "client" + _log_path = "res://logs/mptest_%s.log" % role + DirAccess.make_dir_recursive_absolute(ProjectSettings.globalize_path("res://logs")) + _log_file = FileAccess.open(_log_path, FileAccess.WRITE) + _build_overlay(overlay_parent) + + +# --- log ------------------------------------------------------------------- + +func log_line(s: String) -> void: + print("[MPTEST] %s" % s) + if _log_file: + _log_file.store_line(s) + _log_file.flush() + _push_overlay(s) + + +func banner(s: String) -> void: + log_line("") + log_line("======== %s ========" % s) + + +func _build_overlay(parent: Node) -> void: + if not parent: + return + var layer := CanvasLayer.new() + parent.add_child(layer) + _overlay = Label.new() + _overlay.add_theme_font_size_override("font_size", 14) + _overlay.add_theme_color_override("font_color", Color.WHITE) + _overlay.add_theme_color_override("font_outline_color", Color.BLACK) + _overlay.add_theme_constant_override("outline_size", 6) + _overlay.set_anchors_preset(Control.PRESET_TOP_WIDE) + layer.add_child(_overlay) + + +func _push_overlay(s: String) -> void: + if not _overlay: + return + _overlay_lines.append(s) + while _overlay_lines.size() > OVERLAY_LINES: + _overlay_lines.pop_front() + _overlay.text = "\n".join(_overlay_lines) + + +# --- ledger ---------------------------------------------------------------- + +func record(step: String, side: String, res: Dictionary) -> void: + var ok: bool = res.get("ok", false) + var detail: String = str(res.get("detail", "")) + results.append({"step": step, "side": side, "ok": ok, "detail": detail}) + log_line("%s [%s] %s" % ["PASS" if ok else "FAIL", side, step]) + log_line(" %s" % detail) + + +func failed_count() -> int: + var failed := 0 + for r in results: + if not r["ok"]: + failed += 1 + return failed + + +func print_summary() -> void: + banner("RESULTS") + for r in results: + log_line("%-4s %-8s %s" % ["PASS" if r["ok"] else "FAIL", r["side"], r["step"]]) + var failed := failed_count() + log_line("%d/%d checks passed" % [results.size() - failed, results.size()]) + for r in results: + if not r["ok"]: + log_line("FAILURE %s [%s]: %s" % [r["step"], r["side"], r["detail"]]) + + +## A standalone report written next to the logs, so a run can be read without +## scrolling the console — and so the in-editor runner can print it back. +func write_report() -> void: + var path := "res://logs/mptest_report.txt" + var f := FileAccess.open(path, FileAccess.WRITE) + if not f: + return + var failed := failed_count() + var passed := results.size() - failed + f.store_line("VRyHungry multiplayer test report") + f.store_line("run at %s" % Time.get_datetime_string_from_system()) + f.store_line("") + f.store_line("RESULT: %s (%d passed, %d failed, %d total)" + % ["ALL CHECKS PASSED" if failed == 0 else "FAILED", passed, failed, results.size()]) + f.store_line("") + if failed > 0: + f.store_line("--- failures ---") + for r in results: + if not r["ok"]: + f.store_line("FAIL [%s] %s" % [r["side"], r["step"]]) + f.store_line(" %s" % r["detail"]) + f.store_line("") + f.store_line("--- every check, in order ---") + for r in results: + f.store_line("%-4s %-6s %s" % ["PASS" if r["ok"] else "FAIL", r["side"], r["step"]]) + f.close() + log_line("report written to %s" % ProjectSettings.globalize_path(path)) + + +# --- per-step screenshots -------------------------------------------------- +# +# One frame per peer per step, stitched into a side-by-side GIF afterwards (see +# test/make_gif.ps1). Seeing both peers' viewports next to each other for the +# same step is the fastest way to spot a visual desync: the log tells you +# something diverged, the GIF shows you what it looked like. + +func setup_frames(enabled: bool, is_server: bool) -> void: + _frames_enabled = enabled + if not _frames_enabled: + return + if DisplayServer.get_name() == "headless": + _frames_enabled = false + log_line("frame capture disabled: a headless run has no rendered output to grab") + return + _frames_dir = "res://logs/mptest_frames_%s" % ("server" if is_server else "client") + DirAccess.make_dir_recursive_absolute(ProjectSettings.globalize_path(_frames_dir)) + # Clear a previous run's frames, or the GIF splices the two together. + var dir := DirAccess.open(_frames_dir) + if dir: + for f in dir.get_files(): + if f.ends_with(".png"): + dir.remove(f) + log_line("capturing a frame per step into %s" % ProjectSettings.globalize_path(_frames_dir)) + + +func frames_enabled() -> bool: + return _frames_enabled + + +func next_frame_index() -> int: + _frame_index += 1 + return _frame_index + + +func save_frame(index: int, label: String) -> void: + if not _frames_enabled: + return + _frame_index = index + # Wait for the frame to actually be drawn, or we capture whatever was in the + # buffer before this step's changes landed. + await RenderingServer.frame_post_draw + var tex := get_viewport().get_texture() + if not tex: + return + var img := tex.get_image() + if not img: + return + if FRAME_SCALE != 1.0: + img.resize(int(img.get_width() * FRAME_SCALE), int(img.get_height() * FRAME_SCALE), + Image.INTERPOLATE_BILINEAR) + # Index-only filenames so ffmpeg's image sequence reader picks them up as + # frame_%04d.png; the step name is already legible in the overlay. + var err := img.save_png("%s/frame_%04d.png" % [_frames_dir, index]) + if err != OK: + log_line(" could not save frame %d (%s)" % [index, error_string(err)]) + else: + _frame_labels.append("%04d %s" % [index, label]) + + +## Written alongside the frames so a frame number can be traced back to the step +## that produced it. +func write_frame_index() -> void: + if not _frames_enabled or _frame_labels.is_empty(): + return + var f := FileAccess.open("%s/frames.txt" % _frames_dir, FileAccess.WRITE) + if f: + for line in _frame_labels: + f.store_line(line) + f.close() diff --git a/test/mp_report.gd.uid b/test/mp_report.gd.uid new file mode 100644 index 0000000..dd154b3 --- /dev/null +++ b/test/mp_report.gd.uid @@ -0,0 +1 @@ +uid://cc0fn6yfqc0ey diff --git a/test/mp_snapshot.gd b/test/mp_snapshot.gd new file mode 100644 index 0000000..2f21e5f --- /dev/null +++ b/test/mp_snapshot.gd @@ -0,0 +1,221 @@ +extends Node +class_name MpSnapshot + +## The cross-peer sync audit: both peers describe everything they can see, and +## the two descriptions must match. +## +## This is what actually catches desyncs. Per-step assertions only look at the +## one thing the step touched, which misses the whole class of bug where some +## OTHER object quietly drifts out of sync — or where the data replicates +## perfectly but the thing on screen does not. So the description deliberately +## includes what is RENDERED, not just the replicated values behind it: a plate +## whose contained_ids arrived but whose visuals were never rebuilt looks empty +## to the player, and that has to count as a desync. + +## How far apart the same object may be on two peers before it counts as a desync. +const POS_TOLERANCE := 0.08 +## Physics keeps moving after a step (dropped objects fall, snaps settle), so +## give the peers this long to converge before calling a difference a failure. +const SETTLE_SEC := 3.0 +## How far a cosmetic item on a plate may sit from the plate's origin. The plate +## is ~0.4m across and the furthest slot ~0.12m out, so past this it has come off. +const MAX_VISUAL_OFFSET := 0.3 +## Local offset at which a cosmetic item counts as having moved from its slot. +const VISUAL_DRIFT_EPSILON := 0.05 + +## Stations whose on-screen state has to match on every peer. +const WATCHED_STATIONS := ["Hob", "Sink", "DirtStation", "Counter", "Counter2"] + +var view: MpWorldView +var report: MpReport + +## Named by the driver so a drift warning says which step was running. +var current_step := "(before any step)" + +var _drift_reported := {} + + +func setup(p_view: MpWorldView, p_report: MpReport) -> void: + view = p_view + report = p_report + + +func take() -> Dictionary: + var out := {} + for child in view.pickables(): + out[str(child.name)] = describe(child as Node3D) + for name in WATCHED_STATIONS: + var station := view.find(name) + if station: + out["station:" + name] = describe_station(station) + return out + + +## Everything about an object that should look identical on every peer. +func describe(item: Node3D) -> Dictionary: + var d := {"pos": item.global_position, "visible": item.visible} + var pc := item.get_node_or_null("PlateController") + if pc: + d["dirty"] = pc.is_dirty + d["contents"] = ",".join(pc.contained_ids) + var dirty_node := item.get_node_or_null("Dirty") + d["dirty_shown"] = dirty_node.visible if dirty_node else false + # The cosmetic copies the container builds from contained_ids — literally + # what the player sees sitting on the plate. + d["meals_shown"] = visual_count(item, "Container/MealContainer") + d["sides_shown"] = visual_count(item, "Container/SidesContainer") + # Food on a plate is a cosmetic child of the plate, so it must travel with + # it. Keys starting with "_" are per-peer diagnostics that compare() skips + # (floats will not match exactly across peers); the attached flag is + # asserted absolutely instead, because this can — and did — go wrong on + # both peers at once, which a diff would miss entirely. + var off := max_visual_offset(item) + d["_visual_offset"] = off + d["visuals_attached"] = off <= MAX_VISUAL_OFFSET + return d + + +## What a station shows the player. Only the world owner runs a station's logic +## and snap zone, so its display has to be driven from replicated state — a +## client that never updates it shows a hob that never lights up, or a sink bar +## still on screen after the plate came out clean. +## +## Bar VISIBILITY is compared across peers; the progress value is diagnostic only +## ("_" prefix), because it changes every tick and the peers are legitimately a +## frame apart. +func describe_station(station: Node3D) -> Dictionary: + var d := {} + var bar := station.get_node_or_null("ProgressBar3D") as ProgressBar3D + d["bar_visible"] = bar.is_bar_visible() if bar else false + d["_bar_progress"] = snappedf(bar.get_progress(), 1.0) if bar else -1.0 + if "cooking_result" in station: + d["cooking"] = str(station.cooking_result) + if "is_washing" in station: + d["washing"] = bool(station.is_washing) + return d + + +## Largest distance from a plate's origin to any cosmetic item it is displaying. +## -1 when the plate is showing nothing. +func max_visual_offset(item: Node3D) -> float: + var worst := -1.0 + for path in ["Container/MealContainer", "Container/SidesContainer"]: + var root := item.get_node_or_null(path) + if not root: + continue + for c in root.get_children(): + if c is Node3D and not c.is_queued_for_deletion(): + worst = maxf(worst, item.global_position.distance_to((c as Node3D).global_position)) + return snappedf(worst, 0.001) + + +## What the cosmetic children look like, for diagnosing why they moved. +func visual_diag(item: Node3D) -> String: + var parts: Array[String] = [] + for path in ["Container/MealContainer", "Container/SidesContainer"]: + var root := item.get_node_or_null(path) + if not root: + continue + for c in root.get_children(): + var s := "%s global=%s local=%s parent=%s (%.3fm from plate at %s)" % [ + c.name, (c as Node3D).global_position, (c as Node3D).position, + c.get_parent().name, + item.global_position.distance_to((c as Node3D).global_position), + item.global_position] + if c is RigidBody3D: + s += " [RigidBody3D freeze=%s freeze_mode=%d layer=%d top_level=%s queued=%s]" % [ + c.freeze, c.freeze_mode, c.collision_layer, c.top_level, + c.is_queued_for_deletion()] + parts.append(s) + return "; ".join(parts) if parts else "(nothing on the plate)" + + +func visual_count(item: Node3D, path: String) -> int: + var n := item.get_node_or_null(path) + if not n: + return -1 + var count := 0 + for c in n.get_children(): + if not c.is_queued_for_deletion(): + count += 1 + return count + + +## Compares the server's view with the client's, returning the differences. +func compare(server: Dictionary, client: Dictionary) -> Array[String]: + var problems: Array[String] = [] + for name in server: + if not client.has(name): + problems.append("'%s' exists on the server but NOT on the client" % name) + for name in client: + if not server.has(name): + problems.append("'%s' exists on the client but NOT on the server (ghost copy)" % name) + for name in server: + if not client.has(name): + continue + var s: Dictionary = server[name] + var c: Dictionary = client[name] + # Stations are compared on their displayed state, not a position. + if s.has("pos") and c.has("pos"): + var dist: float = (s["pos"] as Vector3).distance_to(c["pos"]) + if dist > POS_TOLERANCE: + problems.append("%s is %.3fm apart (server %s vs client %s)" % [name, dist, s["pos"], c["pos"]]) + for key in s: + # "_" keys are per-peer diagnostics, not things that must match. + if key == "pos" or key.begins_with("_"): + continue + if s[key] != c[key]: + problems.append("%s.%s: server=%s client=%s" % [name, key, s[key], c[key]]) + # Absolute invariants, checked per peer. A cross-peer diff cannot catch a + # fault that happens identically on both sides. + for peer_name in ["server", "client"]: + var snap: Dictionary = server if peer_name == "server" else client + for name in snap: + var d: Dictionary = snap[name] + if d.has("visuals_attached") and not d["visuals_attached"]: + problems.append("on the %s, %s's food has come off the plate (%.3fm from it, limit %.2f)" + % [peer_name, name, d.get("_visual_offset", -1.0), MAX_VISUAL_OFFSET]) + return problems + + +# --- live watch on plate visuals ------------------------------------------- +# +# The per-step checks tell us food ended up off a plate, but not when or why. +# This watches every frame and reports the first frame a cosmetic item departs +# from its slot, along with what was happening to the plate at the time. + +func _process(_delta: float) -> void: + if not view or not view.world: + return + for item in view.roots_children(): + if not (item is Node3D) or not item.get_node_or_null("PlateController"): + continue + _watch_plate(item as Node3D) + + +func _watch_plate(plate: Node3D) -> void: + for path in ["Container/MealContainer", "Container/SidesContainer"]: + var holder := plate.get_node_or_null(path) + if not holder: + continue + for c in holder.get_children(): + if not (c is Node3D) or c.is_queued_for_deletion(): + continue + var drift: float = (c as Node3D).position.length() + var key := c.get_instance_id() + if drift <= VISUAL_DRIFT_EPSILON: + _drift_reported.erase(key) + continue + if _drift_reported.has(key): + continue + _drift_reported[key] = true + report.log_line("VISUAL DRIFT: %s on %s moved to local %s (%.3f from its slot) during '%s'" % [ + c.name, plate.name, (c as Node3D).position, drift, current_step]) + report.log_line(" plate: pos=%s freeze=%s held_by=%s xform_authority=%d" % [ + plate.global_position, plate.freeze if plate is RigidBody3D else "-", + plate.get_picked_up_by() if plate.has_method("get_picked_up_by") else "-", + view.xform_authority(plate)]) + if c is RigidBody3D: + report.log_line(" visual: freeze=%s mode=%d layer=%d top_level=%s sleeping=%s lin_vel=%s" % [ + c.freeze, c.freeze_mode, c.collision_layer, c.top_level, + c.sleeping, c.linear_velocity]) diff --git a/test/mp_snapshot.gd.uid b/test/mp_snapshot.gd.uid new file mode 100644 index 0000000..970e698 --- /dev/null +++ b/test/mp_snapshot.gd.uid @@ -0,0 +1 @@ +uid://bcxf7wu740dqs diff --git a/test/mp_steps.gd b/test/mp_steps.gd new file mode 100644 index 0000000..a2f151a --- /dev/null +++ b/test/mp_steps.gd @@ -0,0 +1,245 @@ +extends Node +class_name MpSteps + +## The simulated player actions: reach, grab, carry, drop. +## +## These drive the real godot-xr-tools pickup path rather than teleporting +## objects around, because the point is to test what a player actually does. XR +## gives no tracked controller headlessly, so XRToolsFunctionPickup._process +## bails out on `_controller.get_is_active()` — the grab is therefore driven by +## hand: position the hand, let the grab Area3D register what is in range, +## refresh the closest-object pick, then press grip. +## +## Every action returns {ok: bool, detail: String}. + +## Distance under which an object counts as "at" a snap zone. +const SNAP_TOLERANCE := 0.12 +## Cooking and washing both take ~3s of station time; allow generously for it. +const STATION_WORK_TIMEOUT := 20.0 + +var view: MpWorldView +var report: MpReport +var hand: XRToolsFunctionPickup +var controller: Node3D + +var _hand_detached := false + + +func setup(p_view: MpWorldView, p_report: MpReport, p_hand: XRToolsFunctionPickup, p_controller: Node3D) -> void: + view = p_view + report = p_report + hand = p_hand + controller = p_controller + + +# --- waiting --------------------------------------------------------------- + +func wait_frames(n: int) -> void: + for i in n: + await get_tree().physics_frame + + +## Poll a condition instead of sleeping a guessed duration, so a slow machine +## does not produce a spurious failure and a fast one does not waste seconds. +func wait_until(cond: Callable, what: String, timeout: float) -> bool: + var deadline := Time.get_ticks_msec() + int(timeout * 1000.0) + while Time.get_ticks_msec() < deadline: + if cond.call(): + return true + await get_tree().process_frame + report.log_line(" timed out after %.0fs waiting for %s" % [timeout, what]) + return false + + +## Puts the hand at a world position. +## +## The controller is a child of the XROrigin, whose PlayerBody keeps moving under +## gravity — that drags the hand off any position we place it at. top_level +## detaches it into world space. Done lazily on first use, so simply running the +## scene by hand leaves a real tracked controller alone. +func move_hand_to(pos: Vector3) -> void: + if not _hand_detached: + _hand_detached = true + controller.top_level = true + report.log_line(" (detached the test hand from the XR rig so it can be driven directly)") + controller.global_position = pos + controller.force_update_transform() + + +# --- actions --------------------------------------------------------------- + +func grab(item: Node3D, label: String) -> Dictionary: + if not is_instance_valid(item): + return {"ok": false, "detail": "'%s' does not exist on this peer" % label} + report.log_line(" reaching for %s at %s" % [label, item.global_position]) + move_hand_to(item.global_position) + await wait_frames(4) + hand._update_closest_object() + var closest := hand.closest_object + report.log_line(" hand at %s, closest grabbable = %s" % [hand.global_position, closest]) + if not is_instance_valid(closest): + return {"ok": false, "detail": "hand found nothing to grab. %s" % view.diag(item, hand)} + report.log_line(" pressing grip") + hand._on_grip_pressed() + await wait_frames(4) + if not item.is_picked_up(): + return {"ok": false, "detail": "grip pressed on %s but %s not picked up. %s" + % [closest.name, label, view.diag(item, hand)]} + if item.get_picked_up_by() != hand: + return {"ok": false, "detail": "%s is held by %s, not our hand. %s" + % [label, item.get_picked_up_by(), view.diag(item, hand)]} + # Grabbing is predicted locally and confirmed by the server handing us the + # object's NetXform. Until that lands the server is still driving it, so + # waiting here is what makes the following carry meaningful. + report.log_line(" holding %s; waiting for the server to hand over NetXform..." % label) + if not await wait_until(func(): return view.xform_authority(item) == multiplayer.get_unique_id(), + "NetXform handoff", 5.0): + return {"ok": false, "detail": "grabbed %s, but NetXform authority stayed with peer %d. %s" + % [label, view.xform_authority(item), view.diag(item, hand)]} + report.log_line(" NetXform is ours (peer %d)" % multiplayer.get_unique_id()) + return {"ok": true, "detail": "grabbed %s via %s; %s" % [label, closest.name, view.diag(item, hand)]} + + +func drop(item: Node3D, label: String) -> Dictionary: + if not is_instance_valid(item): + return {"ok": false, "detail": "'%s' does not exist on this peer" % label} + if not item.is_picked_up(): + return {"ok": false, "detail": "nothing to drop: %s is not held. %s" % [label, view.diag(item, hand)]} + report.log_line(" releasing grip (held by %s)" % item.get_picked_up_by()) + hand._on_grip_release() + await wait_frames(8) + if not is_instance_valid(item): + return {"ok": true, "detail": "%s was consumed on release" % label} + # Explicitly typed: `item` is a Node3D here, so get_picked_up_by()'s return + # type is not known statically and := cannot infer it. + var by: Node = item.get_picked_up_by() + report.log_line(" after release %s is held by %s" % [label, by]) + if by == hand: + return {"ok": false, "detail": "grip released but our hand still holds %s" % label} + # A station catching the object on release is intended — but only on the peer + # that owns world logic. A client's own snap zone doing it means that peer is + # running station logic it has no authority for. + if by is XRToolsSnapZone and not NetworkManager.owns_world(): + return {"ok": false, "detail": "%s on this client grabbed %s out of our hand; station snap zones must only run on the world owner (zone enabled=%s)" + % [by.get_parent().name, label, by.enabled]} + if not await wait_until(func(): return not is_instance_valid(item) or view.xform_authority(item) == 1, + "NetXform to return to the server", 5.0): + return {"ok": false, "detail": "dropped %s, but NetXform authority stayed with peer %d" + % [label, view.xform_authority(item)]} + return {"ok": true, "detail": "dropped %s (now held by %s)" % [label, by]} + + +## Grab an object, carry it onto a station's snap zone, and let go there. +func place_in_zone(item: Node3D, label: String, station: String) -> Dictionary: + var zone := view.zone_of(station) + if not zone: + return {"ok": false, "detail": "station '%s' has no snap zone on this peer" % station} + var res := await grab(item, label) + if not res["ok"]: + return res + res = await carry_to(item, label, zone.global_position) + if not res["ok"]: + return res + res = await drop(item, label) + if not res["ok"]: + return res + report.log_line(" waiting for %s to settle onto %s..." % [label, station]) + await wait_until(func(): return not is_instance_valid(item) \ + or item.global_position.distance_to(zone.global_position) <= SNAP_TOLERANCE, + "%s to settle onto %s" % [label, station], 5.0) + return {"ok": true, "detail": "placed %s into %s; %s" % [label, station, view.diag(item, hand)]} + + +## Grab an object and carry it into another, holding it there. Used for the +## combine (buns into the cooked burger) and for putting food on a plate, both of +## which are triggered by an Area3D overlap rather than by dropping. +func carry_item_to_item(item: Node3D, label: String, target: Node3D, target_label: String) -> Dictionary: + if not is_instance_valid(target): + return {"ok": false, "detail": "target '%s' does not exist on this peer" % target_label} + var target_pos := target.global_position + var res := await grab(item, label) + if not res["ok"]: + return res + res = await carry_to(item, label, target_pos) + if not res["ok"] and is_instance_valid(item): + return res + # Hold it there a moment: the reaction happens on the server, and the object + # we are holding may be consumed by it. + for i in 60: + if not is_instance_valid(item): + report.log_line(" %s was consumed (the reaction fired)" % label) + return {"ok": true, "detail": "%s consumed on contact with %s" % [label, target_label]} + await get_tree().physics_frame + # Both uses of this consume the carried object, so still holding it means the + # reaction never fired. Let go first, so the next step is not left fighting + # our hand. + if is_instance_valid(item) and item.is_picked_up(): + hand._on_grip_release() + await wait_frames(8) + return {"ok": false, "detail": "%s reached %s but was never consumed - the reaction did not fire; %s" + % [label, target_label, view.diag(item, hand)]} + + +## Carry an object somewhere clear and put it down, freeing the station it was in. +func park(item: Node3D, label: String, pos: Vector3) -> Dictionary: + var res := await grab(item, label) + if not res["ok"]: + return res + res = await carry_to(item, label, pos) + if not res["ok"]: + return res + return await drop(item, label) + + +## Move the held object onto a world position. Closed-loop: the hand moves by +## whatever the object's remaining error is, since the grab point offsets the +## object from the hand by an amount not worth hard-coding. +func carry_to(item: Node3D, label: String, target: Vector3) -> Dictionary: + if not is_instance_valid(item) or not item.is_picked_up(): + return {"ok": false, "detail": "cannot carry: %s is not held" % label} + report.log_line(" carrying %s from %s to %s" % [label, item.global_position, target]) + for i in 120: + if not is_instance_valid(item): + return {"ok": true, "detail": "%s was consumed while being carried" % label} + var err := item.global_position - target + if err.length() <= 0.01: + break + controller.global_position -= err + await get_tree().physics_frame + await get_tree().physics_frame + if not is_instance_valid(item): + return {"ok": true, "detail": "%s was consumed while being carried" % label} + var dist := item.global_position.distance_to(target) + report.log_line(" %s is now %.3fm from the target" % [label, dist]) + if dist > 0.05: + return {"ok": false, "detail": "could not carry %s to the target: still %.3fm away" % [label, dist]} + return {"ok": true, "detail": "carried %s to within %.3fm" % [label, dist]} + + +## Wait for a station to produce an object with the given food id (cooking the +## burger, or combining into a hamburger). Server-side: stations only run there. +func await_food(food_id: String) -> Dictionary: + report.log_line(" waiting for a '%s' to appear..." % food_id) + var ok := await wait_until(func(): return view.find_by_food_id(food_id) != null, + "a '%s' to be produced" % food_id, STATION_WORK_TIMEOUT) + if not ok: + return {"ok": false, "detail": "no '%s' was produced within %.0fs" % [food_id, STATION_WORK_TIMEOUT]} + # Let the spawn replicate before the checks that follow go looking for it. + await wait_frames(30) + var made := view.find_by_food_id(food_id) + return {"ok": true, "detail": "'%s' produced: %s at %s" % [food_id, made.name, made.global_position]} + + +func await_clean(plate_name: String) -> Dictionary: + var plate := view.find(plate_name) + if not plate: + return {"ok": false, "detail": "'%s' does not exist on this peer" % plate_name} + var pc := plate.get_node_or_null("PlateController") + report.log_line(" waiting for the sink to wash %s (dirty=%s)..." % [plate_name, pc.is_dirty if pc else "?"]) + var ok := await wait_until(func(): return pc and not pc.is_dirty, + "the sink to wash the plate", STATION_WORK_TIMEOUT) + await wait_frames(30) + if not ok: + return {"ok": false, "detail": "%s was still dirty after %.0fs in the sink; %s" + % [plate_name, STATION_WORK_TIMEOUT, view.diag(plate, hand)]} + return {"ok": true, "detail": "%s was washed clean" % plate_name} diff --git a/test/mp_steps.gd.uid b/test/mp_steps.gd.uid new file mode 100644 index 0000000..fa1087e --- /dev/null +++ b/test/mp_steps.gd.uid @@ -0,0 +1 @@ +uid://cnwwp8f22wwk5 diff --git a/test/mp_test_driver.gd b/test/mp_test_driver.gd index 0df44a1..c03dca8 100644 --- a/test/mp_test_driver.gd +++ b/test/mp_test_driver.gd @@ -1,63 +1,64 @@ extends Node -## Multiplayer debug harness for the kitchen flow, living in -## test/multiPlayerTest.tscn. +## Multiplayer harness for the kitchen flow, living in test/multiPlayerTest.tscn +## (and, inert unless asked for, in Scenes/multiPlayer.tscn). +## +## This file is the orchestration only — the scripted sequence, the RPC plumbing +## between the two peers, and the manual keyboard controls. The work itself lives +## in four modules, each with one job: +## +## MpWorldView finding things in the world and describing what they are doing +## MpSteps the simulated player actions (reach, grab, carry, drop) +## MpAsserts the per-step checks +## MpSnapshot the cross-peer sync audit +## MpReport the ledger, the log, the overlay, the screenshots ## ## Two ways to use it: ## -## AUTOMATIC — pass `--mptest` and the server runs the whole scripted sequence -## and exits non-zero if any check fails. test/run_mp_test.ps1 does this -## headlessly; test/run_mp_test_windowed.ps1 does it in two visible windows with -## a pause between steps so you can watch it happen. +## AUTOMATIC — pass `--mptest` and the server runs the whole sequence and exits +## non-zero if any check fails. test/run_mp_test.ps1 does this headlessly; +## test/run_mp_test_windowed.ps1 does it in two visible windows with a pause +## between steps so you can watch it happen. ## -## MANUAL — just run the scene (no `--mptest`). Every window gets an on-screen -## overlay, a fixed camera over the kitchen, and keyboard controls: -## -## H / J host / join 127.0.0.1 -## 1 grab the plate 2 drop it -## 3 plate -> dirt station 4 plate -> sink -## 5 raw burger -> hob 6 cooked burger -> counter -## 7 buns -> cooked burger (combine) -## 8 plate -> counter 2 9 hamburger -> plate -## R run the whole automatic sequence (server only) -## 0 dump state C toggle camera -## -## Keys act on the peer whose window has focus, so you can do a step on the -## client and watch the server window follow (or fail to). +## MANUAL — just run the scene (no `--mptest`). Every window gets an overlay, a +## fixed camera over the kitchen, and keyboard controls. Keys act on the peer +## whose window has focus, so you can do a step on the client and watch the +## server window follow (or fail to). ## ## The scripted sequence: ## 1. client grabs the plate, then drops it ## 2. server grabs the plate, then drops it ## 3. client carries it to the dirt station -> snaps + turns dirty on both ## 4. both peers confirm they can still pick it up -## 5. client carries the dirty plate to the sink -> gets washed clean on both +## 5. client carries the dirty plate to the sink -> washed clean on both ## 6. a cook-and-plate round, run once by the CLIENT and once by the SERVER: -## raw burger -> hob (cooks into a cooked burger, raw one removed), -## cooked burger -> counter, buns -> cooked burger (combines into a -## hamburger), plate -> counter 2, hamburger -> plate. +## raw burger -> hob (cooks, raw one removed), cooked burger -> counter, +## buns -> cooked burger (combines into a hamburger), plate -> counter 2, +## hamburger -> plate. ## How long the server waits for a client step reply before calling it failed. const STEP_TIMEOUT_SEC := 30.0 -## How long to wait for the client to connect and for the plate to replicate. +## How long to wait for the client to connect and for the world to replicate. const SETUP_TIMEOUT_SEC := 30.0 -## Distance under which an item counts as "at" a snap zone. -const SNAP_TOLERANCE := 0.12 -## Cooking and washing both take ~3s of station time; allow generously for it. -const STATION_WORK_TIMEOUT := 20.0 -## Lines kept in the on-screen overlay. Enough to show a whole step, without the -## panel eating the view of the kitchen underneath it. -const OVERLAY_LINES := 11 -## Where the debug camera sits and what it aims at: a fixed vantage point that -## frames the whole kitchen (Counter2 at x=-2 through DirtStation at x=2). +## Where the debug camera sits and what it aims at: a fixed vantage point framing +## the whole kitchen (Counter2 at x=-2 through DirtStation at x=2). const DEBUG_CAM_POS := Vector3(0.0, 2.1, 3.4) const DEBUG_CAM_LOOK_AT := Vector3(0.0, 0.9, 0.0) const HELP := "[H]ost [J]oin 1 grab 2 drop 3 dirt 4 sink 5 hob 6 counter 7 combine 8 plate>counter2 9 >plate R run-all A sync-audit 0 dump C cam" -var _log_file: FileAccess -var _log_path := "" +var _view: MpWorldView +var _steps: MpSteps +var _asserts: MpAsserts +var _snapshot: MpSnapshot +var _report: MpReport + +var _world: Node3D +var _controller: Node3D +var _hand: XRToolsFunctionPickup var _debug_cam: Camera3D + var _role := "?" var _client_id := 0 var _auto_mode := false @@ -66,59 +67,59 @@ var _step_pause := 0.0 var _end_hold := 0.0 var _step_no := 0 -# Server-side ledger of every check: {step, side, ok, detail} -var _results: Array[Dictionary] = [] -# Latest reply from the client, consumed by _remote(). +## Latest reply from the client, consumed by _remote(). var _reply: Dictionary = {} - -var _world: Node3D -var _controller: Node3D -var _hand: XRToolsFunctionPickup -var _hand_detached := false - -var _overlay: Label -var _overlay_lines: Array[String] = [] - -# Per-step screenshots, later stitched into a side-by-side GIF of both peers. -var _frames_enabled := false -var _frames_dir := "" -var _frame_index := 0 +var _client_snapshot: Dictionary = {} +var _snapshot_pending := false func _ready() -> void: var args := OS.get_cmdline_user_args() _auto_mode = "--mptest" in args # Opt-in only. This node also sits in the real multiplayer scene (so a client - # joining a test session has a driver), and must be completely inert during - # an ordinary game — no overlay, no debug camera, no keyboard hooks. + # joining a test session has a driver), and must be completely inert during an + # ordinary game — no overlay, no debug camera, no keyboard hooks. if not _auto_mode and not ("--mptest-manual" in args): queue_free() return - _frames_enabled = "--mptest-frames" in args _step_pause = _arg_value(args, "--mptest-pause", 0.0) _end_hold = _arg_value(args, "--mptest-hold", 0.0) _world = get_parent() - _open_log() - _build_overlay() + await get_tree().process_frame _refresh_role() - _log("=== mp test driver ready (role=%s, peer=%d, mode=%s) ===" + _build_modules(_role == "server") + _report.setup_frames("--mptest-frames" in args, _role == "server") + _report.log_line("=== mp test driver ready (role=%s, peer=%d, mode=%s) ===" % [_role, multiplayer.get_unique_id(), "automatic" if _auto_mode else "manual"]) - # await: _resolve_nodes now waits for the server's spawns to arrive. + if not await _resolve_nodes(): if _auto_mode: _finish(false) return _build_debug_camera() - _setup_frames() if not _auto_mode: - _log("MANUAL MODE - keys act on this window's peer:") - _log(" " + HELP) + _report.log_line("MANUAL MODE - keys act on this window's peer:") + _report.log_line(" " + HELP) return if _role == "server": await _run_server() +func _build_modules(is_server: bool) -> void: + _report = MpReport.new() + add_child(_report) + _report.setup(is_server, _world) + + _view = MpWorldView.new() + add_child(_view) + _view.setup(_world, _report) + + _snapshot = MpSnapshot.new() + add_child(_snapshot) + _snapshot.setup(_view, _report) + + func _arg_value(args: PackedStringArray, key: String, fallback: float) -> float: var i := args.find(key) if i >= 0 and i + 1 < args.size(): @@ -130,96 +131,54 @@ func _refresh_role() -> void: _role = "server" if NetworkManager.is_server() else ("client" if NetworkManager.is_online() else "offline") -# Only the hand is resolved up front. Everything else is looked up by name at -# use time, because items get consumed and respawned as the test runs (the raw -# burger becomes a cooked burger, which becomes a hamburger, which is absorbed -# into a plate) — caching node references would leave us holding freed objects. +## Only the hand is resolved up front; everything else is looked up by name at +## use time (see MpWorldView). func _resolve_nodes() -> bool: _controller = _world.get_node_or_null("XROrigin3D/XRControllerRightHand") as Node3D _hand = _controller.get_node_or_null("FunctionPickup") as XRToolsFunctionPickup if _controller else null if not _hand: - _log("FATAL: could not resolve XROrigin3D/XRControllerRightHand/FunctionPickup") + _report.log_line("FATAL: could not resolve XROrigin3D/XRControllerRightHand/FunctionPickup") return false - # The kitchen is no longer baked into the live scene: the server harvests the + + _steps = MpSteps.new() + add_child(_steps) + _steps.setup(_view, _report, _hand, _controller) + _asserts = MpAsserts.new() + add_child(_asserts) + _asserts.setup(_view, _snapshot, _hand) + + # The kitchen is not baked into the live scene: the server harvests the # authored nodes and respawns them replicated, so on a client nothing exists # until those spawns arrive. Wait for them rather than failing immediately. for required in ["Hob", "Sink", "DirtStation", "Counter", "Counter2", "Plate"]: - if not await _wait_until(func(): return _find(required) != null, + if not await _steps.wait_until(func(): return _view.find(required) != null, "'%s' to arrive from the server" % required, SETUP_TIMEOUT_SEC): - _log("FATAL: '%s' never appeared in the world" % required) + _report.log_line("FATAL: '%s' never appeared in the world" % required) return false - _log("resolved hand=%s; kitchen has Hob, Sink, DirtStation, Counter, Counter2" % _hand.get_path()) - _disable_despawn_timers() + _report.log_line("resolved hand=%s; kitchen has Hob, Sink, DirtStation, Counter, Counter2" % _hand.get_path()) + _view.disable_despawn_timers() return true -# The test deliberately leaves items sitting still for minutes at a time, which -# DespawningItem would treat as litter and remove (it took the raw burger out -# before the client had even connected). Hold them indefinitely instead, so the -# run tests the kitchen rather than the despawn timer. -func _disable_despawn_timers() -> void: - var stopped := 0 - for node in _world.find_children("*", "DespawningItem", true, false): - if _despawn_timers_seen.has(node.get_instance_id()): - continue - _despawn_timers_seen[node.get_instance_id()] = true - node.set_process(false) - stopped += 1 - if stopped > 0: - _log("disabled %d DespawningItem timer(s) so test items don't vanish mid-run" % stopped) - - -# Items appear as the run goes on (cooking and combining spawn new ones), so -# this is re-checked before every step rather than only at startup. -var _despawn_timers_seen := {} - - -# Items live either baked in the scene root or, once spawned at runtime, under -# WorldContent. Look in both. -func _find(name: String) -> Node3D: - var n := _world.get_node_or_null(name) - if not n: - n = _world.get_node_or_null("WorldContent/" + name) - return n as Node3D - - -func _zone_of(station_name: String) -> XRToolsSnapZone: - var s := _find(station_name) - return s.get_node_or_null("XRToolsSnapZone") as XRToolsSnapZone if s else null - - -# Cooking and combining spawn their results with engine-assigned names, so the -# only stable way to find them is by the food id they carry. -func _find_by_food_id(id: String) -> Node3D: - for root in [_world, _world.get_node_or_null("WorldContent")]: - if not root: - continue - for child in root.get_children(): - var f := child.get_node_or_null("FoodItem") as FoodItem - if f and f.id == id and is_instance_valid(child): - return child as Node3D - return null - - -# --- Server orchestration -------------------------------------------------- +# --- server orchestration -------------------------------------------------- func _run_server() -> void: _running = true - _results.clear() + _report.results.clear() _step_no = 0 if not await _wait_for_client(): _running = false if _auto_mode: _finish(false) return - await _wait_frames(60) - _banner("starting sequence") + await _steps.wait_frames(60) + _report.banner("starting sequence") # A frame of the untouched kitchen, so the GIF opens on the starting state. await _capture_step_frame("start") # 0. The client opened a different, empty scene, so everything it has must - # have arrived over the network. Check that before touching anything — this - # is the same path a player joining mid-session takes. + # have arrived over the network. Check that before touching anything — this is + # the same path a player joining mid-session takes. await _step("server", "world_replicated_to_client", "verify_world_replicated", []) # 1-2. Both peers can pick the plate up and put it down. @@ -247,41 +206,37 @@ func _run_server() -> void: await _both("plate_washed_clean", "verify_dirty", ["Plate", "false"]) await _both("sink_bar_hidden_when_done", "verify_station_bar", ["Sink", "false"]) - # 6. The cook-and-plate round, once per peer. The first round uses the items + # 6. The cook-and-plate round, once per peer. The first round uses the objects # baked into the scene; the second uses freshly spawned ones, so both paths - # through the spawner get covered. - # Finished plates are parked well clear of every snap zone (all the stations - # sit on z=0), so they can't get re-snapped on the way down. + # through the spawner get covered. Finished plates are parked well clear of + # every snap zone (all the stations sit on z=0), so they cannot get re-snapped + # on the way down. await _cook_and_plate_round("client", "raw_burger", "BurgerBuns", "Plate", Vector3(-2.0, 1.1, 1.5)) await _spawn_round_items() await _cook_and_plate_round("server", "RawBurger2", "BurgerBuns2", "Plate2", Vector3(-1.0, 1.1, 1.5)) _running = false - await _report() + await _finish_run() -# One full food round performed by `actor`: cook a burger, combine it with buns -# on the counter, and put the result on a plate that's sitting on another -# counter. Every result is checked on BOTH peers, since the whole point is that -# the server's authoritative outcome reaches the client. +## One full food round performed by `actor`: cook a burger, combine it with buns +## on the counter, and put the result on a plate sitting on another counter. +## Every result is checked on BOTH peers, since the whole point is that the +## server's authoritative outcome reaches the client. func _cook_and_plate_round(actor: String, burger: String, buns: String, plate: String, park_at: Vector3) -> void: - _banner("%s's cook-and-plate round (%s + %s -> %s)" % [actor, burger, buns, plate]) + _report.banner("%s's cook-and-plate round (%s + %s -> %s)" % [actor, burger, buns, plate]) # Burger onto the hob; it should cook and the raw one should disappear. await _step(actor, "%s_burger_to_hob" % actor, "place_in_zone", [burger, "Hob"]) await _both("%s_burger_snapped_in_hob" % actor, "verify_snapped", [burger, "Hob"]) await _both("%s_hob_bar_shown_while_cooking" % actor, "verify_station_bar", ["Hob", "true"]) await _step("server", "%s_wait_for_cook" % actor, "await_food", ["cooked_burger"]) - - # Get it off the hob before anything else: the hob keeps cooking whatever is - # in it, and a cooked burger left there burns to charcoal in another 2s — - # which would blow up the run as soon as there's any pause between steps. - await _step(actor, "%s_cooked_to_counter" % actor, "place_food_in_zone", ["cooked_burger", "Counter"]) await _both("%s_raw_burger_removed" % actor, "verify_gone", [burger]) await _both("%s_cooked_burger_exists" % actor, "verify_food_exists", ["cooked_burger"]) - await _both("%s_hob_bar_hidden_when_empty" % actor, "verify_station_bar", ["Hob", "false"]) - # Now bring the buns to it to combine. + # Cooked burger onto the counter, then buns into it: they combine. + await _step(actor, "%s_cooked_to_counter" % actor, "place_food_in_zone", ["cooked_burger", "Counter"]) + await _both("%s_hob_bar_hidden_when_empty" % actor, "verify_station_bar", ["Hob", "false"]) await _step(actor, "%s_buns_to_cooked" % actor, "carry_food_to_food", [buns, "cooked_burger"]) await _step("server", "%s_wait_for_combine" % actor, "await_food", ["hamburger"]) await _both("%s_ingredients_consumed" % actor, "verify_gone", [buns]) @@ -292,24 +247,22 @@ func _cook_and_plate_round(actor: String, burger: String, buns: String, plate: S await _both("%s_plate_snapped_on_counter2" % actor, "verify_snapped", [plate, "Counter2"]) await _step(actor, "%s_hamburger_to_plate" % actor, "carry_food_to_item", ["hamburger", plate]) await _both("%s_plate_holds_hamburger" % actor, "verify_plate_contains", [plate, "hamburger"]) - - # Take the finished plate away again, the way a player would carry it off to - # be served. Without this the counter stays occupied and the next round has - # nowhere to put its plate. await _both("%s_food_on_plate_before_lift" % actor, "verify_plate_visuals", [plate]) + + # Lift the plate off the counter and set it down clear of every station. await _step(actor, "%s_plate_off_counter2" % actor, "park", [plate, park_at]) await _both("%s_counter2_freed" % actor, "verify_zone_empty", ["Counter2"]) - # The food must still be on the plate after it has been carried off the - # counter and set down again. + # The food must still be on the plate after being carried off and set down. await _both("%s_food_stayed_on_plate" % actor, "verify_plate_visuals", [plate]) -# Spawn a second set of ingredients through NetworkManager for the server's -# round (the scene only bakes one of each). +## A second set of ingredients for the server's round (the scene bakes only one +## of each), spawned through the normal path so the runtime-spawn case is covered +## as well as the authored one. func _spawn_round_items() -> void: - _banner("state between rounds (server's view)") - _dump_state() - _banner("spawning a second set of ingredients for the server's round") + _report.banner("state between rounds (server's view)") + _view.dump_state(MpSnapshot.WATCHED_STATIONS, _hand) + _report.banner("spawning a second set of ingredients for the server's round") var spawns := [ ["res://Items/burger.tscn", "RawBurger2", Vector3(0.3, 1.05, 0.7)], ["res://Items/BurgerBuns.tscn", "BurgerBuns2", Vector3(-0.4, 1.05, 0.7)], @@ -317,15 +270,16 @@ func _spawn_round_items() -> void: ] for s in spawns: NetworkManager.spawn_item(s[0], Transform3D(Basis(), s[2]), s[1]) - _log(" spawned %s" % s[1]) - await _wait_frames(30) + _report.log_line(" spawned %s" % s[1]) + await _steps.wait_frames(30) func _wait_for_client() -> bool: - var ok := await _wait_until(func(): return _find_client_id() != 0, "client to connect", SETUP_TIMEOUT_SEC) + var ok := await _steps.wait_until(func(): return _find_client_id() != 0, + "client to connect", SETUP_TIMEOUT_SEC) _client_id = _find_client_id() if ok: - _log("client connected: peer %d" % _client_id) + _report.log_line("client connected: peer %d" % _client_id) return ok @@ -336,31 +290,31 @@ func _find_client_id() -> int: return 0 -# Run one step as `actor` (locally if that's us, over RPC if it's the client) -# and record the verdict. +## Run one step as `actor` (locally if that is us, over RPC if it is the client) +## and record the verdict. func _step(actor: String, label: String, step: String, args: Array) -> void: - _current_step = label - _disable_despawn_timers() - _banner("STEP %d: %s (on the %s)" % [_next_step_no(), label, actor.to_upper()]) + _snapshot.current_step = label + _view.disable_despawn_timers() + _report.banner("STEP %d: %s (on the %s)" % [_next_step_no(), label, actor.to_upper()]) var res: Dictionary if actor == "server": res = await _run_local_step(step, args) else: res = await _remote(step, args) - _record(label, actor, res) + _report.record(label, actor, res) await _audit_sync(label) await _capture_step_frame(label) await _pause() -# Run the same check on both peers - the server's state and the client's must -# agree, which is the whole point of the exercise. +## Run the same check on both peers — the server's state and the client's must +## agree, which is the whole point of the exercise. func _both(label: String, step: String, args: Array) -> void: - _current_step = label - _disable_despawn_timers() - _banner("STEP %d: %s (checked on BOTH peers)" % [_next_step_no(), label]) - _record(label, "server", await _run_local_step(step, args)) - _record(label, "client", await _remote(step, args)) + _snapshot.current_step = label + _view.disable_despawn_timers() + _report.banner("STEP %d: %s (checked on BOTH peers)" % [_next_step_no(), label]) + _report.record(label, "server", await _run_local_step(step, args)) + _report.record(label, "client", await _remote(step, args)) await _audit_sync(label) await _capture_step_frame(label) await _pause() @@ -387,79 +341,34 @@ func _pause() -> void: await get_tree().create_timer(_step_pause).timeout -func _record(step: String, side: String, res: Dictionary) -> void: - var ok: bool = res.get("ok", false) - var detail: String = res.get("detail", "") - _results.append({"step": step, "side": side, "ok": ok, "detail": detail}) - _log("%s [%s] %s" % ["PASS" if ok else "FAIL", side, step]) - _log(" %s" % detail) - - -func _report() -> void: - var failed := 0 - _banner("RESULTS") - for r in _results: - if not r["ok"]: - failed += 1 - _log("%-4s %-8s %s" % ["PASS" if r["ok"] else "FAIL", r["side"], r["step"]]) - _log("%d/%d checks passed" % [_results.size() - failed, _results.size()]) - for r in _results: - if not r["ok"]: - _log("FAILURE %s [%s]: %s" % [r["step"], r["side"], r["detail"]]) +func _finish_run() -> void: + _report.print_summary() await _capture_step_frame("final") - _write_frame_index() - _write_report(failed) + _report.write_frame_index() + _report.write_report() if not _auto_mode: return _quit_client.rpc_id(_client_id) if _end_hold > 0.0: - _log("holding for %.0fs so you can look at the final state..." % _end_hold) + _report.log_line("holding for %.0fs so you can look at the final state..." % _end_hold) await get_tree().create_timer(_end_hold).timeout else: - await _wait_frames(30) - _finish(failed == 0) + await _steps.wait_frames(30) + _finish(_report.failed_count() == 0) -# A standalone report of the run, written next to the logs so it can be read -# without scrolling the console — and so the in-editor runner can print it back. -func _write_report(failed: int) -> void: - var path := "res://logs/mptest_report.txt" - var f := FileAccess.open(path, FileAccess.WRITE) - if not f: - return - var passed := _results.size() - failed - f.store_line("VRyHungry multiplayer test report") - f.store_line("run at %s" % Time.get_datetime_string_from_system()) - f.store_line("") - f.store_line("RESULT: %s (%d passed, %d failed, %d total)" - % ["ALL CHECKS PASSED" if failed == 0 else "FAILED", passed, failed, _results.size()]) - f.store_line("") - if failed > 0: - f.store_line("--- failures ---") - for r in _results: - if not r["ok"]: - f.store_line("FAIL [%s] %s" % [r["side"], r["step"]]) - f.store_line(" %s" % r["detail"]) - f.store_line("") - f.store_line("--- every check, in order ---") - for r in _results: - f.store_line("%-4s %-6s %s" % ["PASS" if r["ok"] else "FAIL", r["side"], r["step"]]) - f.close() - _log("report written to %s" % ProjectSettings.globalize_path(path)) - - -# --- Client command handling ---------------------------------------------- +# --- client command handling ---------------------------------------------- @rpc("authority", "reliable") func _cmd(step: String, args: Array) -> void: - _current_step = step - _disable_despawn_timers() - _log("<- server: %s%s" % [step, args]) + _snapshot.current_step = step + _view.disable_despawn_timers() + _report.log_line("<- server: %s%s" % [step, args]) _running = true var res := await _run_local_step(step, args) _running = false - _log("%s %s" % ["PASS" if res.get("ok") else "FAIL", step]) - _log(" %s" % res.get("detail")) + _report.log_line("%s %s" % ["PASS" if res.get("ok") else "FAIL", step]) + _report.log_line(" %s" % res.get("detail")) _result.rpc_id(1, step, res.get("ok", false), str(res.get("detail", ""))) @@ -470,7 +379,7 @@ func _result(step: String, ok: bool, detail: String) -> void: @rpc("authority", "reliable") func _quit_client() -> void: - _write_frame_index() + _report.write_frame_index() if _end_hold > 0.0: await get_tree().create_timer(_end_hold).timeout _finish(true) @@ -479,523 +388,51 @@ func _quit_client() -> void: func _run_local_step(step: String, args: Array) -> Dictionary: match step: "grab": - return await _do_grab(_find(args[0]), args[0]) + return await _steps.grab(_view.find(args[0]), args[0]) "drop": - return await _do_drop(_find(args[0]), args[0]) + return await _steps.drop(_view.find(args[0]), args[0]) "place_in_zone": - return await _do_place_in_zone(_find(args[0]), args[0], args[1]) + return await _steps.place_in_zone(_view.find(args[0]), args[0], args[1]) "place_food_in_zone": - return await _do_place_in_zone(_find_by_food_id(args[0]), args[0], args[1]) + return await _steps.place_in_zone(_view.find_by_food_id(args[0]), args[0], args[1]) "carry_food_to_food": - return await _do_carry_item_to_item(_find(args[0]), args[0], _find_by_food_id(args[1]), args[1]) + return await _steps.carry_item_to_item( + _view.find(args[0]), args[0], _view.find_by_food_id(args[1]), args[1]) "carry_food_to_item": - return await _do_carry_item_to_item(_find_by_food_id(args[0]), args[0], _find(args[1]), args[1]) + return await _steps.carry_item_to_item( + _view.find_by_food_id(args[0]), args[0], _view.find(args[1]), args[1]) "await_food": - return await _do_await_food(args[0]) + return await _steps.await_food(args[0]) "await_clean": - return await _do_await_clean(args[0]) + return await _steps.await_clean(args[0]) "park": - return await _do_park(_find(args[0]), args[0], args[1]) + return await _steps.park(_view.find(args[0]), args[0], args[1]) "verify_snapped": - return _check_snapped(args[0], args[1]) + return _asserts.snapped(args[0], args[1]) "verify_dirty": - return _check_dirty(args[0], args[1] == "true") + return _asserts.dirty(args[0], args[1] == "true") "verify_gone": - return _check_gone(args[0]) + return _asserts.gone(args[0]) "verify_food_exists": - return _check_food_exists(args[0]) + return _asserts.food_exists(args[0]) "verify_plate_contains": - return _check_plate_contains(args[0], args[1]) + return _asserts.plate_contains(args[0], args[1]) "verify_plate_visuals": - return _check_plate_visuals(args[0]) + return _asserts.plate_visuals(args[0]) "verify_station_bar": - return _check_station_bar(args[0], args[1] == "true") + return _asserts.station_bar(args[0], args[1] == "true") "verify_zone_empty": - return _check_zone_empty(args[0]) + return _asserts.zone_empty(args[0]) "verify_world_replicated": return await _check_world_replicated() return {"ok": false, "detail": "unknown step %s" % step} -# --- The simulated player actions ----------------------------------------- - -# Reach out to an item and squeeze the grip, the same way the real controller -# path does: position the hand, let the grab Area3D register what's in range, -# refresh the closest-object pick (normally done from _process, which bails out -# headlessly because the controller reports as untracked), then press grip. -func _do_grab(item: Node3D, label: String) -> Dictionary: - if not is_instance_valid(item): - return {"ok": false, "detail": "'%s' does not exist on this peer" % label} - _log(" reaching for %s at %s" % [label, item.global_position]) - _move_hand_to(item.global_position) - await _wait_frames(4) - _hand._update_closest_object() - var closest := _hand.closest_object - _log(" hand at %s, closest grabbable = %s" % [_hand.global_position, closest]) - if not is_instance_valid(closest): - return {"ok": false, "detail": "hand found nothing to grab. %s" % _diag(item)} - _log(" pressing grip") - _hand._on_grip_pressed() - await _wait_frames(4) - if not item.is_picked_up(): - return {"ok": false, "detail": "grip pressed on %s but %s not picked up. %s" - % [closest.name, label, _diag(item)]} - if item.get_picked_up_by() != _hand: - return {"ok": false, "detail": "%s is held by %s, not our hand. %s" - % [label, item.get_picked_up_by(), _diag(item)]} - _log(" holding %s; waiting for authority..." % label) - if not await _wait_until(func(): return _xform_authority(item) == multiplayer.get_unique_id(), - "authority handoff", 5.0): - return {"ok": false, "detail": "grabbed %s, but NetXform authority stayed with peer %d. %s" - % [label, _xform_authority(item), _diag(item)]} - _log(" authority is ours (peer %d)" % multiplayer.get_unique_id()) - return {"ok": true, "detail": "grabbed %s via %s; %s" % [label, closest.name, _diag(item)]} - - -func _do_drop(item: Node3D, label: String) -> Dictionary: - if not is_instance_valid(item): - return {"ok": false, "detail": "'%s' does not exist on this peer" % label} - if not item.is_picked_up(): - return {"ok": false, "detail": "nothing to drop: %s is not held. %s" % [label, _diag(item)]} - _log(" releasing grip (held by %s)" % item.get_picked_up_by()) - _hand._on_grip_release() - await _wait_frames(8) - if not is_instance_valid(item): - return {"ok": true, "detail": "%s was consumed on release" % label} - # Explicitly typed: `item` is a Node3D here, so the return type of - # get_picked_up_by() isn't known statically and := can't infer it. - var by: Node = item.get_picked_up_by() - _log(" after release %s is held by %s" % [label, by]) - if by == _hand: - return {"ok": false, "detail": "grip released but our hand still holds %s" % label} - # A station catching the item on release is intended - but only on the peer - # that owns world logic. A client's own snap zone doing it means that peer is - # running station logic it has no authority for. - if by is XRToolsSnapZone and not NetworkManager.owns_world(): - return {"ok": false, "detail": "%s on this client grabbed %s out of our hand; station snap zones must only run on the world owner (zone enabled=%s snap_mode=%d processing=%s in_grab_area=%d)" - % [by.get_parent().name, label, by.enabled, by.snap_mode, - by.is_processing(), by._object_in_grab_area.size()]} - if not await _wait_until(func(): return not is_instance_valid(item) or _xform_authority(item) == 1, - "authority return to server", 5.0): - return {"ok": false, "detail": "dropped %s, but NetXform authority stayed with peer %d" - % [label, _xform_authority(item)]} - return {"ok": true, "detail": "dropped %s (now held by %s)" % [label, by]} - - -# Grab an item, carry it onto a station's snap zone, and let go there. -func _do_place_in_zone(item: Node3D, label: String, station: String) -> Dictionary: - var zone := _zone_of(station) - if not zone: - return {"ok": false, "detail": "station '%s' has no snap zone on this peer" % station} - var res := await _do_grab(item, label) - if not res["ok"]: - return res - res = await _do_carry_to(item, label, zone.global_position) - if not res["ok"]: - return res - res = await _do_drop(item, label) - if not res["ok"]: - return res - _log(" waiting for %s to settle onto %s..." % [label, station]) - await _wait_until(func(): return not is_instance_valid(item) \ - or item.global_position.distance_to(zone.global_position) <= SNAP_TOLERANCE, - "%s to settle onto %s" % [label, station], 5.0) - return {"ok": true, "detail": "placed %s into %s; %s" % [label, station, _diag(item)]} - - -# Grab an item and carry it into another item, holding it there. Used for the -# combine (buns into the cooked burger) and for putting food on a plate, both of -# which are triggered by an Area3D overlap rather than by dropping. -func _do_carry_item_to_item(item: Node3D, label: String, target: Node3D, target_label: String) -> Dictionary: - if not is_instance_valid(target): - return {"ok": false, "detail": "target '%s' does not exist on this peer" % target_label} - var target_pos := target.global_position - var res := await _do_grab(item, label) - if not res["ok"]: - return res - res = await _do_carry_to(item, label, target_pos) - if not res["ok"] and is_instance_valid(item): - return res - # Hold it there a moment: the reaction happens on the server, and the item - # we're holding may be consumed by it. - for i in 60: - if not is_instance_valid(item): - _log(" %s was consumed (the reaction fired)" % label) - return {"ok": true, "detail": "%s consumed on contact with %s" % [label, target_label]} - await get_tree().physics_frame - # Both uses of this (combining, and putting food on a plate) consume the - # carried item, so still holding it means the reaction never fired. Let go - # first so the next step isn't left fighting our hand. - if is_instance_valid(item) and item.is_picked_up(): - _hand._on_grip_release() - await _wait_frames(8) - return {"ok": false, "detail": "%s reached %s but was never consumed - the reaction did not fire; %s" - % [label, target_label, _diag(item)]} - - -# Carry an item somewhere clear and put it down, freeing the station it was in. -func _do_park(item: Node3D, label: String, pos: Vector3) -> Dictionary: - var res := await _do_grab(item, label) - if not res["ok"]: - return res - res = await _do_carry_to(item, label, pos) - if not res["ok"]: - return res - res = await _do_drop(item, label) - if not res["ok"]: - return res - return {"ok": true, "detail": "parked %s at %s" % [label, pos]} - - -# Move the held item onto a world position. Closed-loop: move the hand by -# whatever the item's remaining error is, since the grab point offsets the item -# from the hand by an amount we don't want to hard-code. -func _do_carry_to(item: Node3D, label: String, target: Vector3) -> Dictionary: - if not is_instance_valid(item) or not item.is_picked_up(): - return {"ok": false, "detail": "cannot carry: %s is not held" % label} - _log(" carrying %s from %s to %s" % [label, item.global_position, target]) - for i in 120: - if not is_instance_valid(item): - return {"ok": true, "detail": "%s was consumed while being carried" % label} - var err := item.global_position - target - if err.length() <= 0.01: - break - _controller.global_position -= err - await get_tree().physics_frame - await get_tree().physics_frame - if not is_instance_valid(item): - return {"ok": true, "detail": "%s was consumed while being carried" % label} - var dist := item.global_position.distance_to(target) - _log(" %s is now %.3fm from the target" % [label, dist]) - if dist > 0.05: - return {"ok": false, "detail": "could not carry %s to the target: still %.3fm away" % [label, dist]} - return {"ok": true, "detail": "carried %s to within %.3fm" % [label, dist]} - - -# Wait for a station to produce an item with the given food id (cooking the -# burger, or combining into a hamburger). Server-side: stations only run there. -func _do_await_food(food_id: String) -> Dictionary: - _log(" waiting for a '%s' to appear..." % food_id) - var ok := await _wait_until(func(): return _find_by_food_id(food_id) != null, - "a '%s' to be produced" % food_id, STATION_WORK_TIMEOUT) - if not ok: - return {"ok": false, "detail": "no '%s' was produced within %.0fs" % [food_id, STATION_WORK_TIMEOUT]} - # Let the spawn replicate before the checks that follow look for it. - await _wait_frames(30) - var made := _find_by_food_id(food_id) - return {"ok": true, "detail": "'%s' produced: %s at %s" % [food_id, made.name, made.global_position]} - - -func _do_await_clean(plate_name: String) -> Dictionary: - var plate := _find(plate_name) - if not plate: - return {"ok": false, "detail": "'%s' does not exist on this peer" % plate_name} - var pc := plate.get_node_or_null("PlateController") - _log(" waiting for the sink to wash %s (dirty=%s)..." % [plate_name, pc.is_dirty if pc else "?"]) - var ok := await _wait_until(func(): return pc and not pc.is_dirty, - "the sink to wash the plate", STATION_WORK_TIMEOUT) - await _wait_frames(30) - if not ok: - return {"ok": false, "detail": "%s was still dirty after %.0fs in the sink; %s" - % [plate_name, STATION_WORK_TIMEOUT, _diag(plate)]} - return {"ok": true, "detail": "%s was washed clean" % plate_name} - - -# --- Checks ---------------------------------------------------------------- - -# On the server "snapped" means the zone owns the item. On a client the snap is -# server-authoritative and never happens locally, so what must be true there is -# that the replicated item actually sits in the zone. -func _check_snapped(item_name: String, station: String) -> Dictionary: - var item := _find(item_name) - var zone := _zone_of(station) - if not item: - return {"ok": false, "detail": "'%s' does not exist on this peer" % item_name} - if not zone: - return {"ok": false, "detail": "station '%s' has no snap zone on this peer" % station} - var dist := item.global_position.distance_to(zone.global_position) - var problems: Array[String] = [] - if dist > SNAP_TOLERANCE: - problems.append("%s is %.3fm from %s's zone (tolerance %.2f)" % [item_name, dist, station, SNAP_TOLERANCE]) - if NetworkManager.owns_world(): - if zone.picked_up_object != item: - problems.append("%s's zone holds %s, not %s" % [station, zone.picked_up_object, item_name]) - elif not item.is_picked_up(): - problems.append("%s's zone claims %s but it has no grab driver (half-snapped)" % [station, item_name]) - if problems.is_empty(): - return {"ok": true, "detail": "%s is snapped into %s; %s" % [item_name, station, _diag(item)]} - return {"ok": false, "detail": "%s | %s" % [", ".join(problems), _diag(item)]} - - -func _check_dirty(plate_name: String, want_dirty: bool) -> Dictionary: - var plate := _find(plate_name) - if not plate: - return {"ok": false, "detail": "'%s' does not exist on this peer" % plate_name} - var pc := plate.get_node_or_null("PlateController") - if not pc: - return {"ok": false, "detail": "'%s' has no PlateController" % plate_name} - if pc.is_dirty != want_dirty: - return {"ok": false, "detail": "%s.is_dirty is %s, expected %s; %s" - % [plate_name, pc.is_dirty, want_dirty, _diag(plate)]} - return {"ok": true, "detail": "%s.is_dirty == %s as expected" % [plate_name, want_dirty]} - - -# A consumed item must be gone on EVERY peer, not just the one that consumed it. -func _check_gone(item_name: String) -> Dictionary: - var item := _find(item_name) - if item and is_instance_valid(item): - return {"ok": false, "detail": "'%s' still exists on this peer at %s (it should have been consumed)" - % [item_name, item.global_position]} - return {"ok": true, "detail": "'%s' is gone, as expected" % item_name} - - -func _check_food_exists(food_id: String) -> Dictionary: - var item := _find_by_food_id(food_id) - if not item: - return {"ok": false, "detail": "no item with food id '%s' exists on this peer" % food_id} - return {"ok": true, "detail": "'%s' exists: %s at %s" % [food_id, item.name, item.global_position]} - - -func _check_plate_contains(plate_name: String, food_id: String) -> Dictionary: - var plate := _find(plate_name) - if not plate: - return {"ok": false, "detail": "'%s' does not exist on this peer" % plate_name} - var pc := plate.get_node_or_null("PlateController") - if not pc: - return {"ok": false, "detail": "'%s' has no PlateController" % plate_name} - if not (food_id in pc.contained_ids): - return {"ok": false, "detail": "%s holds %s, expected it to contain '%s'" - % [plate_name, str(pc.contained_ids), food_id]} - return {"ok": true, "detail": "%s contains %s" % [plate_name, str(pc.contained_ids)]} - - -# --- Per-step screenshots -------------------------------------------------- -# -# One frame per peer per step, saved as PNGs and stitched into a single -# side-by-side GIF afterwards (see test/make_gif.ps1). Seeing both peers' -# viewports next to each other for the same step is the fastest way to spot a -# visual desync — the numbers in the log tell you something diverged, the GIF -# shows you what it looked like. - -## Frames are captured at half the viewport's resolution: 60-odd full-size -## frames per peer is a lot of pixels to write and then re-encode. -const FRAME_SCALE := 0.5 - - -func _setup_frames() -> void: - if not _frames_enabled: - return - if DisplayServer.get_name() == "headless": - _frames_enabled = false - _log("frame capture disabled: a headless run has no rendered output to grab") - return - var role := "server" if "--server" in OS.get_cmdline_user_args() else "client" - _frames_dir = "res://logs/mptest_frames_%s" % role - DirAccess.make_dir_recursive_absolute(ProjectSettings.globalize_path(_frames_dir)) - # Clear out a previous run's frames, or the GIF would splice the two together. - var dir := DirAccess.open(_frames_dir) - if dir: - for f in dir.get_files(): - if f.ends_with(".png"): - dir.remove(f) - _log("capturing a frame per step into %s" % ProjectSettings.globalize_path(_frames_dir)) - - -# The server numbers the frames and tells the client to grab the matching one, so -# frame N is the same step on both sides and they can be stitched in pairs. -func _capture_step_frame(label: String) -> void: - if not _frames_enabled: - return - _frame_index += 1 - if NetworkManager.is_server() and _client_id != 0: - _capture_frame_rpc.rpc_id(_client_id, _frame_index, label) - await _save_frame(_frame_index, label) - - -@rpc("authority", "reliable") -func _capture_frame_rpc(index: int, label: String) -> void: - if not _frames_enabled: - return - _frame_index = index - await _save_frame(index, label) - - -func _save_frame(index: int, label: String) -> void: - # Wait for the frame to actually be drawn, or we capture whatever was in the - # buffer before this step's changes landed. - await RenderingServer.frame_post_draw - var tex := get_viewport().get_texture() - if not tex: - return - var img := tex.get_image() - if not img: - return - if FRAME_SCALE != 1.0: - img.resize(int(img.get_width() * FRAME_SCALE), int(img.get_height() * FRAME_SCALE), - Image.INTERPOLATE_BILINEAR) - # Index-only filenames so ffmpeg's image sequence reader can pick them up as - # frame_%04d.png; the step name is already legible in the on-screen overlay. - var err := img.save_png("%s/frame_%04d.png" % [_frames_dir, index]) - if err != OK: - _log(" could not save frame %d (%s)" % [index, error_string(err)]) - else: - _frame_labels.append("%04d %s" % [index, label]) - - -# Written alongside the frames so a given frame number can be traced back to the -# step that produced it. -var _frame_labels: Array[String] = [] - - -func _write_frame_index() -> void: - if not _frames_enabled or _frame_labels.is_empty(): - return - var f := FileAccess.open("%s/frames.txt" % _frames_dir, FileAccess.WRITE) - if f: - for line in _frame_labels: - f.store_line(line) - f.close() - - -# --- Cross-peer sync audit ------------------------------------------------- -# -# Runs after every step. Targeted per-step assertions only look at the one thing -# the step touched, which misses the whole class of bug where some *other* -# object quietly drifts out of sync — or where the data replicates fine but the -# thing you actually see on screen doesn't. So after each step both peers -# describe every item they can see, and the two descriptions must match. - -## How far apart the same item may be on the two peers before it counts as a desync. -const SYNC_POS_TOLERANCE := 0.08 -## Physics keeps moving after a step (dropped items fall, snaps settle), so give -## the peers this long to converge before calling a difference a failure. -const SYNC_SETTLE_SEC := 3.0 - -var _client_snapshot: Dictionary = {} -var _snapshot_pending := false - - -# Everything about an item that should look identical on every peer. Includes -# what is actually rendered, not just the replicated data behind it: a plate -# whose contained_ids arrived but whose visuals were never rebuilt looks empty -# to the player, and that must count as a desync. -func _describe(item: Node3D) -> Dictionary: - var d := {"pos": item.global_position, "visible": item.visible} - var pc := item.get_node_or_null("PlateController") - if pc: - d["dirty"] = pc.is_dirty - d["contents"] = ",".join(pc.contained_ids) - var dirty_node := item.get_node_or_null("Dirty") - d["dirty_shown"] = dirty_node.visible if dirty_node else false - # The cosmetic copies the container builds from contained_ids - this is - # literally what the player sees sitting on the plate. - d["meals_shown"] = _visual_count(item, "Container/MealContainer") - d["sides_shown"] = _visual_count(item, "Container/SidesContainer") - # Food sitting on a plate is a cosmetic child of the plate, so it must - # travel with it. Keys starting with "_" are per-peer diagnostics that - # _compare() skips (floats won't match exactly across peers); the - # attached flag is asserted absolutely instead, because this can — and - # did — go wrong on both peers at once, which a diff would miss. - var off := _max_visual_offset(item) - d["_visual_offset"] = off - d["visuals_attached"] = off <= MAX_VISUAL_OFFSET - return d - - -## How far a cosmetic item on a plate may sit from the plate's origin. The plate -## is ~0.4m across and the furthest slot is ~0.12m out, so anything past this has -## come off the plate. -const MAX_VISUAL_OFFSET := 0.3 - - -# Largest distance from the plate's origin to any of the cosmetic items it is -# displaying. -1 when the plate is showing nothing. -func _max_visual_offset(item: Node3D) -> float: - var worst := -1.0 - for path in ["Container/MealContainer", "Container/SidesContainer"]: - var root := item.get_node_or_null(path) - if not root: - continue - for c in root.get_children(): - if c is Node3D and not c.is_queued_for_deletion(): - worst = maxf(worst, item.global_position.distance_to((c as Node3D).global_position)) - return snappedf(worst, 0.001) - - -# What the cosmetic children look like, for diagnosing why they moved. -func _visual_diag(item: Node3D) -> String: - var parts: Array[String] = [] - for path in ["Container/MealContainer", "Container/SidesContainer"]: - var root := item.get_node_or_null(path) - if not root: - continue - for c in root.get_children(): - var s := "%s global=%s local=%s parent=%s (%.3fm from plate at %s)" % [ - c.name, (c as Node3D).global_position, (c as Node3D).position, - c.get_parent().name, - item.global_position.distance_to((c as Node3D).global_position), - item.global_position] - if c is RigidBody3D: - s += " [RigidBody3D freeze=%s freeze_mode=%d layer=%d top_level=%s queued=%s]" % [ - c.freeze, c.freeze_mode, c.collision_layer, c.top_level, - c.is_queued_for_deletion()] - parts.append(s) - return "; ".join(parts) if parts else "(nothing on the plate)" - - -func _visual_count(item: Node3D, path: String) -> int: - var n := item.get_node_or_null(path) - if not n: - return -1 - var count := 0 - for c in n.get_children(): - if not c.is_queued_for_deletion(): - count += 1 - return count - - -## Stations whose on-screen state has to match on every peer. -const WATCHED_STATIONS := ["Hob", "Sink", "DirtStation", "Counter", "Counter2"] - - -func _snapshot() -> Dictionary: - var out := {} - for root in [_world, _world.get_node_or_null("WorldContent")]: - if not root: - continue - for child in root.get_children(): - if child is XRToolsPickable and not child.is_queued_for_deletion(): - out[str(child.name)] = _describe(child) - for name in WATCHED_STATIONS: - var station := _find(name) - if station: - out["station:" + name] = _describe_station(station) - return out - - -# What a station shows the player. Only the world owner runs a station's logic -# and snap zone, so its display has to be driven from replicated state — a -# client that never updates it shows a hob that never lights up, or a sink bar -# that stays on screen after the plate came out clean. -# -# Bar *visibility* is compared across peers; the progress value is diagnostic -# only ("_" prefix), because it changes every tick and the two peers are -# legitimately a frame apart. -func _describe_station(station: Node3D) -> Dictionary: - var d := {} - var bar := station.get_node_or_null("ProgressBar3D") as ProgressBar3D - d["bar_visible"] = bar.is_bar_visible() if bar else false - d["_bar_progress"] = snappedf(bar.get_progress(), 1.0) if bar else -1.0 - if "cooking_result" in station: - d["cooking"] = str(station.cooking_result) - if "is_washing" in station: - d["washing"] = bool(station.is_washing) - return d - +# --- cross-peer sync audit ------------------------------------------------- @rpc("authority", "reliable") func _request_snapshot() -> void: - _snapshot_reply.rpc_id(1, _snapshot()) + _snapshot_reply.rpc_id(1, _snapshot.take()) @rpc("any_peer", "reliable") @@ -1014,243 +451,74 @@ func _fetch_client_snapshot() -> Dictionary: return _client_snapshot -# Compare the server's view with the client's, returning a list of differences. -func _compare(server: Dictionary, client: Dictionary) -> Array[String]: - var problems: Array[String] = [] - for name in server: - if not client.has(name): - problems.append("'%s' exists on the server but NOT on the client" % name) - for name in client: - if not server.has(name): - problems.append("'%s' exists on the client but NOT on the server (ghost copy)" % name) - for name in server: - if not client.has(name): - continue - var s: Dictionary = server[name] - var c: Dictionary = client[name] - # Stations are compared on their displayed state, not a position. - if s.has("pos") and c.has("pos"): - var dist: float = (s["pos"] as Vector3).distance_to(c["pos"]) - if dist > SYNC_POS_TOLERANCE: - problems.append("%s is %.3fm apart (server %s vs client %s)" % [name, dist, s["pos"], c["pos"]]) - for key in s: - # "_" keys are per-peer diagnostics, not things that must match. - if key == "pos" or key.begins_with("_"): - continue - if s[key] != c[key]: - problems.append("%s.%s: server=%s client=%s" % [name, key, s[key], c[key]]) - # Absolute invariants, checked per peer. A cross-peer diff can't catch a - # fault that happens identically on both sides. - for peer_name in ["server", "client"]: - var snap: Dictionary = server if peer_name == "server" else client - for name in snap: - var d: Dictionary = snap[name] - if d.has("visuals_attached") and not d["visuals_attached"]: - problems.append("on the %s, %s's food has come off the plate (%.3fm from it, limit %.2f)" - % [peer_name, name, d.get("_visual_offset", -1.0), MAX_VISUAL_OFFSET]) - return problems - - -# Poll until the two peers agree, so ordinary physics settling isn't reported as -# a desync — a real one never converges and gets reported with its details. +## Poll until the two peers agree, so ordinary physics settling is not reported +## as a desync — a real one never converges and gets reported with its details. func _audit_sync(label: String) -> void: if not NetworkManager.is_server() or _client_id == 0: return var problems: Array[String] = [] - var deadline := Time.get_ticks_msec() + int(SYNC_SETTLE_SEC * 1000.0) + var deadline := Time.get_ticks_msec() + int(MpSnapshot.SETTLE_SEC * 1000.0) while true: - var mine := _snapshot() + var mine := _snapshot.take() var theirs := await _fetch_client_snapshot() - problems = _compare(mine, theirs) + problems = _snapshot.compare(mine, theirs) if problems.is_empty() or Time.get_ticks_msec() > deadline: break - await _wait_frames(10) + await _steps.wait_frames(10) var res := {"ok": problems.is_empty(), "detail": ""} if problems.is_empty(): - res["detail"] = "server and client agree on all %d items" % _snapshot().size() + res["detail"] = "server and client agree on all %d objects" % _snapshot.take().size() else: - res["detail"] = "after %.0fs the peers still disagree: %s" % [SYNC_SETTLE_SEC, "; ".join(problems)] - _record("sync_after_" + label, "both", res) + res["detail"] = "after %.0fs the peers still disagree: %s" % [MpSnapshot.SETTLE_SEC, "; ".join(problems)] + _report.record("sync_after_" + label, "both", res) -# --- Live watch on plate visuals ------------------------------------------ -# -# The per-step checks tell us the food ended up off the plate, but not when or -# why. This watches every frame and reports the first frame a cosmetic item -# departs from its slot, along with what was happening to the plate at the time. - -## Local offset from its slot at which a cosmetic item counts as having moved. -const VISUAL_DRIFT_EPSILON := 0.05 - -var _current_step := "(before any step)" -var _drift_reported := {} - - -func _process(_delta: float) -> void: - if not _world: - return - for root in [_world, _world.get_node_or_null("WorldContent")]: - if not root: - continue - for item in root.get_children(): - if not (item is Node3D) or not item.get_node_or_null("PlateController"): - continue - _watch_plate(item as Node3D) - - -func _watch_plate(plate: Node3D) -> void: - for path in ["Container/MealContainer", "Container/SidesContainer"]: - var holder := plate.get_node_or_null(path) - if not holder: - continue - for c in holder.get_children(): - if not (c is Node3D) or c.is_queued_for_deletion(): - continue - var drift: float = (c as Node3D).position.length() - var key := c.get_instance_id() - if drift <= VISUAL_DRIFT_EPSILON: - _drift_reported.erase(key) - continue - if _drift_reported.has(key): - continue - _drift_reported[key] = true - _log("VISUAL DRIFT: %s on %s moved to local %s (%.3f from its slot) during '%s'" % [ - c.name, plate.name, (c as Node3D).position, drift, _current_step]) - _log(" plate: pos=%s freeze=%s held_by=%s authority=%d" % [ - plate.global_position, plate.freeze if plate is RigidBody3D else "-", - plate.get_picked_up_by() if plate.has_method("get_picked_up_by") else "-", - plate.get_multiplayer_authority()]) - if c is RigidBody3D: - _log(" visual: freeze=%s mode=%d layer=%d top_level=%s sleeping=%s lin_vel=%s" % [ - c.freeze, c.freeze_mode, c.collision_layer, c.top_level, - c.sleeping, c.linear_velocity]) - - -# Food shown on a plate is a cosmetic child of that plate, so it has to stay put -# when the plate is picked up and carried around. If it drifts away, the player -# sees the burger fly off the plate. -func _check_plate_visuals(plate_name: String) -> Dictionary: - var plate := _find(plate_name) - if not plate: - return {"ok": false, "detail": "'%s' does not exist on this peer" % plate_name} - var off := _max_visual_offset(plate) - if off < 0.0: - return {"ok": false, "detail": "%s is not showing any food to check" % plate_name} - if off > MAX_VISUAL_OFFSET: - return {"ok": false, "detail": "%s's food has come off the plate: %.3fm away (limit %.2f). %s" - % [plate_name, off, MAX_VISUAL_OFFSET, _visual_diag(plate)]} - return {"ok": true, "detail": "%s's food is still on it (%.3fm from centre). %s" - % [plate_name, off, _visual_diag(plate)]} - - -# A station's progress bar must show the same thing to everyone: visible while -# the station is working, gone once it has finished. Only the world owner runs -# station logic, so a client can only get this right if the display is driven -# from replicated state. -func _check_station_bar(station_name: String, want_visible: bool) -> Dictionary: - var station := _find(station_name) - if not station: - return {"ok": false, "detail": "'%s' does not exist on this peer" % station_name} - var bar := station.get_node_or_null("ProgressBar3D") as ProgressBar3D - if not bar: - return {"ok": false, "detail": "%s has no ProgressBar3D" % station_name} - var shown := bar.is_bar_visible() - var detail := "%s bar visible=%s progress=%.0f%%" % [station_name, shown, bar.get_progress()] - if "cooking_result" in station: - detail += " cooking='%s'" % station.cooking_result - if "is_washing" in station: - detail += " washing=%s" % station.is_washing - if shown != want_visible: - return {"ok": false, "detail": "expected %s's bar to be %s, but %s" - % [station_name, "visible" if want_visible else "hidden", detail]} - return {"ok": true, "detail": detail} - - -# The client loaded a bare multiplayer scene with no kitchen in it, so every -# object it can see arrived from the server. This confirms it got the whole -# layout — the same thing that has to work for a player joining mid-session. -# Server-side check: it asks the client for its inventory and compares. +## The client loaded a bare multiplayer scene with no kitchen in it, so every +## object it can see arrived from the server. This confirms it got the whole +## layout — the same thing that has to work for a player joining mid-session. func _check_world_replicated() -> Dictionary: - var mine := _snapshot() + var mine := _snapshot.take() var theirs := await _fetch_client_snapshot() if theirs.is_empty(): return {"ok": false, "detail": "the client reported nothing at all"} - var problems := _compare(mine, theirs) + var problems := _snapshot.compare(mine, theirs) var detail := "server has %d objects, client has %d" % [mine.size(), theirs.size()] if not problems.is_empty(): return {"ok": false, "detail": "%s; %s" % [detail, "; ".join(problems)]} return {"ok": true, "detail": "%s, all matching (client received the world over the network)" % detail} -# A station that has had its item taken away must not still be holding it. -func _check_zone_empty(station_name: String) -> Dictionary: - var zone := _zone_of(station_name) - if not zone: - return {"ok": false, "detail": "station '%s' has no snap zone on this peer" % station_name} - if not NetworkManager.owns_world(): - # Client zones are gated off entirely; they never hold anything. - return {"ok": true, "detail": "%s: client zones are gated, nothing to check" % station_name} - if is_instance_valid(zone.picked_up_object): - return {"ok": false, "detail": "%s's zone still holds %s after it was taken away" - % [station_name, zone.picked_up_object]} - return {"ok": true, "detail": "%s's zone is empty" % station_name} +# --- per-step screenshots -------------------------------------------------- + +## The server numbers the frames and tells the client to grab the matching one, +## so frame N is the same step on both sides and they can be stitched in pairs. +func _capture_step_frame(label: String) -> void: + if not _report.frames_enabled(): + return + var index := _report.next_frame_index() + if NetworkManager.is_server() and _client_id != 0: + _capture_frame_rpc.rpc_id(_client_id, index, label) + await _report.save_frame(index, label) -# --- Diagnostics ----------------------------------------------------------- - -## Who is currently driving this object's transform. Under the high-level model -## the object's own authority never changes — only its NetXform's does, and that -## is what "who is holding this" means now. -func _xform_authority(item: Node) -> int: - if not is_instance_valid(item): - return 0 - var xform := item.get_node_or_null(NetReplication.XFORM_NAME) - return xform.get_multiplayer_authority() if xform else 0 +@rpc("authority", "reliable") +func _capture_frame_rpc(index: int, label: String) -> void: + await _report.save_frame(index, label) -func _diag(item: Node3D) -> String: - if not is_instance_valid(item): - return "item[freed]" - var pc := item.get_node_or_null("PlateController") - var s := "%s[pos=%s xform_authority=%d" % [ - item.name, item.global_position, _xform_authority(item), - ] - if item is XRToolsPickable: - s += " enabled=%s can_pick_up=%s layer=%d held_by=%s" % [ - item.enabled, item.can_pick_up(_hand), item.collision_layer, item.get_picked_up_by()] - if pc: - s += " dirty=%s contains=%s" % [pc.is_dirty, str(pc.contained_ids)] - return s + "]" - - -func _dump_state() -> void: - _log(" stations:") - for station in ["Hob", "Sink", "DirtStation", "Counter", "Counter2"]: - var z := _zone_of(station) - if z: - _log(" %-12s zone holds %s (enabled=%s)" % [station, z.picked_up_object, z.enabled]) - _log(" items:") - for root in [_world, _world.get_node_or_null("WorldContent")]: - if not root: - continue - for child in root.get_children(): - if child is XRToolsPickable: - _log(" %s" % _diag(child)) - - -# --- Manual controls ------------------------------------------------------- +# --- manual controls ------------------------------------------------------- func _unhandled_input(event: InputEvent) -> void: if not (event is InputEventKey) or not event.pressed or event.echo: return if _running and event.keycode != KEY_0: - _log("busy running a step, ignoring that key") + _report.log_line("busy running a step, ignoring that key") return match event.keycode: KEY_H: - _log("KEY: host"); NetworkManager.host(); _refresh_role() + _report.log_line("KEY: host"); NetworkManager.host(); _refresh_role() KEY_J: - _log("KEY: join 127.0.0.1"); NetworkManager.join("127.0.0.1") + _report.log_line("KEY: join 127.0.0.1"); NetworkManager.join("127.0.0.1") await get_tree().create_timer(1.0).timeout _refresh_role() KEY_1: await _manual("grab plate", "grab", ["Plate"]) @@ -1265,19 +533,21 @@ func _unhandled_input(event: InputEvent) -> void: KEY_R: _refresh_role() if _role != "server": - _log("KEY: run-all is server-only (this peer is %s)" % _role) + _report.log_line("KEY: run-all is server-only (this peer is %s)" % _role) return - _log("KEY: running the full automatic sequence") + _report.log_line("KEY: running the full automatic sequence") await _run_server() KEY_0: - _log("KEY: state dump") - _dump_state() + _report.log_line("KEY: state dump") + _view.dump_state(MpSnapshot.WATCHED_STATIONS, _hand) KEY_A: _refresh_role() if _role != "server": - _log("KEY: the sync audit runs from the server window") + _report.log_line("KEY: the sync audit runs from the server window") return - _log("KEY: comparing every object against the client") + if _client_id == 0: + _client_id = _find_client_id() + _report.log_line("KEY: comparing every object against the client") _running = true await _audit_sync("manual_check") _running = false @@ -1287,64 +557,30 @@ func _unhandled_input(event: InputEvent) -> void: func _manual(what: String, step: String, args: Array) -> void: _refresh_role() - _banner("MANUAL: %s" % what) + _report.banner("MANUAL: %s" % what) _running = true var res := await _run_local_step(step, args) _running = false - _log("%s %s :: %s" % ["PASS" if res.get("ok") else "FAIL", what, res.get("detail", "")]) + _report.log_line("%s %s :: %s" % ["PASS" if res.get("ok") else "FAIL", what, res.get("detail", "")]) # Capture manual steps too, so a hand-driven repro can be turned into a GIF. await _capture_step_frame(step) - _write_frame_index() - - -# --- Helpers --------------------------------------------------------------- - -func _move_hand_to(pos: Vector3) -> void: - # The controller is a child of the XROrigin, whose PlayerBody keeps moving - # (gravity) — that drags the hand off any position we place it at. top_level - # detaches it into world space. Done lazily on first use so that simply - # running the scene by hand leaves a real tracked controller alone. - if not _hand_detached: - _hand_detached = true - _controller.top_level = true - _log(" (detached the test hand from the XR rig so it can be driven directly)") - _controller.global_position = pos - _controller.force_update_transform() - - -func _wait_frames(n: int) -> void: - for i in n: - await get_tree().physics_frame - - -# Poll a condition instead of sleeping a guessed duration, so a slow machine -# doesn't produce a spurious failure and a fast one doesn't waste seconds. -func _wait_until(cond: Callable, what: String, timeout: float) -> bool: - var deadline := Time.get_ticks_msec() + int(timeout * 1000.0) - while Time.get_ticks_msec() < deadline: - if cond.call(): - return true - await get_tree().process_frame - _log(" timed out after %.0fs waiting for %s" % [timeout, what]) - return false + _report.write_frame_index() func _finish(ok: bool) -> void: - _log("=== %s exiting (%s) ===" % [_role, "ok" if ok else "FAILED"]) - if _log_file: - _log_file.flush() + _report.log_line("=== %s exiting (%s) ===" % [_role, "ok" if ok else "FAILED"]) get_tree().quit(0 if ok else 1) -# --- Camera ---------------------------------------------------------------- +# --- camera ---------------------------------------------------------------- -# A fixed camera overlooking the kitchen. -# -# Without this a windowed run shows nothing useful: the only camera is the -# XROrigin's XRCamera3D, which isn't driven by anything when XR is off, and the -# rig's PlayerBody keeps falling under gravity — it ends up metres below the -# floor pointing at the void. Ours is a plain Camera3D parented to the world -# (not the rig), so it stays put. +## A fixed camera overlooking the kitchen. +## +## Without this a windowed run shows nothing useful: the only camera is the +## XROrigin's XRCamera3D, which nothing drives when XR is off, and the rig's +## PlayerBody keeps falling under gravity — the view ends up metres below the +## floor pointing at the void. Ours is a plain Camera3D parented to the world, +## not the rig, so it stays put. func _build_debug_camera() -> void: if DisplayServer.get_name() == "headless": return @@ -1353,13 +589,13 @@ func _build_debug_camera() -> void: _world.add_child(_debug_cam) _debug_cam.global_position = DEBUG_CAM_POS _debug_cam.look_at(DEBUG_CAM_LOOK_AT) - # Explicitly stand the rig's camera down first: setting `current` alone lost + # Stand the rig's camera down explicitly first: setting `current` alone lost # the race against XRCamera3D, leaving the view stuck under the floor. var xr_cam := _world.get_node_or_null("XROrigin3D/XRCamera3D") as Camera3D if xr_cam: xr_cam.current = false _debug_cam.make_current() - _log("debug camera at %s looking at %s ([C] toggles back to the XR rig camera)" + _report.log_line("debug camera at %s looking at %s ([C] toggles back to the XR rig camera)" % [DEBUG_CAM_POS, DEBUG_CAM_LOOK_AT]) _assert_debug_camera.call_deferred() @@ -1367,101 +603,41 @@ func _build_debug_camera() -> void: func _assert_debug_camera() -> void: if _debug_cam and _debug_cam.current and get_viewport().get_camera_3d() != _debug_cam: _debug_cam.make_current() - _log("rendering through camera: %s" % get_viewport().get_camera_3d()) + _report.log_line("rendering through camera: %s" % get_viewport().get_camera_3d()) _check_framing() -# Confirm the things the test acts on are actually on screen. Checked by -# projection rather than by eye, because it's the only way to be sure across -# window sizes and display scaling. +## Confirm the things the test acts on are actually on screen. Checked by +## projection rather than by eye, because that is the only way to be sure across +## window sizes and display scaling. func _check_framing() -> void: var size := get_viewport().get_visible_rect().size var offscreen: Array[String] = [] for name in ["Counter2", "Counter", "Hob", "Sink", "DirtStation", "Plate"]: - var n := _find(name) + var n := _view.find(name) if not n: continue var p := _debug_cam.unproject_position(n.global_position) var frac := Vector2(p.x / size.x, p.y / size.y) var on := not _debug_cam.is_position_behind(n.global_position) \ and frac.x > 0.02 and frac.x < 0.98 and frac.y > 0.02 and frac.y < 0.98 - _log(" framing: %-12s at %.2f,%.2f of frame%s" % [name, frac.x, frac.y, "" if on else " <-- OFF SCREEN"]) + _report.log_line(" framing: %-12s at %.2f,%.2f of frame%s" + % [name, frac.x, frac.y, "" if on else " <-- OFF SCREEN"]) if not on: offscreen.append(name) if offscreen.is_empty(): - _log(" framing: all test objects are in view") + _report.log_line(" framing: all test objects are in view") else: - _log(" framing: WARNING - not visible: %s (adjust DEBUG_CAM_POS)" % ", ".join(offscreen)) + _report.log_line(" framing: WARNING - not visible: %s (adjust DEBUG_CAM_POS)" % ", ".join(offscreen)) func _toggle_debug_camera() -> void: if not _debug_cam: - _log("KEY: no debug camera in a headless run") return - _debug_cam.current = not _debug_cam.current - if not _debug_cam.current: - var xr_cam := _world.get_node_or_null("XROrigin3D/XRCamera3D") as Camera3D - if xr_cam: - xr_cam.current = true - _log("KEY: camera -> %s" % ("fixed debug camera" if _debug_cam.current else "XR rig camera")) - - -# --- Output ---------------------------------------------------------------- - -# A heading that's easy to find when scrolling a window full of engine spam. -func _banner(s: String) -> void: - _log("") - _log("======== %s ========" % s) - - -# Write the step log next to the engine's own log, under /logs/, so -# everything from a run is in one place. Named per role because both instances -# would otherwise fight over one file (the engine's own godot.log has exactly -# that problem when two peers run at once — it rotates per process). -func _open_log() -> void: - var role := "server" if "--server" in OS.get_cmdline_user_args() else "client" - var path := "res://logs/mptest_%s.log" % role - DirAccess.make_dir_recursive_absolute(ProjectSettings.globalize_path("res://logs")) - _log_file = FileAccess.open(path, FileAccess.WRITE) - if not _log_file: - # res:// is read-only in an exported build; fall back to somewhere writable. - path = OS.get_environment("TEMP").path_join("vryhungry_mptest_%s.log" % role) - _log_file = FileAccess.open(path, FileAccess.WRITE) - _log_path = ProjectSettings.globalize_path(path) - print("[MPTEST] step log -> %s" % _log_path) - - -func _log(s: String) -> void: - print("[MPTEST %s] %s" % [_role, s]) - if _log_file: - _log_file.store_line(s) - _log_file.flush() - _push_overlay(s) - - -# On-screen mirror of the log, so a windowed run shows what's happening without -# needing the console — including which peer this window is. -func _build_overlay() -> void: - var layer := CanvasLayer.new() - layer.name = "MPTestOverlay" - var panel := PanelContainer.new() - panel.set_anchors_preset(Control.PRESET_TOP_WIDE) - panel.modulate = Color(1, 1, 1, 0.85) - _overlay = Label.new() - # Sized for a 1800x1200 canvas, and to stay legible once a captured frame has - # been scaled down into the GIF. - _overlay.add_theme_font_size_override("font_size", 22) - _overlay.autowrap_mode = TextServer.AUTOWRAP_OFF - _overlay.clip_text = true - panel.add_child(_overlay) - layer.add_child(panel) - add_child(layer) - - -func _push_overlay(s: String) -> void: - if not _overlay: - return - _overlay_lines.append(s) - while _overlay_lines.size() > OVERLAY_LINES: - _overlay_lines.pop_front() - _overlay.text = "[%s] %s\n%s" % [_role.to_upper(), HELP, "\n".join(_overlay_lines)] + var xr_cam := _world.get_node_or_null("XROrigin3D/XRCamera3D") as Camera3D + if _debug_cam.current and xr_cam: + xr_cam.make_current() + _report.log_line("switched to the XR rig camera") + else: + _debug_cam.make_current() + _report.log_line("switched to the debug camera") diff --git a/test/mp_world_view.gd b/test/mp_world_view.gd new file mode 100644 index 0000000..77b6c77 --- /dev/null +++ b/test/mp_world_view.gd @@ -0,0 +1,117 @@ +extends Node +class_name MpWorldView + +## Finding things in the world under test, and describing what they are doing. +## +## Nothing here caches a node. Items are consumed and respawned as the run goes +## on — the raw burger becomes a cooked burger, which becomes a hamburger, which +## is absorbed into a plate — so a held reference is a freed object waiting to +## happen. Everything is looked up at the moment it is used. + +var world: Node3D +var report: MpReport + +var _despawn_timers_seen := {} + + +func setup(p_world: Node3D, p_report: MpReport) -> void: + world = p_world + report = p_report + + +## Objects live either baked in the scene root or, once spawned at runtime, under +## WorldContent. Look in both. +func find(name: String) -> Node3D: + var n := world.get_node_or_null(name) + if not n: + n = world.get_node_or_null("WorldContent/" + name) + return n as Node3D + + +func zone_of(station_name: String) -> XRToolsSnapZone: + var s := find(station_name) + return s.get_node_or_null("XRToolsSnapZone") as XRToolsSnapZone if s else null + + +## Cooking and combining spawn their results with engine-assigned names, so the +## only stable way to find one is by the food id it carries. +func find_by_food_id(id: String) -> Node3D: + for child in roots_children(): + var f := child.get_node_or_null("FoodItem") as FoodItem + if f and f.id == id and is_instance_valid(child): + return child as Node3D + return null + + +func roots_children() -> Array[Node]: + var out: Array[Node] = [] + for root in [world, world.get_node_or_null("WorldContent")]: + if not root: + continue + for child in root.get_children(): + out.append(child) + return out + + +func pickables() -> Array[Node]: + var out: Array[Node] = [] + for child in roots_children(): + if child is XRToolsPickable and not child.is_queued_for_deletion(): + out.append(child) + return out + + +## Who is currently driving this object's transform. +## +## Under the high-level model the object's own multiplayer authority never +## changes — only its NetXform's does, and that is what "who is holding this" +## means now. +func xform_authority(item: Node) -> int: + if not is_instance_valid(item): + return 0 + var xform := item.get_node_or_null(NetReplication.XFORM_NAME) + return xform.get_multiplayer_authority() if xform else 0 + + +## The test deliberately leaves objects sitting still for minutes at a time, +## which DespawningItem treats as litter and removes — it took the raw burger +## away before the client had even connected. Hold them indefinitely instead, so +## the run tests the kitchen rather than the despawn timer. +## +## Re-checked before every step rather than only at startup, because cooking and +## combining spawn new objects as the run goes on. +func disable_despawn_timers() -> void: + var stopped := 0 + for node in world.find_children("*", "DespawningItem", true, false): + if _despawn_timers_seen.has(node.get_instance_id()): + continue + _despawn_timers_seen[node.get_instance_id()] = true + node.set_process(false) + stopped += 1 + if stopped > 0: + report.log_line("disabled %d DespawningItem timer(s) so test objects don't vanish mid-run" % stopped) + + +func diag(item: Node3D, hand: XRToolsFunctionPickup = null) -> String: + if not is_instance_valid(item): + return "item[freed]" + var pc := item.get_node_or_null("PlateController") + var s := "%s[pos=%s xform_authority=%d" % [item.name, item.global_position, xform_authority(item)] + if item is XRToolsPickable: + s += " enabled=%s can_pick_up=%s layer=%d held_by=%s" % [ + item.enabled, item.can_pick_up(hand) if hand else "?", + item.collision_layer, item.get_picked_up_by()] + if pc: + s += " dirty=%s contains=%s" % [pc.is_dirty, str(pc.contained_ids)] + return s + "]" + + +func dump_state(stations: Array, hand: XRToolsFunctionPickup) -> void: + report.log_line(" stations:") + for station in stations: + var z := zone_of(station) + if z: + report.log_line(" %-12s zone holds %s (enabled=%s)" % [station, z.picked_up_object, z.enabled]) + report.log_line(" items:") + for child in pickables(): + report.log_line(" %s" % diag(child as Node3D, hand)) diff --git a/test/mp_world_view.gd.uid b/test/mp_world_view.gd.uid new file mode 100644 index 0000000..5d23dc0 --- /dev/null +++ b/test/mp_world_view.gd.uid @@ -0,0 +1 @@ +uid://dxqia06f3e4u4 diff --git a/test/spike/probe.gd b/test/spike/probe.gd new file mode 100644 index 0000000..b9e34a6 --- /dev/null +++ b/test/spike/probe.gd @@ -0,0 +1,24 @@ +extends Node + +## Throwaway probe: prints how GDScript reports typed-array properties, so +## NetReplication's filter can exclude Array[Node3D] / Array[FoodItem] without +## guessing at the hint format. + +func _ready() -> void: + for path in [ + "res://Containers/container.gd", + "res://Containers/plate_controller.gd", + "res://Stations/sink.gd", + "res://Stations/item_dispenser.gd", + "res://Stations/hob.gd", + ]: + var script: Script = load(path) + print("=== ", path) + for prop in script.get_script_property_list(): + if not (prop["usage"] & PROPERTY_USAGE_SCRIPT_VARIABLE): + continue + print(" name=%s type=%d hint=%d hint_string=%s" % [ + prop["name"], prop["type"], prop["hint"], prop["hint_string"], + ]) + print("TYPE_ARRAY=%d TYPE_OBJECT=%d" % [TYPE_ARRAY, TYPE_OBJECT]) + get_tree().quit() diff --git a/test/spike/probe.gd.uid b/test/spike/probe.gd.uid new file mode 100644 index 0000000..41aebf2 --- /dev/null +++ b/test/spike/probe.gd.uid @@ -0,0 +1 @@ +uid://ctsonlf12536k diff --git a/test/spike/probe.tscn b/test/spike/probe.tscn new file mode 100644 index 0000000..e7eeefc --- /dev/null +++ b/test/spike/probe.tscn @@ -0,0 +1,6 @@ +[gd_scene load_steps=2 format=3 uid="uid://bspike0probe0"] + +[ext_resource type="Script" path="res://test/spike/probe.gd" id="1_probe"] + +[node name="Probe" type="Node"] +script = ExtResource("1_probe")