godotengine / godot

Godot Engine – Multi-platform 2D and 3D game engine
https://godotengine.org
MIT License
91.22k stars 21.22k forks source link

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

Closed unfa closed 10 months ago

unfa commented 11 months ago

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 commented 11 months ago

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 commented 11 months ago

cc @TokageItLab

TokageItLab commented 11 months ago

I can't tell anything without MRP.

Guessing from the stack trace, there possibly could be a problem with the Continuous interpolation of StringName https://github.com/godotengine/godot/pull/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 commented 11 months ago

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 commented 11 months ago

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 commented 11 months ago

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 commented 11 months ago

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 commented 11 months ago

@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 commented 11 months ago

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

akien-mga commented 11 months ago

BTW, this may be a similar/related issue?

  • 85388

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 commented 11 months ago

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 commented 11 months ago

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 commented 11 months ago

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 https://github.com/godotengine/godot/issues/85365#issuecomment-1828449427

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 commented 11 months ago

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 commented 11 months ago

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 commented 11 months ago

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

https://github.com/godotengine/godot/blob/eda44bfe109d7f15c5a965db2d65c8a17ce4b7d0/core/object/object.cpp#L226

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:

https://github.com/godotengine/godot/blob/eda44bfe109d7f15c5a965db2d65c8a17ce4b7d0/scene/animation/animation_mixer.cpp#L1711

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 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*) 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() 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 const&) E:/Repositories/godot/./core/variant/binder_common.h:567:2 #9 0x7ff62e9c22ca in MethodBindTRC::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(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*, 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*, 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 commented 11 months ago

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

TokageItLab commented 11 months ago

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 commented 11 months ago

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.