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

ResourceLoader.load_threaded_get_status(SCENE, PROGRESS) always returns 0 (THREAD_LOAD_INVALID_RESOURCE) #95470

Closed
maktoobgar opened this issue Aug 13, 2024 · 7 comments · Fixed by #95476

Comments

@maktoobgar
Copy link

Tested versions

  • Reproducible in: 4.3.rc3 [03afb92]

System information

Ubuntu 22.04.4 LTS - Godot v4.3.rc3

Issue description

I have an addon called Scene Manager and I got an issue about this which made me come here and report the problem after identifying the problem.

In one sentence: ResourceLoader.load_threaded_get_status doesn't seem to work right at all.

Simply define a scene and request to load it with ResourceLoader.load_threaded_request and then ask for how it is doing with ResourceLoader.load_threaded_get_status and it always returns 0 which means THREAD_LOAD_INVALID_RESOURCE but actually when used ResourceLoader.load_threaded_get after you see the THREAD_LOAD_INVALID_RESOURCE, it actually returns the scene just fine but ResourceLoader.load_threaded_get_status said that the scene is not valid which means that it isn't working properly as expected.

Note: This was working completely fine in previous versions of godot4.
Note: Loading normally is fine but loading with ResourceLoading doesn't seem to work at all.

Steps to reproduce

Simply pass a scene address into this function and watch the results:

func load_scene_interactive(_load_scene: String, use_sub_threads = false) -> void:
	ResourceLoader.load_threaded_request(_load_scene, "", use_sub_threads, ResourceLoader.CACHE_MODE_IGNORE)
	var _percent = []
	print("status: ", ResourceLoader.load_threaded_get_status(_load_scene, _percent))
	print("percent: ", _percent)
	print("actual scene: ", ResourceLoader.load_threaded_get(_load_scene))
	print("status: ",ResourceLoader.load_threaded_get_status(_load_scene, _percent))
	print("percent: ", _percent)

You will see this output:

status: 0
percent: [0]
actual scene: <PackedScene#-9223371992663587553>
status: 0
percent: [0]

Which means ResourceLoader.load_threaded_get_status is not working properly at all but actually ResourceLoader.load_threaded_get works just fine although is was said by ResourceLoader.load_threaded_get_status that the scene is not valid and it will not load properly.

What was expected:

status: 1
percent: [0]
actual scene: <PackedScene#-9223371992663587553>
status: 3
percent: [1]

Minimal reproduction project (MRP)

load_threaded_get_status.zip

@akien-mga
Copy link
Member

Testing on Fedora 40.

I can reproduce the 0 status in 4.3.rc3, but not the 1/3 statuses of the "what was expected" in 4.2.2.stable. Could you clarify how you tested previous versions?

In 4.2.2.stable, I get:

status: 1
percent: [0]
actual scene: <PackedScene#-9223372003333897050>
status: 0
percent: [0]

I get the same result with 4.3.beta1.

Then 4.3.beta2 gives:

status: 1
percent: [0]
ERROR: Invalid Task ID
   at: wait_for_task_completion (core/object/worker_thread_pool.cpp:363)
actual scene: <PackedScene#-9223372002310486718>
status: 0
percent: [0]

4.3.beta3 exhibits the behavior described here and still reproducible as of 4.3.rc3:

status: 0
percent: [0]
actual scene: <PackedScene#-9223372003904322285>
status: 0
percent: [0]

And finally the latest master branch at a7a124a... segfaults :'(

ERROR: FATAL: Method/function failed.
   at: load_threaded_get_status (./core/io/resource_loader.cpp:586)

Thread 1 "godot-git" received signal SIGILL, Illegal instruction.
0x000000000a90d819 in ResourceLoader::load_threaded_get_status (p_path=..., r_progress=0x7fffffff0b3c) at ./core/io/resource_loader.cpp:586
586                             CRASH_NOW();

(gdb) bt
#0  0x000000000a90d819 in ResourceLoader::load_threaded_get_status (p_path=..., r_progress=0x7fffffff0b3c) at ./core/io/resource_loader.cpp:586
#1  0x000000000a7020ce in core_bind::ResourceLoader::load_threaded_get_status (this=0xb7c2c50, p_path=..., r_progress=...) at ./core/core_bind.cpp:58
#2  0x000000000a7d5cbf in call_with_variant_args_ret_helper<__UnexistingClass, core_bind::ResourceLoader::ThreadLoadStatus, String const&, Array, 0ul, 1ul> (p_instance=0xb7c2c50, 
    p_method=(core_bind::ResourceLoader::ThreadLoadStatus (__UnexistingClass::*)(__UnexistingClass * const, const String &, Array)) 0xa70209e <core_bind::ResourceLoader::load_threaded_get_status(String const&, Array)>, p_args=0x7fffffff0c20, r_ret=..., r_error=...) at ./core/variant/binder_common.h:756
#3  0x000000000a7c717f in call_with_variant_args_ret_dv<__UnexistingClass, core_bind::ResourceLoader::ThreadLoadStatus, String const&, Array> (p_instance=0xb7c2c50, 
    p_method=(core_bind::ResourceLoader::ThreadLoadStatus (__UnexistingClass::*)(__UnexistingClass * const, const String &, Array)) 0xa70209e <core_bind::ResourceLoader::load_threaded_get_status(String const&, Array)>, p_args=0x7fffffff0da8, p_argcount=2, r_ret=..., r_error=..., default_values=...) at ./core/variant/binder_common.h:535
#4  0x000000000a7ba262 in MethodBindTR<core_bind::ResourceLoader::ThreadLoadStatus, String const&, Array>::call (this=0xb7c34b0, p_object=0xb7c2c50, p_args=0x7fffffff0da8, p_arg_count=2, r_error=...)
    at ./core/object/method_bind.h:524
#5  0x00000000068eefed in GDScriptFunction::call (this=0xdad5260, p_instance=0xdad83f0, p_args=0x7fffffff50c0, p_argcount=1, r_err=..., p_state=0x0) at ./modules/gdscript/gdscript_vm.cpp:1874
#6  0x000000000683f134 in GDScriptInstance::callp (this=0xdad83f0, p_method=..., p_args=0x7fffffff50c0, p_argcount=1, r_error=...) at ./modules/gdscript/gdscript.cpp:2032
#7  0x000000000ad8c91f in Object::callp (this=0xdad0320, p_method=..., p_args=0x7fffffff50c0, p_argcount=1, r_error=...) at ./core/object/object.cpp:786
#8  0x000000000aa676b8 in Variant::callp (this=0x7fffffff5060, p_method=..., p_args=0x7fffffff50c0, p_argcount=1, r_ret=..., r_error=...) at ./core/variant/variant_call.cpp:1211
#9  0x00000000068ee28d in GDScriptFunction::call (this=0xdad90c0, p_instance=0xdad83f0, p_args=0x0, p_argcount=0, r_err=..., p_state=0x0) at ./modules/gdscript/gdscript_vm.cpp:1780
#10 0x000000000683f134 in GDScriptInstance::callp (this=0xdad83f0, p_method=..., p_args=0x0, p_argcount=0, r_error=...) at ./modules/gdscript/gdscript.cpp:2032
#11 0x000000000ad8c91f in Object::callp (this=0xdad0320, p_method=..., p_args=0x0, p_argcount=0, r_error=...) at ./core/object/object.cpp:786
#12 0x000000000aa52f41 in Callable::callp (this=0x7fffffff93b0, p_arguments=0x0, p_argcount=0, r_return_value=..., r_call_error=...) at ./core/variant/callable.cpp:69
#13 0x000000000ad8eac1 in Object::emit_signalp (this=0xdad6f80, p_name=..., p_args=0x0, p_argcount=0) at ./core/object/object.cpp:1187
#14 0x00000000088923a6 in Node::emit_signalp (this=0xdad6f80, p_name=..., p_args=0x0, p_argcount=0) at ./scene/main/node.cpp:3895
#15 0x000000000643f4cb in Object::emit_signal<>(StringName const&) (this=0xdad6f80, p_name=...) at ./core/object/object.h:936
#16 0x00000000089eb026 in BaseButton::on_action_event (this=0xdad6f80, p_event=...) at ./scene/gui/base_button.cpp:185
#17 0x00000000089ea8ff in BaseButton::gui_input (this=0xdad6f80, p_event=...) at ./scene/gui/base_button.cpp:68
#18 0x0000000008a441e5 in Control::_call_gui_input (this=0xdad6f80, p_event=...) at ./scene/gui/control.cpp:1830
#19 0x00000000088aea0b in Viewport::_gui_call_input (this=0xda43880, p_control=0xdad6f80, p_input=...) at ./scene/main/viewport.cpp:1567
#20 0x00000000088afc84 in Viewport::_gui_input_event (this=0xda43880, p_event=...) at ./scene/main/viewport.cpp:1836
#21 0x00000000088b7688 in Viewport::push_input (this=0xda43880, p_event=..., p_local_coords=false) at ./scene/main/viewport.cpp:3258
#22 0x00000000088dd2d5 in Window::_window_input (this=0xda43880, p_ev=...) at ./scene/main/window.cpp:1680
#23 0x00000000089e3f54 in call_with_variant_args_helper<Window, Ref<InputEvent> const&, 0ul> (p_instance=0xda43880, 
    p_method=(void (Window::*)(Window * const, const Ref<InputEvent> &)) 0x88dcd7a <Window::_window_input(Ref<InputEvent> const&)>, p_args=0x7fffffffc630, r_error=...) at ./core/variant/binder_common.h:304
#24 0x00000000089c657e in call_with_variant_args<Window, Ref<InputEvent> const&> (p_instance=0xda43880, 
    p_method=(void (Window::*)(Window * const, const Ref<InputEvent> &)) 0x88dcd7a <Window::_window_input(Ref<InputEvent> const&)>, p_args=0x7fffffffc630, p_argcount=1, r_error=...)
    at ./core/variant/binder_common.h:418
#25 0x00000000089a4f78 in CallableCustomMethodPointer<Window, Ref<InputEvent> const&>::call (this=0xd9a07e0, p_arguments=0x7fffffffc630, p_argcount=1, r_return_value=..., r_call_error=...)
    at ./core/object/callable_method_pointer.h:103
#26 0x000000000aa52c8d in Callable::callp (this=0x7fffffffc6d0, p_arguments=0x7fffffffc630, p_argcount=1, r_return_value=..., r_call_error=...) at ./core/variant/callable.cpp:57
#27 0x0000000005d163c9 in Callable::call<Ref<InputEvent> > (this=0x7fffffffc6d0) at ./core/variant/variant.h:875
#28 0x0000000005d01d1b in DisplayServerX11::_dispatch_input_event (this=0xbd93ae0, p_event=...) at platform/linuxbsd/x11/display_server_x11.cpp:4063
#29 0x0000000005d01aa5 in DisplayServerX11::_dispatch_input_events (p_event=...) at platform/linuxbsd/x11/display_server_x11.cpp:4039
#30 0x000000000a9ef057 in Input::_parse_input_event_impl (this=0xb5a88e0, p_event=..., p_is_emulated=false) at ./core/input/input.cpp:774
#31 0x000000000a9f03a0 in Input::flush_buffered_events (this=0xb5a88e0) at ./core/input/input.cpp:1055
#32 0x0000000005d06c86 in DisplayServerX11::process_events (this=0xbd93ae0) at platform/linuxbsd/x11/display_server_x11.cpp:5199
#33 0x0000000005cde1b6 in OS_LinuxBSD::run (this=0x7fffffffd090) at platform/linuxbsd/os_linuxbsd.cpp:958
#34 0x0000000005cd69f1 in main (argc=1, argv=0x7fffffffd6f8) at platform/linuxbsd/godot_linuxbsd.cpp:85

@akien-mga akien-mga added this to the 4.3 milestone Aug 13, 2024
@akien-mga akien-mga moved this from Unassessed to Release Blocker in 4.x Release Blockers Aug 13, 2024
@akien-mga
Copy link
Member

akien-mga commented Aug 13, 2024

Nevermind the crash, it happens only in a DEV_ENABLED build due to this code:

                String local_path = _validate_local_path(p_path);
                if (!thread_load_tasks.has(local_path)) {
#ifdef DEV_ENABLED
                        CRASH_NOW();
#endif
                        // On non-dev, be defensive and at least avoid crashing (at this point at least).
                        return THREAD_LOAD_INVALID_RESOURCE;
                }

So it was trying to catch this kind of error case but it's only evident when running a dev build.

(For the record @RandomShaper I'm still of the opinion that well placed ERR_FAIL_COND_MSG(..., "Bug in ResourceLoader logic, please report.") would be more useful than dev-only asserts that are only useful if contributors end up triggering the edge case.)

In a non dev build, I get the same issue as in the OP in latest master:

status: 0
percent: [0]
actual scene: <PackedScene#-9223372005531712208>
status: 0
percent: [0]

@akien-mga akien-mga removed the crash label Aug 13, 2024
@akien-mga akien-mga moved this from Release Blocker to Very Bad in 4.x Release Blockers Aug 13, 2024
@akien-mga
Copy link
Member

I tested #94169 but it doesn't seem to address this issue.

@maktoobgar
Copy link
Author

I can reproduce the 0 status in 4.3.rc3, but not the 1/3 statuses of the "what was expected" in 4.2.2.stable. Could you clarify how you tested previous versions?

You are right, sorry I just made a mistake, I got those logs from other situations which... doesn't matter actually.

The state you are seeing is right and in a normal behavior, the status: 3 and percent: [1] is accessible right before you retrieve your scene from ResourceLoader.load_threaded_get, after that you get your scene, you should see status: 0 and percent: [0].
I provide another test here and write how it should act:

load_threaded_get_status_2.zip

Expected logs:

*** load started ***

stating values:
status: 1
percent: [0]
=========================
*** In _process ***
status: 3
percent: [1]
actual scene: <PackedScene#-9223372005481380632>
*** load finished ***

=========================
status: 0
percent: [0]

Received Logs:

*** load started ***

stating values:
status: 0
percent: [0]
=========================
*** In _process ***
status: 0
percent: [0]
*** In _process ***
status: 0
percent: [0]
*** In _process ***
status: 0
percent: [0]
.
.
.

It goes into a loop because it never actually sees the status = 3 and so it never loads the scene.

@akien-mga
Copy link
Member

Thanks, I can reproduce these results with the new MRP. I'll bisect so we can pinpoint when the regression happened exactly.

@akien-mga
Copy link
Member

Bisected to 884d1da / #93540.

@BlueCube3310
Copy link
Contributor

This seems to be the correct behavior since the cache mode is set to ignore, which means it doesn't get registered by the task map. Before the aforementioned commit the task would be incorrectly registered on the task map, so it looks like a compatibility issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
Status: Very Bad
Development

Successfully merging a pull request may close this issue.

3 participants