Handle panics occurring in GDScript tests; trace logging

Author: Bromeon

godot-core/src/lib.rs

@@ -82,7 +82,7 @@ pub mod private {
             && *global_config.is_editor.get_or_init(is_editor)
     }
 
-    fn print_panic(err: Box<dyn std::any::Any + Send>) {
+    pub fn print_panic(err: Box<dyn std::any::Any + Send>) {
         if let Some(s) = err.downcast_ref::<&'static str>() {
             print_panic_message(s);
         } else if let Some(s) = err.downcast_ref::<String>() {

godot-core/src/obj/gd.rs

@@ -406,7 +406,8 @@ where
         let ref_counted = T::Mem::is_ref_counted(&self.raw);
         assert_ne!(
             ref_counted, Some(true),
-            "called free() on Gd<Object> which points to a RefCounted dynamic type; free() only supported for manually managed types."
+            "called free() on Gd<Object> which points to a RefCounted dynamic type; free() only supported for manually managed types\n\
+            object: {self:?}"
         );
 
         // If ref_counted returned None, that means the instance was destroyed

godot-core/src/obj/guards.rs

@@ -4,6 +4,8 @@
  * file, You can obtain one at https://mozilla.org/MPL/2.0/.
  */
 
+use godot_ffi::out;
+
 #[cfg(not(feature = "experimental-threads"))]
 use std::cell;
 use std::fmt::Debug;
@@ -31,6 +33,7 @@ impl<'a, T> GdRef<'a, T> {
 
     #[cfg(feature = "experimental-threads")]
     pub(crate) fn from_cell(cell_ref: sync::RwLockReadGuard<'a, T>) -> Self {
+        out!("GdRef init: {:?}", std::any::type_name::<T>());
         Self { cell_ref }
     }
 }
@@ -43,6 +46,12 @@ impl<T> Deref for GdRef<'_, T> {
     }
 }
 
+impl<T> Drop for GdRef<'_, T> {
+    fn drop(&mut self) {
+        out!("GdRef drop: {:?}", std::any::type_name::<T>());
+    }
+}
+
 // TODO Clone or Share
 
 // ----------------------------------------------------------------------------------------------------------------------------------------------
@@ -67,6 +76,7 @@ impl<'a, T> GdMut<'a, T> {
 
     #[cfg(feature = "experimental-threads")]
     pub(crate) fn from_cell(cell_ref: sync::RwLockWriteGuard<'a, T>) -> Self {
+        out!("GdMut init: {:?}", std::any::type_name::<T>());
         Self { cell_ref }
     }
 }
@@ -84,3 +94,9 @@ impl<T> DerefMut for GdMut<'_, T> {
         self.cell_ref.deref_mut()
     }
 }
+
+impl<T> Drop for GdMut<'_, T> {
+    fn drop(&mut self) {
+        out!("GdMut drop: {:?}", std::any::type_name::<T>());
+    }
+}

godot-core/src/obj/raw.rs

@@ -461,7 +461,8 @@ 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   <{}>", std::any::type_name::<T>());
+
         // SAFETY: This `Gd` wont be dropped again after this.
         let is_last = unsafe { T::Mem::maybe_dec_ref(self) }; // may drop
         if is_last {

godot-core/src/storage.rs

@@ -37,7 +37,7 @@ mod single_threaded {
     /// Manages storage and lifecycle of user's extension class instances.
     pub struct InstanceStorage<T: GodotClass> {
         user_instance: cell::RefCell<T>,
-        base: Base<T::Base>,
+        pub(super) base: Base<T::Base>,
 
         // Declared after `user_instance`, is dropped last
         pub(super) lifecycle: cell::Cell<Lifecycle>,
@@ -160,7 +160,7 @@ mod multi_threaded {
     /// Manages storage and lifecycle of user's extension class instances.
     pub struct InstanceStorage<T: GodotClass> {
         user_instance: sync::RwLock<T>,
-        base: Base<T::Base>,
+        pub(super) base: Base<T::Base>,
 
         // Declared after `user_instance`, is dropped last
         pub(super) lifecycle: AtomicLifecycle,
@@ -256,6 +256,12 @@ mod multi_threaded {
 }
 
 impl<T: GodotClass> InstanceStorage<T> {
+    pub fn debug_info(&self) -> String {
+        // Unlike get_gd(), this doesn't require special trait bounds.
+
+        format!("{:?}", self.base)
+    }
+
     #[must_use]
     pub fn into_raw(self) -> *mut Self {
         Box::into_raw(Box::new(self))
@@ -268,18 +274,20 @@ impl<T: GodotClass> InstanceStorage<T> {
         );
         self.lifecycle.set(Lifecycle::Destroying);
         out!(
-            "    mark;  self={:?}, val={:?}",
+            "    mark;  self={:?}, val={:?}, obj={:?}",
             self as *const _,
-            self.lifecycle.get()
+            self.lifecycle.get(),
+            self.base,
         );
     }
 
     #[inline(always)]
     pub fn destroyed_by_godot(&self) -> bool {
         out!(
-            "    is_d;  self={:?}, val={:?}",
+            "    is_d;  self={:?}, val={:?}, obj={:?}",
             self as *const _,
-            self.lifecycle.get()
+            self.lifecycle.get(),
+            self.base,
         );
         matches!(
             self.lifecycle.get(),
@@ -325,7 +333,9 @@ pub unsafe fn destroy_storage<T: GodotClass>(instance_ptr: sys::GDExtensionClass
 
     assert!(
         !(*raw).is_bound(),
-        "tried to destroy object while a bind() or bind_mut() call is active"
+        "tried to destroy object while a bind() or bind_mut() call is active\n  \
+        object: {}",
+        (*raw).debug_info()
     );
 
     let _drop = Box::from_raw(raw);

itest/godot/ManualFfiTests.gd

@@ -254,14 +254,14 @@ func test_custom_property():
 func test_custom_property_wrong_values_1():
 	var has_property: HasCustomProperty = HasCustomProperty.new()
 	disable_error_messages()
-	has_property.some_c_style_enum = 10
+	has_property.some_c_style_enum = 10 # Should fail.
 	enable_error_messages()
 	assert_fail("HasCustomProperty.some_c_style_enum should only accept integers in the range `(0 ..= 2)`")
 
 func test_custom_property_wrong_values_2():
 	var has_property: HasCustomProperty = HasCustomProperty.new()
 	disable_error_messages()
-	has_property.not_exportable = {"a": "hello", "b": Callable()}
+	has_property.not_exportable = {"a": "hello", "b": Callable()}  # Should fail.
 	enable_error_messages()
 	assert_fail("HasCustomProperty.not_exportable should only accept dictionaries with float values")
 

itest/godot/TestRunner.gd

@@ -89,7 +89,7 @@ class GDScriptTestCase:
 		var script: GDScript = suite.get_script()
 		return str(script.resource_path.get_file().get_basename(), ".gd")
 
-# Standard test case used for whenever something can be tested by just running a gdscript function.
+# Standard test case used for whenever something can be tested by just running a GDScript function.
 class GDScriptExecutableTestCase extends GDScriptTestCase:
 	func run():
 		# This is a no-op if the suite doesn't have this property.

itest/rust/src/framework/runner.rs

@@ -153,20 +153,40 @@ impl IntegrationTests {
             let test_case = get_property(&test, "method_name");
 
             print_test_pre(&test_case, test_file.clone(), &mut last_file, true);
-            let result = test.call("run", &[]);
-            // In case a test needs to disable error messages to ensure it runs properly.
+
+            // If GDScript invokes Rust code that fails, the panic would break through; catch it.
+            // TODO(bromeon): use try_call() once available.
+            let result = std::panic::catch_unwind(|| test.call("run", &[]));
+
+            // In case a test needs to disable error messages, to ensure it runs properly.
             Engine::singleton().set_print_error_messages(true);
 
             if let Some(duration) = get_execution_time(&test) {
                 extra_duration += duration;
             }
-            let success = result.try_to::<bool>().unwrap_or_else(|_| {
-                panic!("GDScript test case {test} returned non-bool: {result}")
-            });
-            for error in get_errors(&test).iter_shared() {
-                godot_error!("{error}");
-            }
-            let outcome = TestOutcome::from_bool(success);
+
+            let outcome = match result {
+                Ok(result) => {
+                    let success = result.try_to::<bool>().unwrap_or_else(|_| {
+                        // Not a failing test, but an error in the test setup.
+                        panic!("GDScript test case {test} returned non-bool: {result}")
+                    });
+
+                    for error in get_errors(&test).iter_shared() {
+                        godot_error!("{error}");
+                    }
+                    TestOutcome::from_bool(success)
+                }
+                Err(e) => {
+                    // TODO(bromeon) should this be a fatal error, i.e. panicking and aborting tests -> bad test setup?
+                    // If GDScript receives panics, this can also happen in user code that is _not_ invoked from Rust, and thus a panic
+                    // could not be caught, causing UB at the Godot FFI boundary (in practice, this will be a defined Godot crash with
+                    // stack trace though).
+                    godot_error!("GDScript test panicked");
+                    godot::private::print_panic(e);
+                    TestOutcome::Failed
+                }
+            };
 
             self.update_stats(&outcome, &test_file, &test_case);
             print_test_post(&test_case, outcome);