Improve Debug impl for objects

godot-core/src/builtin/variant/mod.rs

@@ -8,6 +8,7 @@
 use crate::builtin::{
     GString, StringName, VariantArray, VariantDispatch, VariantOperator, VariantType,
 };
+use crate::classes;
 use crate::meta::error::{ConvertError, FromVariantError};
 use crate::meta::{
     arg_into_ref, ffi_variant_type, ArrayElement, AsArg, ExtVariantType, FromGodot, GodotType,
@@ -583,6 +584,10 @@ impl fmt::Debug for Variant {
                 array.fmt(f)
             }
 
+            // Converting to objects before printing causes their refcount to increment, leading to an Observer effect
+            // where `Debug` actually changes the object statistics. As such, fetch information without instantiating Gd<T>.
+            VariantType::OBJECT => classes::debug_string_variant(self, f, "VariantGd"),
+
             // VariantDispatch also includes dead objects via `FreedObject` enumerator, which maps to "<Freed Object>".
             _ => VariantDispatch::from_variant(self).fmt(f),
         }

godot-core/src/classes/class_runtime.rs

@@ -7,13 +7,13 @@
 
 //! Runtime checks and inspection of Godot classes.
 
-use crate::builtin::{GString, StringName};
+use crate::builtin::{GString, StringName, Variant, VariantType};
 #[cfg(debug_assertions)]
 use crate::classes::{ClassDb, Object};
 use crate::meta::CallContext;
 #[cfg(debug_assertions)]
 use crate::meta::ClassName;
-use crate::obj::{bounds, Bounds, Gd, GodotClass, InstanceId};
+use crate::obj::{bounds, Bounds, Gd, GodotClass, InstanceId, RawGd};
 use crate::sys;
 
 pub(crate) fn debug_string<T: GodotClass>(
@@ -23,12 +23,85 @@ pub(crate) fn debug_string<T: GodotClass>(
 ) -> std::fmt::Result {
     if let Some(id) = obj.instance_id_or_none() {
         let class: StringName = obj.dynamic_class_string();
-        write!(f, "{ty} {{ id: {id}, class: {class} }}")
+        debug_string_parts(f, ty, id, class, obj.maybe_refcount(), None)
     } else {
         write!(f, "{ty} {{ freed obj }}")
     }
 }
 
+#[cfg(since_api = "4.4")]
+pub(crate) fn debug_string_variant(
+    obj: &Variant,
+    f: &mut std::fmt::Formatter<'_>,
+    ty: &str,
+) -> std::fmt::Result {
+    debug_assert_eq!(obj.get_type(), VariantType::OBJECT);
+
+    let id = obj
+        .object_id_unchecked()
+        .expect("Variant must be of type OBJECT");
+
+    if id.lookup_validity() {
+        // Object::get_class() currently returns String, but this is future-proof if the return type changes to StringName.
+        let class = obj
+            .call("get_class", &[])
+            .try_to_relaxed::<StringName>()
+            .expect("get_class() must be compatible with StringName");
+
+        let refcount = id.is_ref_counted().then(|| {
+            obj.call("get_reference_count", &[])
+                .try_to_relaxed::<i32>()
+                .expect("get_reference_count() must return integer") as usize
+        });
+
+        debug_string_parts(f, ty, id, class, refcount, None)
+    } else {
+        write!(f, "{ty} {{ freed obj }}")
+    }
+}
+
+// Polyfill for Godot < 4.4, where Variant::object_id_unchecked() is not available.
+#[cfg(before_api = "4.4")]
+pub(crate) fn debug_string_variant(
+    obj: &Variant,
+    f: &mut std::fmt::Formatter<'_>,
+    ty: &str,
+) -> std::fmt::Result {
+    debug_assert_eq!(obj.get_type(), VariantType::OBJECT);
+
+    match obj.try_to::<Gd<crate::classes::Object>>() {
+        Ok(obj) => {
+            let id = obj.instance_id(); // Guaranteed valid, since conversion would have failed otherwise.
+            let class = obj.dynamic_class_string();
+
+            // Refcount is off-by-one due to now-created Gd<T> from conversion; correct by -1.
+            let refcount = obj.maybe_refcount().map(|rc| rc.saturating_sub(1));
+
+            debug_string_parts(f, ty, id, class, refcount, None)
+        }
+        Err(_) => {
+            write!(f, "{ty} {{ freed obj }}")
+        }
+    }
+}
+
+pub(crate) fn debug_string_nullable<T: GodotClass>(
+    obj: &RawGd<T>,
+    f: &mut std::fmt::Formatter<'_>,
+    ty: &str,
+) -> std::fmt::Result {
+    if obj.is_null() {
+        write!(f, "{ty} {{ null }}")
+    } else {
+        // Unsafety introduced here to avoid creating a new Gd<T> (which can have all sorts of side effects, logs, refcounts etc.)
+        // *and* pushing down all high-level Gd<T> functions to RawGd<T> as pure delegates.
+
+        // SAFETY: checked non-null.
+        let obj = unsafe { obj.as_non_null() };
+        debug_string(obj, f, ty)
+    }
+}
+
 pub(crate) fn debug_string_with_trait<T: GodotClass>(
     obj: &Gd<T>,
     f: &mut std::fmt::Formatter<'_>,
@@ -37,12 +110,36 @@ pub(crate) fn debug_string_with_trait<T: GodotClass>(
 ) -> std::fmt::Result {
     if let Some(id) = obj.instance_id_or_none() {
         let class: StringName = obj.dynamic_class_string();
-        write!(f, "{ty} {{ id: {id}, class: {class}, trait: {trt} }}")
+        debug_string_parts(f, ty, id, class, obj.maybe_refcount(), Some(trt))
     } else {
         write!(f, "{ty} {{ freed obj }}")
     }
 }
 
+fn debug_string_parts(
+    f: &mut std::fmt::Formatter<'_>,
+    ty: &str,
+    id: InstanceId,
+    class: StringName,
+    refcount: Option<usize>,
+    trait_name: Option<&str>,
+) -> std::fmt::Result {
+    let mut builder = f.debug_struct(ty);
+    builder
+        .field("id", &id.to_i64())
+        .field("class", &format_args!("{class}"));
+
+    if let Some(trait_name) = trait_name {
+        builder.field("trait", &format_args!("{trait_name}"));
+    }
+
+    if let Some(refcount) = refcount {
+        builder.field("refc", &refcount);
+    }
+
+    builder.finish()
+}
+
 pub(crate) fn display_string<T: GodotClass>(
     obj: &Gd<T>,
     f: &mut std::fmt::Formatter<'_>,
@@ -83,7 +180,7 @@ pub(crate) fn ensure_object_alive(
     // namely in PR https://github.com/godotengine/godot/pull/36189. Double-check to make sure.
     assert_eq!(
         new_object_ptr, old_object_ptr,
-        "{call_ctx}: instance ID {instance_id} points to a stale, reused object. Please report this to gdext maintainers."
+        "{call_ctx}: instance ID {instance_id} points to a stale, reused object. Please report this to godot-rust maintainers."
     );
 }
 

godot-core/src/obj/base.rs

@@ -102,6 +102,12 @@ impl<T: GodotClass> Base<T> {
     pub fn obj_sys(&self) -> sys::GDExtensionObjectPtr {
         self.obj.obj_sys()
     }
+
+    // Internal use only, do not make public.
+    #[cfg(feature = "debug-log")]
+    pub(crate) fn debug_instance_id(&self) -> crate::obj::InstanceId {
+        self.obj.instance_id()
+    }
 }
 
 impl<T: GodotClass> Debug for Base<T> {

godot-core/src/obj/bounds.rs

@@ -208,7 +208,7 @@ impl Sealed for MemRefCounted {}
 impl Memory for MemRefCounted {}
 impl DynMemory for MemRefCounted {
     fn maybe_init_ref<T: GodotClass>(obj: &mut RawGd<T>) {
-        out!("  MemRefc::init  <{}>", std::any::type_name::<T>());
+        out!("  MemRefc::init:  {obj:?}");
         if obj.is_null() {
             return;
         }
@@ -226,7 +226,7 @@ impl DynMemory for MemRefCounted {
     }
 
     fn maybe_inc_ref<T: GodotClass>(obj: &mut RawGd<T>) {
-        out!("  MemRefc::inc   <{}>", std::any::type_name::<T>());
+        out!("  MemRefc::inc:   {obj:?}");
         if obj.is_null() {
             return;
         }
@@ -237,7 +237,7 @@ impl DynMemory for MemRefCounted {
     }
 
     unsafe fn maybe_dec_ref<T: GodotClass>(obj: &mut RawGd<T>) -> bool {
-        out!("  MemRefc::dec   <{}>", std::any::type_name::<T>());
+        out!("  MemRefc::dec:   {obj:?}");
         if obj.is_null() {
             return false;
         }
@@ -278,7 +278,7 @@ impl MemDynamic {
 impl Sealed for MemDynamic {}
 impl DynMemory for MemDynamic {
     fn maybe_init_ref<T: GodotClass>(obj: &mut RawGd<T>) {
-        out!("  MemDyn::init  <{}>", std::any::type_name::<T>());
+        out!("  MemDyn::init:  {obj:?}");
         if Self::inherits_refcounted(obj) {
             // Will call `RefCounted::init_ref()` which checks for liveness.
             out!("    MemDyn -> MemRefc");
@@ -289,15 +289,15 @@ impl DynMemory for MemDynamic {
     }
 
     fn maybe_inc_ref<T: GodotClass>(obj: &mut RawGd<T>) {
-        out!("  MemDyn::inc   <{}>", std::any::type_name::<T>());
+        out!("  MemDyn::inc:   {obj:?}");
         if Self::inherits_refcounted(obj) {
             // Will call `RefCounted::reference()` which checks for liveness.
             MemRefCounted::maybe_inc_ref(obj)
         }
     }
 
     unsafe fn maybe_dec_ref<T: GodotClass>(obj: &mut RawGd<T>) -> bool {
-        out!("  MemDyn::dec   <{}>", std::any::type_name::<T>());
+        out!("  MemDyn::dec:   {obj:?}");
         if obj
             .instance_id_unchecked()
             .is_some_and(|id| id.is_ref_counted())

godot-core/src/obj/gd.rs

@@ -302,6 +302,21 @@ impl<T: GodotClass> Gd<T> {
         }
     }
 
+    /// Returns the reference count, if the dynamic object inherits `RefCounted`; and `None` otherwise.
+    pub(crate) fn maybe_refcount(&self) -> Option<usize> {
+        // Fast check if ref-counted without downcast.
+        self.instance_id().is_ref_counted().then(|| {
+            let rc = self.raw.with_ref_counted(|refc| refc.get_reference_count());
+            rc as usize
+        })
+    }
+
+    #[cfg(feature = "trace")] // itest only.
+    #[doc(hidden)]
+    pub fn test_refcount(&self) -> Option<usize> {
+        self.maybe_refcount()
+    }
+
     /// **Upcast:** convert into a smart pointer to a base class. Always succeeds.
     ///
     /// Moves out of this value. If you want to create _another_ smart pointer instance,

godot-core/src/obj/raw_gd.rs

@@ -18,7 +18,7 @@ use crate::meta::{
 use crate::obj::bounds::{Declarer, DynMemory as _};
 use crate::obj::casts::CastSuccess;
 use crate::obj::rtti::ObjectRtti;
-use crate::obj::{bounds, Bounds, GdDerefTarget, GdMut, GdRef, GodotClass, InstanceId};
+use crate::obj::{bounds, Bounds, Gd, GdDerefTarget, GdMut, GdRef, GodotClass, InstanceId};
 use crate::storage::{InstanceCache, InstanceStorage, Storage};
 use crate::{classes, out};
 
@@ -95,8 +95,7 @@ impl<T: GodotClass> RawGd<T> {
 
     /// Returns `true` if the object is null.
     ///
-    /// This does not check if the object is dead, for that use
-    /// [`instance_id_or_none()`](Self::instance_id_or_none).
+    /// This does not check if the object is dead. For that, use [`is_instance_valid()`](Self::is_instance_valid).
     pub(crate) fn is_null(&self) -> bool {
         self.obj.is_null() || self.cached_rtti.is_none()
     }
@@ -148,10 +147,15 @@ impl<T: GodotClass> RawGd<T> {
     ///
     /// On success, you'll get a `CastSuccess<T, U>` instance, which holds a weak `RawGd<U>`. You can only extract that one by trading
     /// a strong `RawGd<T>` for it, to maintain the balance.
+    ///
+    /// This function is unreliable when invoked _during_ destruction (e.g. C++ `~RefCounted()` destructor). This can occur when debug-logging
+    /// instances during cleanups. `Object::object_cast_to()` is a virtual function, but virtual dispatch during destructor doesn't work in C++.
     pub(super) fn ffi_cast<U>(&self) -> Result<CastSuccess<T, U>, ()>
     where
         U: GodotClass,
     {
+        //eprintln!("ffi_cast: {} (dyn {}) -> {}", T::class_name(), self.as_non_null().dynamic_class_string(), U::class_name());
+
         // `self` may be null when we convert a null-variant into a `Option<Gd<T>>`, since we use `ffi_cast`
         // in the `ffi_from_variant` conversion function to ensure type-correctness. So the chain would be as follows:
         // - Variant::nil()
@@ -184,24 +188,57 @@ impl<T: GodotClass> RawGd<T> {
         Ok(CastSuccess::from_weak(weak))
     }
 
+    /// Executes a function, assuming that `self` inherits `RefCounted`.
+    ///
+    /// This function is unreliable when invoked _during_ destruction (e.g. C++ `~RefCounted()` destructor). This can occur when debug-logging
+    /// instances during cleanups. `Object::object_cast_to()` is a virtual function, but virtual dispatch during destructor doesn't work in C++.
+    ///
+    /// # Panics
+    /// If `self` does not inherit `RefCounted` or is null.
     pub(crate) fn with_ref_counted<R>(&self, apply: impl Fn(&mut classes::RefCounted) -> R) -> R {
         // Note: this previously called Declarer::scoped_mut() - however, no need to go through bind() for changes in base RefCounted.
         // Any accesses to user objects (e.g. destruction if refc=0) would bind anyway.
+        //
+        // Might change implementation as follows -- but last time caused UB; investigate.
+        // pub(crate) unsafe fn as_ref_counted_unchecked(&mut self) -> &mut classes::RefCounted {
+        //     self.as_target_mut()
+        // }
+
+        let mut ref_counted = match self.ffi_cast::<classes::RefCounted>() {
+            Ok(cast_success) => cast_success,
+            Err(()) if self.is_null() => {
+                panic!("RawGd::with_ref_counted(): expected to inherit RefCounted, encountered null pointer");
+            }
+            Err(()) => {
+                // SAFETY: this branch implies non-null.
+                let gd_ref = unsafe { self.as_non_null() };
+                let class = gd_ref.dynamic_class_string();
+
+                // One way how this may panic is when invoked during destruction of a RefCounted object. The C++ `Object::object_cast_to()`
+                // function is virtual but cannot be dynamically dispatched in a C++ destructor.
+                panic!("RawGd::with_ref_counted(): expected to inherit RefCounted, but encountered {class}");
+            }
+        };
 
-        let mut cast_obj = self
-            .ffi_cast::<classes::RefCounted>()
-            .expect("object expected to inherit RefCounted");
+        let return_val = apply(ref_counted.as_dest_mut().as_target_mut());
 
-        // Using as_dest_mut() ensures that there is no refcount increment happening, i.e. any apply() function happens on *current* object.
-        // Apart from performance considerations, this is relevant when examining RefCounted::get_reference_count() -- otherwise we have an
-        // Observer effect, where reading the RefCounted object changes its reference count -- e.g. in Debug impl.
-        apply(cast_obj.as_dest_mut().as_target_mut())
+        // CastSuccess is forgotten when dropped, so no ownership transfer.
+        return_val
     }
 
-    // TODO replace the above with this -- last time caused UB; investigate.
-    // pub(crate) unsafe fn as_ref_counted_unchecked(&mut self) -> &mut classes::RefCounted {
-    //     self.as_target_mut()
-    // }
+    /// Enables outer `Gd` APIs or bypasses additional null checks, in cases where `RawGd` is guaranteed non-null.
+    ///
+    /// # Safety
+    /// `self` must not be null.
+    pub(crate) unsafe fn as_non_null(&self) -> &Gd<T> {
+        debug_assert!(
+            !self.is_null(),
+            "RawGd::as_non_null() called on null pointer; this is UB"
+        );
+
+        // SAFETY: layout of Gd<T> is currently equivalent to RawGd<T>.
+        unsafe { std::mem::transmute::<&RawGd<T>, &Gd<T>>(self) }
+    }
 
     pub(crate) fn as_object_ref(&self) -> &classes::Object {
         // SAFETY: Object is always a valid upcast target.
@@ -654,7 +691,7 @@ impl<T: GodotClass> Drop for RawGd<T> {
     fn drop(&mut self) {
         // No-op for manually managed objects
 
-        out!("RawGd::drop   <{}>", std::any::type_name::<T>());
+        out!("RawGd::drop:      {self:?}");
 
         // SAFETY: This `Gd` won't be dropped again after this.
         // If destruction is triggered by Godot, Storage already knows about it, no need to notify it
@@ -669,7 +706,7 @@ impl<T: GodotClass> Drop for RawGd<T> {
 
 impl<T: GodotClass> Clone for RawGd<T> {
     fn clone(&self) -> Self {
-        out!("RawGd::clone");
+        out!("RawGd::clone:     {self:?}  (before clone)");
 
         if self.is_null() {
             Self::null()
@@ -689,12 +726,7 @@ impl<T: GodotClass> Clone for RawGd<T> {
 
 impl<T: GodotClass> fmt::Debug for RawGd<T> {
     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
-        if self.is_null() {
-            return write!(f, "{} {{ null obj }}", std::any::type_name::<T>());
-        }
-
-        let gd = super::Gd::from_ffi(self.clone());
-        write!(f, "{gd:?}")
+        classes::debug_string_nullable(self, f, "RawGd")
     }
 }