From d65b2ca86344a8dc7b7a0b91275578016026dd94 Mon Sep 17 00:00:00 2001 From: algodoogle Date: Sat, 25 Jul 2026 21:07:21 +0100 Subject: [PATCH] Add diagnostic logging for item grab/authority state transitions MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The snap-zone crash fixed just before this was invisible in the logs until traced through addon source by hand — the log showed grabs, drops, and authority handoffs, but nothing about which peer/hand/zone actually held an item at each step, or when a guard clause silently changed behavior. Adds a _holder_desc() helper (reports "loose", "hand()", "zone()", or "other(...)") and logs every net_held_by transition, every reclaim that has to restore freeze_mode/collision_mask from a stuck state, every time the grab-race guard protects an actively- held item from a stale sync, every force-drop triggered by a losing authority race, and every pickup/drop event including the ones that don't get forwarded (picked up by something other than a hand, or dropped while not authority — exactly the silent case behind the snap-zone crash). NetworkManager's snap/release-from-zone calls get the same treatment: which station an item is pulled from, and whether a snap attempt succeeded, was skipped by the race guard, or found nothing in range. Co-Authored-By: Claude Sonnet 5 --- Net/net_pickable.gd | 59 ++++++++++++++++++++++++++++++++++++++++-- Net/network_manager.gd | 23 +++++++++++++++- 2 files changed, 79 insertions(+), 3 deletions(-) diff --git a/Net/net_pickable.gd b/Net/net_pickable.gd index c3f8fc6..52c3a6a 100644 --- a/Net/net_pickable.gd +++ b/Net/net_pickable.gd @@ -38,7 +38,12 @@ func _ready() -> void: func _set_net_held_by(value: int) -> void: + var old := net_held_by net_held_by = value + if old != value and NetworkManager.is_online(): + NetworkManager.log_line("%s net_held_by: %d -> %d (local state: %s, authority=%d)" % [ + _pickable.name, old, value, _holder_desc(), get_multiplayer_authority() + ]) apply_held_state() @@ -56,6 +61,15 @@ func apply_held_state() -> void: # client released it) — while actually held, XRToolsPickable's own # pick_up()/let_go() already manage these fields, so leave those be. if not _pickable.is_picked_up(): + var changed := _pickable.freeze_mode != _original_freeze_mode \ + or _pickable.collision_mask != _pickable.original_collision_mask + if changed and NetworkManager.is_online(): + NetworkManager.log_line( + "%s: reclaiming ownership, restoring freeze_mode %d->%d collision_mask %d->%d" % [ + _pickable.name, _pickable.freeze_mode, _original_freeze_mode, + _pickable.collision_mask, _pickable.original_collision_mask + ] + ) _pickable.freeze_mode = _original_freeze_mode _pickable.collision_mask = _pickable.original_collision_mask return @@ -66,10 +80,24 @@ func apply_held_state() -> void: # hand mid-grab — only an explicit force_release_item rejection, or # actually losing authority for real, should end a grab we initiated. if _pickable.is_picked_up() and _pickable.get_picked_up_by() is XRToolsFunctionPickup: + if NetworkManager.is_online(): + NetworkManager.log_line( + "%s: ignoring non-authority sync (net_held_by=%d) — still actively held by our own hand (grab-race guard)" % [ + _pickable.name, net_held_by + ] + ) return # Someone else owns it: stop simulating locally, just follow the sync. if _pickable.is_picked_up(): + if NetworkManager.is_online(): + NetworkManager.log_line( + "%s: was held by %s on this peer, but authority now says peer %d owns it — force-dropping" % [ + _pickable.name, _holder_desc(), net_held_by + ] + ) _pickable.drop() + if NetworkManager.is_online(): + NetworkManager.log_line("%s: freezing (non-authority, owner=peer %d)" % [_pickable.name, net_held_by]) _pickable.freeze = true _pickable.freeze_mode = RigidBody3D.FREEZE_MODE_KINEMATIC _pickable.collision_mask = 0 @@ -82,9 +110,14 @@ func apply_held_state() -> void: func _on_picked_up(_p) -> void: var by := _pickable.get_picked_up_by() if not (by is XRToolsFunctionPickup): + # e.g. a station snap zone grabbed it (server-side auto-snap, or the + # addon's own "grab out of a snap zone" shortcut mid-cascade) — not a + # player-initiated hand grab, so no authority request from here. + if NetworkManager.is_online(): + NetworkManager.log_line("%s picked up by %s (not a hand) — no authority request" % [_pickable.name, _holder_desc()]) return if NetworkManager.is_online(): - NetworkManager.log_line("Grabbed %s by hand, requesting authority" % _pickable.name) + NetworkManager.log_line("%s grabbed by hand (authority was peer %d), requesting authority" % [_pickable.name, net_held_by]) NetworkManager.request_item_authority_from(_pickable.get_path()) @@ -92,9 +125,31 @@ func _on_dropped(_p) -> void: # Only forward if we're actually still the authority — a drop caused by # apply_held_state() losing authority (see above) must not re-report. if not is_multiplayer_authority(): + if NetworkManager.is_online(): + NetworkManager.log_line("%s dropped locally, but we aren't its authority (peer %d is) — not reporting" % [_pickable.name, net_held_by]) return if NetworkManager.is_online(): - NetworkManager.log_line("Dropped %s, reporting release to server" % _pickable.name) + NetworkManager.log_line("%s dropped, reporting release to server (lin=%s ang=%s)" % [ + _pickable.name, _pickable.linear_velocity, _pickable.angular_velocity + ]) NetworkManager.release_item_authority_from( _pickable.get_path(), _pickable.linear_velocity, _pickable.angular_velocity ) + + +## Human-readable description of what's currently holding this item on THIS +## peer, for diagnosing desyncs between a hand's own "what am I holding" +## bookkeeping and the item's actual grab state (see the snap-zone-grab race +## in NetworkManager._try_snap_into_station for a real example). +func _holder_desc() -> String: + if not _pickable or not _pickable.is_picked_up(): + return "loose" + var by := _pickable.get_picked_up_by() + if not by: + return "held(no grabber?)" + if by is XRToolsFunctionPickup: + return "hand(%s)" % by.get_path() + if by is XRToolsSnapZone: + var station := by.get_parent() + return "zone(%s)" % (station.name if station else str(by.get_path())) + return "other(%s: %s)" % [by.get_class(), by.get_path()] diff --git a/Net/network_manager.gd b/Net/network_manager.gd index cbe9e6c..ed1460f 100644 --- a/Net/network_manager.gd +++ b/Net/network_manager.gd @@ -233,7 +233,7 @@ func _do_release_item_authority(item_path: NodePath, lin: Vector3, ang: Vector3, item.freeze = false item.linear_velocity = lin item.angular_velocity = ang - _try_snap_into_station(item) + _try_snap_into_station.call_deferred(item) # All station snap zones in the world (every XRToolsSnapZone child of a node in @@ -251,13 +251,33 @@ func _station_snap_zones() -> Array: func _release_from_snap_zones(item: Node) -> void: for zone in _station_snap_zones(): if zone.picked_up_object == item: + log_line("releasing %s from %s's snap zone (authority just granted elsewhere)" % [item.name, zone.get_parent().name]) zone.drop_object() # Snap the item into the nearest empty station snap zone within grab range. +# +# Called deferred from _do_release_item_authority: XRToolsFunctionPickup's own +# "grab an item out of a snap zone" path calls zone.drop_object() BEFORE it +# calls pick_up() on the hand's behalf. drop_object()'s let_go() synchronously +# fires the pickable's `dropped` signal, which (via NetPickable) lands here — +# if this ran synchronously it would immediately re-snap the item into the +# very same zone it's still physically inside, stealing it away before the +# hand's own pick_up() call (later in the same call stack) ever runs. That +# leaves XRToolsFunctionPickup.picked_up_object pointing at an item whose +# _grab_driver actually belongs to the zone — a stale reference that crashes +# (null _grab_driver) the next time a controller button is pressed. Deferring +# lets the hand's pick_up() go first; the is_picked_up() check below is a +# second guard in case the item gets grabbed for real before this runs. func _try_snap_into_station(item: Node) -> void: if not (item is Node3D): return + if item.has_method("is_picked_up") and item.is_picked_up(): + var by: Node = null + if item.has_method("get_picked_up_by"): + by = item.get_picked_up_by() + log_line("skipped snapping %s: already held by %s (grab-race guard)" % [item.name, by.get_path() if by else "?"]) + return for zone in _station_snap_zones(): if is_instance_valid(zone.picked_up_object): continue @@ -265,6 +285,7 @@ func _try_snap_into_station(item: Node) -> void: log_line("snapped %s into %s" % [item.name, zone.get_parent().name]) zone.pick_up_object(item) return + log_line("no station in range to snap %s into (or none empty)" % item.name) # Server broadcasts an authority assignment so every peer agrees on who owns the