Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Potential use-after-free in AnimationMixer due to dereferencing pointers to foreign objects, which may have been freed. #85365

Closed
unfa opened this issue Nov 25, 2023 · 19 comments · Fixed by #86687

Comments

@unfa
Copy link

unfa commented Nov 25, 2023

Godot version

git master [1ba920f]

System information

Arch Linux, KDE 5, Radeon RX6800XT, X11

Issue description

The act of shooting a Plasma Gun in Liblast causes the engine to segfault not long after.
The backtrace point to AnimationMixer.
I a,m seeing a lot of errors related to animations for that weapon, but I don't expect the engine to segfault from that.

Backtrace:

Thread 1 "godot.linuxbsd." received signal SIGSEGV, Segmentation fault.
StringName::hash (this=<optimized out>) at ./core/string/string_name.h:136
136                             return _data->hash;
(gdb) bt
#0  StringName::hash (this=<optimized out>) at ./core/string/string_name.h:136
#1  HashMapHasherDefault::hash (p_string_name=...) at ./core/templates/hashfuncs.h:314
#2  HashMap<StringName, ClassDB::ClassInfo, HashMapHasherDefault, HashMapComparatorDefault<StringName>, DefaultTypedAllocator<HashMapElement<StringName, ClassDB::ClassInfo> > >::_hash (p_key=..., this=0x55555c189540 <ClassDB::classes>)
    at ./core/templates/hash_map.h:85
#3  HashMap<StringName, ClassDB::ClassInfo, HashMapHasherDefault, HashMapComparatorDefault<StringName>, DefaultTypedAllocator<HashMapElement<StringName, ClassDB::ClassInfo> > >::_lookup_pos (p_key=..., r_pos=<synthetic pointer>: <optimized out>, 
    this=0x55555c189540 <ClassDB::classes>) at ./core/templates/hash_map.h:106
#4  HashMap<StringName, ClassDB::ClassInfo, HashMapHasherDefault, HashMapComparatorDefault<StringName>, DefaultTypedAllocator<HashMapElement<StringName, ClassDB::ClassInfo> > >::getptr (this=0x55555c189540 <ClassDB::classes>, p_key=...)
    at ./core/templates/hash_map.h:300
#5  0x00005555599a0773 in ClassDB::set_property (p_object=p_object@entry=0x555573eb7600, p_property=..., p_value=..., 
    r_valid=r_valid@entry=0x0) at core/object/class_db.cpp:1208
#6  0x00005555599c1dd4 in Object::set (this=this@entry=0x555573eb7600, p_name=..., p_value=..., r_valid=0x0)
    at core/object/object.cpp:257
#7  0x00005555599c39e9 in Object::set_indexed (this=this@entry=0x555573eb7600, p_names=..., p_value=..., 
    r_valid=r_valid@entry=0x0) at core/object/object.cpp:407
#8  0x0000555558320300 in AnimationMixer::_blend_apply (this=this@entry=0x555573eb7fc0)
    at scene/animation/animation_mixer.cpp:1711
#9  0x0000555558334df1 in AnimationMixer::_process_animation (this=0x555573eb7fc0, p_delta=0.017045999999999999, 
    p_update_only=<optimized out>) at scene/animation/animation_mixer.cpp:940
#10 0x0000555558377d33 in AnimationMixer::_notificationv (p_reversed=false, p_notification=25, this=0x555573eb7fc0)
    at scene/animation/animation_mixer.h:44
#11 AnimationPlayer::_notificationv (this=0x555573eb7fc0, p_notification=25, p_reversed=false)
    at scene/animation/animation_player.h:39
#12 0x00005555599bcdf0 in Object::notification (this=0x555573eb7fc0, p_notification=25, p_reversed=false)
    at core/object/object.cpp:837
#13 0x0000555557b09c91 in SceneTree::_process_group (this=0x5555601349d0, p_group=0x555560134c28, p_physics=false)
    at scene/main/scene_tree.cpp:948
#14 0x0000555557b0a372 in SceneTree::_process (this=this@entry=0x5555601349d0, p_physics=p_physics@entry=false)
    at scene/main/scene_tree.cpp:1028
#15 0x0000555557b0a952 in SceneTree::process (this=0x5555601349d0, p_time=0.017045999999999999) at scene/main/scene_tree.cpp:508
--Type <RET> for more, q to quit, c to continue without paging--c
#16 0x0000555555b21b65 in Main::iteration () at main/main.cpp:3636
#17 0x0000555555ab5531 in OS_LinuxBSD::run (this=this@entry=0x7fffffffd280) at platform/linuxbsd/os_linuxbsd.cpp:933
#18 0x0000555555aa4f58 in main (argc=<optimized out>, argv=0x7fffffffd858) at platform/linuxbsd/godot_linuxbsd.cpp:74

Steps to reproduce

Clone Liblast repository:

git clone https://codeberg.org/Liblast/Liblast.git
cd Liblast
git lfs install
git pull

Open the game in Godot 4.2 editor to import all media (if they all fail, check LFS again)
After the game is imported, run via GDB automatically starting a game:

GODOT_BINARY="./godot.linuxbsd.editor.x86_64" # replace with your debug godot binary
gdb -ex run --args $GODOT_BINARY  --path ./Game/ --host CP1

Once the map loads, click on the "start now" button to avoid waiting 10 sec.
After that, the bots will do their thing and shoot their Plasma Guns causing a crash.

The crash seems to most often happen when shooting that weapon - hitscan weapons don't seem to cause it.

Minimal reproduction project

I am afraid I don't have one just yet.

@unfa
Copy link
Author

unfa commented Nov 25, 2023

I found another segfault, and I am wondering if it could be related (because of HashMap being mentioned in both).
This happens so far only with map CP1, when tested with MapA instead I got the initial crash with AnimationMixer instead.

Run this command to reproduce:

GODOT_BINARY="./godot.linuxbsd.editor.x86_64" # replace with your debug godot binary
gdb -ex run --args $GODOT_BINARY --headless --path ./Game/ --dedicated-host CP1

Very quickly this causes a segfault after the game level is loaded:

Thread 1 "godot.linuxbsd." received signal SIGSEGV, Segmentation fault.
HashSet<RendererSceneCull::Instance*, HashMapHasherDefault, HashMapComparatorDefault<RendererSceneCull::Instance*> >::insert (this=this@entry=0x38, p_key=@0x7fffffffb9f8: 0x5555665dd838) at ./core/templates/hash_set.h:408
408                     uint32_t pos = _insert(p_key);
(gdb) bt
#0  HashSet<RendererSceneCull::Instance*, HashMapHasherDefault, HashMapComparatorDefault<RendererSceneCull::Instance*> >::insert (this=this@entry=0x38, p_key=@0x7fffffffb9f8: 0x5555665dd838) at ./core/templates/hash_set.h:408
#1  0x0000555559316b14 in RendererSceneCull::instance_geometry_set_lightmap (this=0x55555ca40270, p_instance=..., p_lightmap=..., p_lightmap_uv_scale=..., p_slice_index=0) at servers/rendering/renderer_scene_cull.cpp:1461
#2  0x0000555557ff5de7 in LightmapGI::_assign_lightmaps (this=0x55556a26fb00) at scene/3d/lightmap_gi.cpp:1337
#3  0x00005555599bcdf0 in Object::notification (this=0x55556a26fb00, p_notification=27, p_reversed=false) at core/object/object.cpp:837
#4  0x0000555557ac0d4a in Node::_propagate_ready (this=0x55556a26fb00) at scene/main/node.cpp:227
#5  0x0000555557ac0d24 in Node::_propagate_ready (this=this@entry=0x55555df01b40) at scene/main/node.cpp:222
#6  0x0000555557ac4417 in Node::_set_tree (this=0x55555df01b40, p_tree=0x55555da009d0) at scene/main/node.cpp:2938
#7  0x0000555557ad7396 in Node::_add_child_nocheck (this=0x55555e0bb8e0, p_child=<optimized out>, p_name=..., p_internal_mode=Node::INTERNAL_MODE_DISABLED) at scene/main/node.cpp:1394
#8  0x0000555557aeacbc in call_with_variant_args_helper<__UnexistingClass, Node*, bool, Node::InternalMode, 0ul, 1ul, 2ul> (r_error=..., p_args=0x7fffffffbc80, p_method=<optimized out>, p_instance=<optimized out>) at ./core/variant/binder_common.h:303
#9  call_with_variant_args_dv<__UnexistingClass, Node*, bool, Node::InternalMode> (default_values=..., r_error=..., p_argcount=<optimized out>, p_args=<optimized out>, p_method=<optimized out>, p_instance=<optimized out>) at ./core/variant/binder_common.h:450
#10 MethodBindT<Node*, bool, Node::InternalMode>::call (this=<optimized out>, p_object=<optimized out>, p_args=<optimized out>, p_arg_count=<optimized out>, r_error=...) at ./core/object/method_bind.h:335
#11 0x0000555555e2d700 in GDScriptFunction::call (this=<optimized out>, p_instance=<optimized out>, p_instance@entry=0x55555dfa27b0, p_args=p_args@entry=0x7fffffffc3a8, p_argcount=<optimized out>, r_err=..., p_state=<optimized out>) at modules/gdscript/gdscript_vm.cpp:1796
#12 0x0000555555ce9f2f in GDScriptInstance::callp (this=0x55555dfa27b0, p_method=..., p_args=<optimized out>, p_argcount=<optimized out>, r_error=...) at modules/gdscript/gdscript.cpp:1937
#13 0x00005555599bf01c in Object::callp (this=0x55555e0bb8e0, p_method=..., p_args=0x7fffffffc3a8, p_argcount=1, r_error=...) at core/object/object.cpp:753
#14 0x000055555976337a in Variant::callp (this=<optimized out>, p_method=..., p_args=0x7fffffffc3a8, p_argcount=1, r_ret=..., r_error=...) at core/variant/variant_call.cpp:1168
#15 0x0000555555e404dc in GDScriptFunction::call (this=<optimized out>, p_instance=<optimized out>, p_instance@entry=0x55555dfa27b0, p_args=p_args@entry=0x7fffffffc948, p_argcount=<optimized out>, r_err=..., p_state=<optimized out>) at modules/gdscript/gdscript_vm.cpp:1704
#16 0x0000555555ce9f2f in GDScriptInstance::callp (this=0x55555dfa27b0, p_method=..., p_args=<optimized out>, p_argcount=<optimized out>, r_error=...) at modules/gdscript/gdscript.cpp:1937
#17 0x00005555599bf01c in Object::callp (this=0x55555e0bb8e0, p_method=..., p_args=0x7fffffffc948, p_argcount=1, r_error=...) at core/object/object.cpp:753
#18 0x000055555976337a in Variant::callp (this=<optimized out>, p_method=..., p_args=0x7fffffffc948, p_argcount=1, r_ret=..., r_error=...) at core/variant/variant_call.cpp:1168
#19 0x0000555555e404dc in GDScriptFunction::call (this=<optimized out>, p_instance=<optimized out>, p_instance@entry=0x55555dfa27b0, p_args=p_args@entry=0x0, p_argcount=<optimized out>, r_err=..., p_state=<optimized out>) at modules/gdscript/gdscript_vm.cpp:1704
#20 0x0000555555ce9f2f in GDScriptInstance::callp (this=0x55555dfa27b0, p_method=..., p_args=<optimized out>, p_argcount=<optimized out>, r_error=...) at modules/gdscript/gdscript.cpp:1937
#21 0x0000555557ad631b in Node::_gdvirtual__ready_call<false> (this=0x55555e0bb8e0) at scene/main/node.h:322
#22 Node::_notification (this=0x55555e0bb8e0, p_notification=<optimized out>) at scene/main/node.cpp:187
#23 0x000055555806550d in Node::_notificationv (p_reversed=false, p_notification=13, this=0x55555e0bb8e0) at ./scene/main/node.h:49
#24 Node3D::_notificationv (this=0x55555e0bb8e0, p_notification=13, p_reversed=<optimized out>) at scene/3d/node_3d.h:52
#25 0x00005555599bcdf0 in Object::notification (this=0x55555e0bb8e0, p_notification=13, p_reversed=false) at core/object/object.cpp:837
#26 0x0000555557ac0d86 in Node::_propagate_ready (this=this@entry=0x55555e0bb8e0) at scene/main/node.cpp:231
#27 0x0000555557ac4417 in Node::_set_tree (this=0x55555e0bb8e0, p_tree=0x55555da009d0) at scene/main/node.cpp:2938
#28 0x0000555557ad7396 in Node::_add_child_nocheck (this=0x55555da01560, p_child=<optimized out>, p_name=..., p_internal_mode=Node::INTERNAL_MODE_DISABLED) at scene/main/node.cpp:1394
#29 0x0000555557aeacbc in call_with_variant_args_helper<__UnexistingClass, Node*, bool, Node::InternalMode, 0ul, 1ul, 2ul> (r_error=..., p_args=0x7fffffffcea0, p_method=<optimized out>, p_instance=<optimized out>) at ./core/variant/binder_common.h:303
#30 call_with_variant_args_dv<__UnexistingClass, Node*, bool, Node::InternalMode> (default_values=..., r_error=..., p_argcount=<optimized out>, p_args=<optimized out>, p_method=<optimized out>, p_instance=<optimized out>) at ./core/variant/binder_common.h:450
#31 MethodBindT<Node*, bool, Node::InternalMode>::call (this=<optimized out>, p_object=<optimized out>, p_args=<optimized out>, p_arg_count=<optimized out>, r_error=...) at ./core/object/method_bind.h:335
#32 0x00005555599beeb7 in Object::callp (this=0x55555da01560, p_method=..., p_args=0x7fffffffd000, p_argcount=<optimized out>, r_error=...) at core/object/object.cpp:775
#33 0x000055555970bdc4 in Callable::callp (this=0x55555d7994c8, p_arguments=0x7fffffffd000, p_argcount=1, r_return_value=..., r_call_error=...) at core/variant/callable.cpp:69
#34 0x00005555599b73a2 in CallQueue::_call_function (this=this@entry=0x55555c5f6580, p_callable=..., p_args=p_args@entry=0x55555d7994e0, p_argcount=1, p_show_error=true) at core/object/message_queue.cpp:219
#35 0x00005555599ba90d in CallQueue::flush (this=0x55555c5f6580) at core/object/message_queue.cpp:324
#36 0x0000555557b0a65b in SceneTree::physics_process (this=0x55555da009d0, p_time=0.016666666666666666) at scene/main/scene_tree.cpp:471
#37 0x0000555555b21a74 in Main::iteration () at main/main.cpp:3598
#38 0x0000555555ab5531 in OS_LinuxBSD::run (this=this@entry=0x7fffffffd270) at platform/linuxbsd/os_linuxbsd.cpp:933
#39 0x0000555555aa4f58 in main (argc=<optimized out>, argv=0x7fffffffd848) at platform/linuxbsd/godot_linuxbsd.cpp:7

@Calinou
Copy link
Member

Calinou commented Nov 25, 2023

cc @TokageItLab

@TokageItLab
Copy link
Member

TokageItLab commented Nov 26, 2023

I can't tell anything without MRP.

Guessing from the stack trace, there possibly could be a problem with the Continuous interpolation of StringName #84815. Or it could be hashmap-related, and the cache could be corrupted when switching animations by method track or something.

In any case, I cannot say for sure since we do not know what you are doing.

@akien-mga akien-mga changed the title SEGFAULT in AnimationMixer Segfault in AnimationMixer::_blend_apply Nov 26, 2023
@akien-mga
Copy link
Member

akien-mga commented Nov 26, 2023

I can't tell anything without MRP.

The full project is open source and reproduces the crash, I just tested to confirm following the steps to reproduce in the OP.

So that can be used to debug, even if it's a bit heavy, at least it lets you get into a debugger and inspect what is wrong.

@unfa If the issue is confirmed to always happen when firing the Plasma Gun, maybe you can extract a more minimal project with just a bot shooting this gun, with their animations.

@yosoyfreeman
Copy link

I can't tell anything without MRP.

Guessing from the stack trace, there possibly could be a problem with the Continuous interpolation of StringName #84815. Or it could be hashmap-related, and the cache could be corrupted when switching animations by method track or something.

In any case, I cannot say for sure since we do not know what you are doing.

Hi! I always try to create a minimal reproduction project for the bugs we find on Liblast, which is made in a big part to test the engine and help with the reporting, testing, feedback etc. However, we are mostly 2 learning devs and reproducing some of this more technical issues is out of my scope, as sometimes i'm unable to separate the problematic part of the game from the other parts without the project breaking in other way or i can not get the same error while trying to reproduce them from scratch because i can not replicate it. So i apology for the not ideal conditions, but please have in mind this is not because i didn't bother to, but because i could not.

While i understand the project is heavy, it is totally open source and so is the toolchain used, so it can be used for this scenarios without any trouble with licensing and having the whole picture available, from the asset sources to the final project, so complex issues can be tracked to any point. For testing purposes, all you need from the repo is contained inside the game folder, so you can get that and skip all the other files, which are a big part of the total size.

@unfa
Copy link
Author

unfa commented Nov 26, 2023

Yeah, I totally agree with you, @yosoyfreeman - the size of Liblast as a project allows us to find such weird engine bugs - thanks to the relative complexity - but it also makes it harder to isolate the issues.

@akien-mga I will try to do that, and see what can I get.
I have a test scene that shoots a weapon (with no physical character holding it) - let's see how that goes.

@TokageItLab
Copy link
Member

TokageItLab commented Nov 26, 2023

Ah, I had never heard that there was such an open source project. But it takes a lot of effort to isolate the source of a bug from a large project, so the reproduction project is the smaller the better.

BTW, this may be a similar/related issue?

@unfa
Copy link
Author

unfa commented Nov 26, 2023

@TokageItLab Here's an MRP:

PlasmaSecondaryCrash MRP.zip

I've ripped out the guts from Liblast and managed to stop all the bleeding for long enough to reproduce this crash.

@TokageItLab
Copy link
Member

@unfa Thanks! I tried that, but it crashed even without playing the animation, so the animation may not be the actual cause..

@akien-mga
Copy link
Member

BTW, this may be a similar/related issue?

I tested this hypothesis, it doesn't fix this crash, but indeed the final crash location might be related. In some logs I've seen StringName::hash(), though gdb doesn't go all the way there for some reason for me now.

The PlasmaSecondaryCrash MRP crashes for me with this stacktrace:

(gdb) bt
#0  0x0000000000000621 in ?? ()
#1  0x0000000009e58bc4 in Object::set (this=0xd911770, p_name=..., p_value=..., r_valid=0x0) at ./core/object/object.cpp:301
#2  0x0000000009e5905e in Object::set_indexed (this=0xd911770, p_names=..., p_value=..., r_valid=0x0) at ./core/object/object.cpp:407
#3  0x000000000870371c in AnimationMixer::_blend_apply (this=0xdd62320) at ./scene/animation/animation_mixer.cpp:1711
#4  0x00000000086fc5d9 in AnimationMixer::_process_animation (this=0xdd62320, p_delta=0.016666666666666666, p_update_only=false) at ./scene/animation/animation_mixer.cpp:940
#5  0x0000000008705014 in AnimationMixer::_notification (this=0xdd62320, p_what=25) at ./scene/animation/animation_mixer.cpp:2034
#6  0x0000000008731a92 in AnimationMixer::_notificationv (this=0xdd62320, p_notification=25, p_reversed=false) at ./scene/animation/animation_mixer.h:44
#7  0x00000000087405d5 in AnimationPlayer::_notificationv (this=0xdd62320, p_notification=25, p_reversed=false) at ./scene/animation/animation_player.h:39
#8  0x0000000009e5abda in Object::notification (this=0xdd62320, p_notification=25, p_reversed=false) at ./core/object/object.cpp:837
#9  0x0000000007e096e6 in SceneTree::_process_group (this=0xd39ea10, p_group=0xd39ec68, p_physics=false) at ./scene/main/scene_tree.cpp:948
#10 0x0000000007e09c85 in SceneTree::_process (this=0xd39ea10, p_physics=false) at ./scene/main/scene_tree.cpp:1028
#11 0x0000000007e07bc4 in SceneTree::process (this=0xd39ea10, p_time=0.016666666666666666) at ./scene/main/scene_tree.cpp:508
#12 0x000000000579a28c in Main::iteration () at main/main.cpp:3636
#13 0x0000000005713a0e in OS_LinuxBSD::run (this=0x7fffffffcfb0) at platform/linuxbsd/os_linuxbsd.cpp:933
#14 0x000000000570c480 in main (argc=1, argv=0x7fffffffd598) at platform/linuxbsd/godot_linuxbsd.cpp:74

@unfa Thanks! I tried that, but it crashed even without playing the animation, so the animation may not be the actual cause..

What stacktrace do you get? There might be several bugs, but at least the crash originating in AnimationMixer::_blend_apply seems fairly easy to replicate, and even if it's crashing in StringName::hash(), it is likely due to invalid data being passed by AnimationMixer.

@akien-mga
Copy link
Member

akien-mga commented Nov 27, 2023

Since the backtrace isn't super helpful to really understand what's causing the crash exactly, I added some good old printf:

diff --git a/core/object/object.cpp b/core/object/object.cpp
index 40df13849b..6437ebca05 100644
--- a/core/object/object.cpp
+++ b/core/object/object.cpp
@@ -298,6 +298,7 @@ void Object::set(const StringName &p_name, const Variant &p_value, bool *r_valid
 #endif
 
 	// Something inside the object... :|
+	print_line(vformat("Object: %s\tProperty: %s\tValue: %s", to_string(), p_name, p_value.operator String()));
 	bool success = _setv(p_name, p_value);
 	if (success) {
 		if (r_valid) {

That spams a lot, but lets me see what object/property/value combo it's crashing on (which gdb seemed to have trouble extracting, or I don't know how to use it :D):

Object: Explosion:<Node3D#60414756587>	Property: damage_amount	Value: 25
Object: Explosion:<Node3D#60414756587>	Property: push_force	Value: 12
Object: Explosion:<Node3D#60414756587>	Property: blast_radius	Value: 2.5
Object: Explosion:<Node3D#60414756587>	Property: blast_duration	Value: 0.1
Object: <AnimationPlayer#60817409893>	Property: libraries	Value: { "": <AnimationLibrary#-9223371986724452699> }
Object: Halo:<Node3D#60834187110>	Property: SoundClip	Value: res://Assets/SFX/Weapons_BulletHitWall_01.wav
Object: Halo:<Node3D#60834187110>	Property: RandomizePitch	Value: 0.1
WARNING: Node 'SoundPlayer/AudioStreamPlayer3D' was modified from inside an instance, but it has vanished.
     at: instantiate (./scene/resources/packed_scene.cpp:231)
Object: <AnimationPlayer#60884518761>	Property: libraries	Value: { "": <AnimationLibrary#-9223371986640566614> }

================================================================
handle_crash: Program crashed with signal 11

Reproduced a few times, it seems pretty consistent (with different Node IDs, but somehow the same numbers of AnimationLibrary).

The warning also appears before in the logs, but seems to consistently appear before the last set_indexed on libraries.

Here's the full output:
output.log


More printf debugging, got a bit further, it's crashing after setting a script property. That's probably still not what causes the crash, it's just how close I manage to get to the issue:

diff --git a/core/object/object.cpp b/core/object/object.cpp
index 40df13849b..f0cb37bdde 100644
--- a/core/object/object.cpp
+++ b/core/object/object.cpp
@@ -227,6 +227,7 @@ void Object::set(const StringName &p_name, const Variant &p_value, bool *r_valid
 #endif
 
 	if (script_instance) {
+		print_line(vformat("script_instance->set: Object: %s\tProperty: %s\tValue: %s", to_string(), p_name, p_value.operator String()));
 		if (script_instance->set(p_name, p_value)) {
 			if (r_valid) {
 				*r_valid = true;
@@ -298,7 +299,11 @@ void Object::set(const StringName &p_name, const Variant &p_value, bool *r_valid
 #endif
 
 	// Something inside the object... :|
+	print_line(vformat("_setv: Object: %s\tProperty: %s\tValue: %s", to_string(), p_name, p_value.operator String()));
 	bool success = _setv(p_name, p_value);
+	if (p_name == "libraries") {
+		print_line("library");
+	}
 	if (success) {
 		if (r_valid) {
 			*r_valid = true;
WARNING: Node 'SoundPlayer/AudioStreamPlayer3D' was modified from inside an instance, but it has vanished.
     at: instantiate (./scene/resources/packed_scene.cpp:231)
_setv: Object: <AnimationPlayer#64508397417>    Property: libraries     Value: { "": <AnimationLibrary#-9223371986640566614> }
library
script_instance->set: Object: <RefCounted#-9223371991086529163> Property: enabled       Value: false
script_instance->set: Object: <RefCounted#-9223371991069751946> Property: enabled       Value: true
script_instance->set: Object: <RefCounted#-9223371991069751946> Property: changed       Value: true
script_instance->set: Object: <RefCounted#-9223371992445483830> Property: enabled       Value: false
script_instance->set: Object: <RefCounted#-9223371992445483830> Property: changed       Value: false
script_instance->set: Object: <RefCounted#-9223371992428706602> Property: enabled       Value: true
script_instance->set: Object: <RefCounted#-9223371992428706602> Property: changed       Value: false
script_instance->set: Object: <RefCounted#-9223371992445483830> Property: changed       Value: false
script_instance->set: Object: Barrel2:<Node3D#44627396089>      Property: trigger_is_held       Value: false
script_instance->set: Object: <RefCounted#-9223371992428706602> Property: changed       Value: false
script_instance->set: Object: Slide2:<Node3D#44795168259>       Property: slide_rollback_progress       Value: 0.43640959262848
script_instance->set: Object: Slide2:<Node3D#44795168259>       Property: slide_rollback_progress       Value: 0.45925205945969
script_instance->set: Object: Slide2:<Node3D#44795168259>       Property: slide_rollback_progress       Value: 0.47819149494171
script_instance->set: Object: <RefCounted#-9223371991086529163> Property: enabled       Value: true
script_instance->set: Object: <RefCounted#-9223371991069751946> Property: enabled       Value: false
script_instance->set: Object: <RefCounted#-9223371991069751946> Property: changed       Value: true
script_instance->set: Object: <RefCounted#-9223371992445483830> Property: enabled       Value: true
script_instance->set: Object: <RefCounted#-9223371992445483830> Property: changed       Value: false
script_instance->set: Object: <RefCounted#-9223371992428706602> Property: enabled       Value: false
script_instance->set: Object: <RefCounted#-9223371992428706602> Property: changed       Value: false
script_instance->set: Object: <RefCounted#-9223371992445483830> Property: changed       Value: false
script_instance->set: Object: Barrel2:<Node3D#44627396089>      Property: trigger_is_held       Value: true
script_instance->set: Object: <RefCounted#-9223371992428706602> Property: changed       Value: false
script_instance->set: Object: Slide2:<Node3D#44795168259>       Property: slide_rollback_progress       Value: 0.49891084432602
script_instance->set: Object: Slide2:<Node3D#44795168259>       Property: slide_rollback_progress       Value: 0.51974415779114
script_instance->set: Object: Slide2:<Node3D#44795168259>       Property: slide_rollback_progress       Value: 0.54057747125626
script_instance->set: Object: <RefCounted#-9223371991086529163> Property: enabled       Value: false
script_instance->set: Object: <RefCounted#-9223371991069751946> Property: enabled       Value: true
script_instance->set: Object: <RefCounted#-9223371991069751946> Property: changed       Value: true
script_instance->set: Object: <RefCounted#-9223371992445483830> Property: enabled       Value: false
script_instance->set: Object: <RefCounted#-9223371992445483830> Property: changed       Value: false
script_instance->set: Object: <RefCounted#-9223371992428706602> Property: enabled       Value: true
script_instance->set: Object: <RefCounted#-9223371992428706602> Property: changed       Value: false
script_instance->set: Object: <RefCounted#-9223371992445483830> Property: changed       Value: false
script_instance->set: Object: Barrel2:<Node3D#44627396089>      Property: trigger_is_held       Value: false
script_instance->set: Object: <RefCounted#-9223371992428706602> Property: changed       Value: false
script_instance->set: Object: Slide2:<Node3D#44795168259>       Property: slide_rollback_progress       Value: 0.56141078472137

Thread 1 "godot-git" received signal SIGSEGV, Segmentation fault.

@TokageItLab
Copy link
Member

TokageItLab commented Nov 27, 2023

I couldn't figure out how to get a stack trace in my environment, so I send a modified project. It is not always reproducible, but sometimes crashes randomly after a few attempts at this.

PlasmaSecondaryCrash_noanim.zip

@akien-mga
Copy link
Member

akien-mga commented Nov 27, 2023

That noanim MRP crashes the same way for me as @unfa's, and with the same stacktrace - so still in AnimationMixer.
Exact same logs as in #85365 (comment)

BTW the crash in both MRPs seems to always happen at the 6th explosion.

I tried poking at the scenes in the MRP but many of the affected scenes and scripts are broken due to the process of gutting them out of the full game. So I'm not sure how representative the MRP still is of an actionable problem beside "things might crash when half the scenes and scripts are broken".

@akien-mga
Copy link
Member

Tested again with the full Liblast project (and #85388 merged locally as it seemed possibly related), and I still get the crash.
With my tweaked build using the above diff, I get these logs:

setv: Object: Flash:<MeshInstance3D#1793031418085>     Property: shader_uniforms/Energy        Value: (0, 0, 0, 1)
script_instance->set: Object: -10:<CharacterBody3D#1784173045998>       Property: global_transform      Value: [X: (-0.998903, 0, -0.046833), Y: (0, 1, 0), Z: (0.046833, 0, -0.998903), O: (24.17453, 8.001047, -22.72682)]
script_instance->set: Object: <RefCounted#-9223367204194477496> Property: aim   Value: (0.005752, -0.002225)
script_instance->set: Object: <RefCounted#-9223367204194477496> Property: index Value: 293
script_instance->set: Object: <RefCounted#-9223367204194477496> Property: frame Value: 3053
script_instance->set: Object: -10:<CharacterBody3D#1784173045998>       Property: global_transform      Value: [X: (-0.999156, 0, -0.041087), Y: (0, 1, 0), Z: (0.041087, 0, -0.999156), O: (24.17453, 8.001047, -22.72682)]

Thread 1 "godot-git" received signal SIGSEGV, Segmentation fault.
0x0000007400000070 in ?? ()

(gdb) bt
#0  0x0000007400000070 in ?? ()
#1  0x0000000009e58b24 in Object::set (this=0x20152d50, p_name=..., p_value=..., r_valid=0x0) at ./core/object/object.cpp:245
#2  0x0000000009e59418 in Object::set_indexed (this=0x20152d50, p_names=..., p_value=..., r_valid=0x0) at ./core/object/object.cpp:412
#3  0x000000000870379c in AnimationMixer::_blend_apply (this=0x20153370) at ./scene/animation/animation_mixer.cpp:1711
#4  0x00000000086fc659 in AnimationMixer::_process_animation (this=0x20153370, p_delta=0.13266700000000001, p_update_only=false) at ./scene/animation/animation_mixer.cpp:940
#5  0x0000000008705094 in AnimationMixer::_notification (this=0x20153370, p_what=25) at ./scene/animation/animation_mixer.cpp:2034
#6  0x0000000008731b12 in AnimationMixer::_notificationv (this=0x20153370, p_notification=25, p_reversed=false) at ./scene/animation/animation_mixer.h:44
#7  0x0000000008740655 in AnimationPlayer::_notificationv (this=0x20153370, p_notification=25, p_reversed=false) at ./scene/animation/animation_player.h:39
#8  0x0000000009e5af94 in Object::notification (this=0x20153370, p_notification=25, p_reversed=false) at ./core/object/object.cpp:842
#9  0x0000000007e09766 in SceneTree::_process_group (this=0xd9cabe0, p_group=0xd9cae38, p_physics=false) at ./scene/main/scene_tree.cpp:948
#10 0x0000000007e09d05 in SceneTree::_process (this=0xd9cabe0, p_physics=false) at ./scene/main/scene_tree.cpp:1028
#11 0x0000000007e07c44 in SceneTree::process (this=0xd9cabe0, p_time=0.13266700000000001) at ./scene/main/scene_tree.cpp:508
#12 0x000000000579a30c in Main::iteration () at main/main.cpp:3636
#13 0x0000000005713a8e in OS_LinuxBSD::run (this=0x7fffffffcf70) at platform/linuxbsd/os_linuxbsd.cpp:933
#14 0x000000000570c500 in main (argc=5, argv=0x7fffffffd558) at platform/linuxbsd/godot_linuxbsd.cpp:74

That object.cpp line in my build is this:
image

It's starting to sound related to #85155.

Overall this kind of crash is likely some dangling pointers to invalid data or memory corruption.

@unfa
Copy link
Author

unfa commented Nov 27, 2023

I wonder... IIRC the animations for the PlasmaExplosion hit effect call queue_free() on multiple components (I did this in hope of reducing load of processing nodes that are no longer used). Maybe the crash occurs after Nth node is freed this way?

@bitsawer
Copy link
Member

I tested the PlasmaSecondaryCrash_noanim.zip project with ASAN build on Windows 10 on current master (eda44bf). The crash (heap-use-after-free) happens here because the object this pointer has been previously freed:

_edited = true;

The more relevant call is a few stack levels below in AnimationMixer::_blend_apply(). It crashes because t->object has been freed previously and now points to invalid (freed) memory:

t->object->set_indexed(t->subpath, Animation::cast_from_blendwise(t->value, t->init_value.get_type()));

More detailed stack report below, uncollapse to see it. Seems like one potential hint is that the memory was allocated in Object* ClassDB::creator<OmniLight3D>(). Sometimes it changes to creator<GPUParticlesAttractorSphere3D>().

ASAN crash report
ERROR: AddressSanitizer: heap-use-after-free on address 0x12b85b6509fa at pc 0x7ff62b63bf3a bp 0x00df5a9fb020 sp 0x00df5a9fb068
WRITE of size 1 at 0x12b85b6509fa thread T0
    #0 0x7ff62b63bf39 in Object::set(StringName const&, Variant const&, bool*) E:/Repositories/godot/core\object/object.cpp:226:10
    #1 0x7ff62b6400f6 in Object::set_indexed(Vector<StringName> const&, Variant const&, bool*) E:/Repositories/godot/core\object/object.cpp:407:3
    #2 0x7ff636480476 in AnimationMixer::_blend_apply() E:/Repositories/godot/scene\animation/animation_mixer.cpp:1711:16
    #3 0x7ff636450e21 in AnimationMixer::_process_animation(double, bool) E:/Repositories/godot/scene\animation/animation_mixer.cpp:940:3
    #4 0x7ff636490e87 in AnimationMixer::_notification(int) E:/Repositories/godot/scene\animation/animation_mixer.cpp:2034:5
    #5 0x7ff6364cc61c in AnimationMixer::_notificationv(int, bool) E:/Repositories/godot/scene\animation/animation_mixer.h:44:2
    #6 0x7ff636560aac in AnimationPlayer::_notificationv(int, bool) E:/Repositories/godot/scene\animation/animation_player.h:39:2
    #7 0x7ff62b63a99c in Object::notification(int, bool) E:/Repositories/godot/core\object/object.cpp:837:3
    #8 0x7ff62e5f6dd1 in SceneTree::_process_group(SceneTree::ProcessGroup*, bool) E:/Repositories/godot/scene\main/scene_tree.cpp:948:8
    #9 0x7ff62e5e3e0b in SceneTree::_process(bool) E:/Repositories/godot/scene\main/scene_tree.cpp:1028:8
    #10 0x7ff62e5ea1d3 in SceneTree::process(double) E:/Repositories/godot/scene\main/scene_tree.cpp:508:2
    #11 0x7ff629b34c74 in Main::iteration() E:/Repositories/godot/main/main.cpp:3636:44
    #12 0x7ff6298e21b4 in OS_Windows::run() E:/Repositories/godot/platform\windows/os_windows.cpp:1474:7
    #13 0x7ff6298c2c2f in widechar_main(int, wchar_t**) E:/Repositories/godot/platform\windows/godot_windows.cpp:180:6
    #14 0x7ff6298c30dd in _main() E:/Repositories/godot/platform\windows/godot_windows.cpp:204:11
    #15 0x7ff6298c335f in main E:/Repositories/godot/platform\windows/godot_windows.cpp:223:9
    #16 0x7ff6298c1314 in __tmainCRTStartup /home/runner/work/llvm-mingw/llvm-mingw/mingw-w64/mingw-w64-crt/build-x86_64/../crt/crtexe.c:267:15
    #17 0x7ff6298c1155 in .l_startw /home/runner/work/llvm-mingw/llvm-mingw/mingw-w64/mingw-w64-crt/build-x86_64/../crt/crtexe.c:157:9
    #18 0x7ff8b8a07343  (C:\WINDOWS\System32\KERNEL32.DLL+0x180017343)
    #19 0x7ff8ba7e26b0  (C:\WINDOWS\SYSTEM32\ntdll.dll+0x1800526b0)

0x12b85b6509fa is located 122 bytes inside of 1528-byte region [0x12b85b650980,0x12b85b650f78)
freed by thread T0 here:
    #0 0x7ffffd842671 in free /home/runner/work/llvm-mingw/llvm-mingw/llvm-project/compiler-rt/lib/asan/asan_malloc_win.cpp:82:3
    #1 0x7ff62ab730ca in Memory::free_static(void*, bool) E:/Repositories/godot/core\os/memory.cpp:168:3
    #2 0x7ff629b44eb9 in void memdelete<Object>(Object*) E:/Repositories/godot/./core/os/memory.h:112:2
    #3 0x7ff62e5e8b9d in SceneTree::_flush_delete_queue() E:/Repositories/godot/scene\main/scene_tree.cpp:1345:4
    #4 0x7ff62e5ea69b in SceneTree::process(double) E:/Repositories/godot/scene\main/scene_tree.cpp:516:2
    #5 0x7ff629b34c74 in Main::iteration() E:/Repositories/godot/main/main.cpp:3636:44
    #6 0x7ff6298e21b4 in OS_Windows::run() E:/Repositories/godot/platform\windows/os_windows.cpp:1474:7
    #7 0x7ff6298c2c2f in widechar_main(int, wchar_t**) E:/Repositories/godot/platform\windows/godot_windows.cpp:180:6
    #8 0x7ff6298c30dd in _main() E:/Repositories/godot/platform\windows/godot_windows.cpp:204:11
    #9 0x7ff6298c335f in main E:/Repositories/godot/platform\windows/godot_windows.cpp:223:9
    #10 0x7ff6298c1314 in __tmainCRTStartup /home/runner/work/llvm-mingw/llvm-mingw/mingw-w64/mingw-w64-crt/build-x86_64/../crt/crtexe.c:267:15
    #11 0x7ff6298c1155 in .l_startw /home/runner/work/llvm-mingw/llvm-mingw/mingw-w64/mingw-w64-crt/build-x86_64/../crt/crtexe.c:157:9
    #12 0x7ff8b8a07343  (C:\WINDOWS\System32\KERNEL32.DLL+0x180017343)
    #13 0x7ff8ba7e26b0  (C:\WINDOWS\SYSTEM32\ntdll.dll+0x1800526b0)

previously allocated by thread T0 here:
    #0 0x7ffffd842791 in malloc /home/runner/work/llvm-mingw/llvm-mingw/llvm-project/compiler-rt/lib/asan/asan_malloc_win.cpp:98:3
    #1 0x7ff62ab7186b in Memory::alloc_static(unsigned long long, bool) E:/Repositories/godot/core\os/memory.cpp:75:14
    #2 0x7ff62ab716dc in operator new(unsigned long long, char const*) E:/Repositories/godot/core\os/memory.cpp:40:9
    #3 0x7ff62c53dc4a in Object* ClassDB::creator<OmniLight3D>() E:/Repositories/godot/./core/object/class_db.h:144:10
    #4 0x7ff62b584ace in ClassDB::instantiate(StringName const&) E:/Repositories/godot/core\object/class_db.cpp:377:10
    #5 0x7ff62e912f22 in SceneState::instantiate(SceneState::GenEditState) const E:/Repositories/godot/scene\resources/packed_scene.cpp:237:18
    #6 0x7ff62e921ec1 in PackedScene::instantiate(PackedScene::GenEditState) const E:/Repositories/godot/scene\resources/packed_scene.cpp:1946:19
    #7 0x7ff62e9c4cd4 in void call_with_variant_args_retc_helper<__UnexistingClass, Node*, PackedScene::GenEditState, 0ull>(__UnexistingClass*, Node* (__UnexistingClass::*)(PackedScene::GenEditState) const, Variant const**, Variant&, Callable::CallError&, IndexSequence<0ull>) E:/Repositories/godot/./core/variant/binder_common.h:806:10
    #8 0x7ff62e9c47e5 in void call_with_variant_args_retc_dv<__UnexistingClass, Node*, PackedScene::GenEditState>(__UnexistingClass*, Node* (__UnexistingClass::*)(PackedScene::GenEditState) const, Variant const**, int, Variant&, Callable::CallError&, Vector<Variant> const&) E:/Repositories/godot/./core/variant/binder_common.h:567:2
    #9 0x7ff62e9c22ca in MethodBindTRC<Node*, PackedScene::GenEditState>::call(Object*, Variant const**, int, Callable::CallError&) const E:/Repositories/godot/./core/object/method_bind.h:583:3
    #10 0x7ff6429ee572 in GDScriptFunction::call(GDScriptInstance*, Variant const**, int, Callable::CallError&, GDScriptFunction::CallState*) E:/Repositories/godot/modules\gdscript/gdscript_vm.cpp:1794:21
    #11 0x7ff63c2542a5 in GDScriptInstance::callp(StringName const&, Variant const**, int, Callable::CallError&) E:/Repositories/godot/modules\gdscript/gdscript.cpp:1937:21
    #12 0x7ff62b64afe0 in Object::callp(StringName const&, Variant const**, int, Callable::CallError&) E:/Repositories/godot/core\object/object.cpp:753:26
    #13 0x7ff630df56ae in Variant::callp(StringName const&, Variant const**, int, Variant&, Callable::CallError&) E:/Repositories/godot/core\variant/variant_call.cpp:1168:27
    #14 0x7ff6429ea6df in GDScriptFunction::call(GDScriptInstance*, Variant const**, int, Callable::CallError&, GDScriptFunction::CallState*) E:/Repositories/godot/modules\gdscript/gdscript_vm.cpp:1704:12
    #15 0x7ff63c2542a5 in GDScriptInstance::callp(StringName const&, Variant const**, int, Callable::CallError&) E:/Repositories/godot/modules\gdscript/gdscript.cpp:1937:21
    #16 0x7ff62b64afe0 in Object::callp(StringName const&, Variant const**, int, Callable::CallError&) E:/Repositories/godot/core\object/object.cpp:753:26
    #17 0x7ff630df56ae in Variant::callp(StringName const&, Variant const**, int, Variant&, Callable::CallError&) E:/Repositories/godot/core\variant/variant_call.cpp:1168:27
    #18 0x7ff6429ea6df in GDScriptFunction::call(GDScriptInstance*, Variant const**, int, Callable::CallError&, GDScriptFunction::CallState*) E:/Repositories/godot/modules\gdscript/gdscript_vm.cpp:1704:12
    #19 0x7ff63c2542a5 in GDScriptInstance::callp(StringName const&, Variant const**, int, Callable::CallError&) E:/Repositories/godot/modules\gdscript/gdscript.cpp:1937:21
    #20 0x7ff62b64afe0 in Object::callp(StringName const&, Variant const**, int, Callable::CallError&) E:/Repositories/godot/core\object/object.cpp:753:26
    #21 0x7ff62b1313bf in Callable::callp(Variant const**, int, Variant&, Callable::CallError&) const E:/Repositories/godot/core\variant/callable.cpp:69:25
    #22 0x7ff62b656742 in Object::emit_signalp(StringName const&, Variant const**, int) E:/Repositories/godot/core\object/object.cpp:1127:15
    #23 0x7ff62ea65efd in Node::emit_signalp(StringName const&, Variant const**, int) E:/Repositories/godot/scene\main/node.cpp:3606:17
    #24 0x7ff62e6210ef in Error Object::emit_signal<Node*>(StringName const&, Node*) E:/Repositories/godot/./core/object/object.h:922:10
    #25 0x7ff6374befc7 in Area3D::_body_inout(int, RID const&, ObjectID, int, int) E:/Repositories/godot/scene\3d/area_3d.cpp:248:6
    #26 0x7ff637507e5d in void call_with_variant_args_helper<Area3D, int, RID const&, ObjectID, int, int, 0ull, 1ull, 2ull, 3ull, 4ull>(Area3D*, void (Area3D::*)(int, RID const&, ObjectID, int, int), Variant const**, Callable::CallError&, IndexSequence<0ull, 1ull, 2ull, 3ull, 4ull>) E:/Repositories/godot/./core/variant/binder_common.h:303:2
    #27 0x7ff63750767c in void call_with_variant_args<Area3D, int, RID const&, ObjectID, int, int>(Area3D*, void (Area3D::*)(int, RID const&, ObjectID, int, int), Variant const**, int, Callable::CallError&) E:/Repositories/godot/./core/variant/binder_common.h:417:2

SUMMARY: AddressSanitizer: heap-use-after-free E:/Repositories/godot/core\object/object.cpp:226:10 in Object::set(StringName const&, Variant const&, bool*)
Shadow bytes around the buggy address:
  0x12b85b650700: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x12b85b650780: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x12b85b650800: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x12b85b650880: 00 00 00 fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x12b85b650900: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
=>0x12b85b650980: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd[fd]
  0x12b85b650a00: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x12b85b650a80: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x12b85b650b00: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x12b85b650b80: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x12b85b650c00: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
==12152==ABORTING

akien-mga added a commit to akien-mga/godot that referenced this issue Nov 28, 2023
… freed

Works around godotengine#85365, but it's likely only a partial fix.
The proper fix would be to remove the Object pointer from the TrackCache
and always go back to the ObjectID before doing operations like this.
@akien-mga
Copy link
Member

Thanks @bitsawer! I could work around the issue in #85461, which should be "good enough" for 4.2 hopefully. At least it fixes Liblast.

I'll repurpose this issue to focus on the fact that AnimationMixer stores Object pointers in its TrackCache, and as seen here, this is really unsafe. We should remove object from the TrackCache and always get the object pointed from the stored object_id. But that's refactoring work for 4.3 (maybe 4.2.x cherry-pick if we find more crashes like this).

@akien-mga akien-mga modified the milestones: 4.2, 4.3 Nov 28, 2023
@TokageItLab
Copy link
Member

TokageItLab commented Nov 28, 2023

Thanks a lots @bitsawer @akien-mga! I don't remember how long track->object has existed (it probably already existed before 4.0), but a quick look at the code that eliminating track->object seems quite straightforward.

@akien-mga
Copy link
Member

Another crash likely caused by the same t->object problem: #85572.

We should aim to fix this sooner than later, ideally for 4.2.1.

akien-mga added a commit to akien-mga/godot that referenced this issue Jan 2, 2024
Using it could easily lead to use-after-free crashes, as the object may have
been freed. Caching object pointers like this is unsafe.

Instead, we rely only on the ObjectID and query ObjectDB with it each time
we need access to the instance.

- Fixes godotengine#85365.
- Fixes godotengine#85572.
GuybrushThreepwood-GitHub pushed a commit to GuybrushThreepwood-GitHub/godot that referenced this issue Jan 27, 2024
… freed

Works around godotengine#85365, but it's likely only a partial fix.
The proper fix would be to remove the Object pointer from the TrackCache
and always go back to the ObjectID before doing operations like this.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment