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")