[Android Editor] Error parsing `editor_settings-4.3.tres`

m4gr3d commented 1 month ago

Tested versions

Reproducible in Godot Android Editor 4.3 beta 2
Not reproducible in Godot Android Editor 4.2.2 stable

System information

Android 12, Android 14

Issue description

There is a regression that causes the editor_settings-4.3.tres file to be randomly truncated. This seems to be a race condition as the issue doesn't always occur, but when it does, it first causes the editor to crash when re-opening the project, then it causes the editor to crash every time it's opened with the following error logs:

E  USER ERROR: /data/data/org.godotengine.editor.v4.debug/files/config/godot/editor_settings-4.3.tres:1 - Parse Error: 
E     at: open (scene/resources/resource_format_text.cpp:1056)
E  USER ERROR: Failed loading resource: /data/data/org.godotengine.editor.v4.debug/files/config/godot/editor_settings-4.3.tres. Make sure resources have been imported by opening the project in the editor at least once.
E     at: _load (core/io/resource_loader.cpp:282)
A  Fatal signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x0 in tid 8173 (GLThread 30), pid 8145 (editor.v4.debug)
---------------------------- PROCESS STARTED (8196) for package org.godotengine.editor.v4.debug ----------------------------
A  Fatal signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x0 in tid 8173 (GLThread 30), pid 8145 (editor.v4.debug)

The editor_settings-4.3.tres file ends up empty.

Steps to reproduce

Download Godot Android Editor 4.3 beta 2
Load a sample project from the asset library. E.g: https://godotengine.org/asset-library/asset/2174
Open the project in the editor
After the project has loaded, select Project -> Quit to project list to return to the project list
In the project list, press the back button to exit the editor
Re-open the editor
Re-launch the sample project

Note: As mentioned in the description, this seems to be a race condition so it may take several attempts before it repros, and even then it's not guaranteed to repro

Minimal reproduction project (MRP)

https://godotengine.org/asset-library/asset/2174

dsnopek commented 1 month ago

I encountered this problem "naturally" (ie not while trying to reproduce it on purpose) on the Meta Quest.

After cleaning things up so the editor would run again, I attempted to reproduce the problem on purpose by following the "Steps to reproduce" here and was unable to after many tries.

m4gr3d commented 1 month ago

We recently updated how we write the editor settings file in https://github.com/godotengine/godot/pull/90875, could the issue be related to that?

cc @akien-mga @KoBeWi

akien-mga commented 1 month ago

We recently updated how we write the editor settings file in #90875, could the issue be related to that?

That's possible, but given how difficult the issue is to reproduce, it's tricky to debug.

I don't see at a glance what could cause a race condition / fail specifically on Android and not other platforms in that code.

Maybe some of the DirAccess APIs like dir_exists_absolute don't always work on Android with scoped storage? Still would be weird that it works sometimes and not other times.

I've tried to trigger the bug a dozen times on a Pixel 7a with 4.3-beta3 and didn't succeed so far.

akien-mga commented 1 month ago

I see @m4gr3d's build is named org.godotengine.editor.v4.debug - is that a custom debug build? Was that also your case when reproducing the bug @dsnopek?

If it's a race condition, it might be more prominent / only present in unoptimized debug builds and not in official 4.3.beta snapshots.

dsnopek commented 1 month ago

Was that also your case when reproducing the bug @dsnopek?

Yes, it was a custom built debug build.

Hilderin commented 1 month ago

I tested on my Android Samsung A14 with Android 14.

I was able to reproduce the problem with a custom debug build from master after a couple of "open a project, go back to Project List, reopen project, etc...". Sometimes it needs at least 10 retries.

When the problem occurs the content of editor-settings-4.3.tres is empty.

I added some debug print in EditorSettings::save and each time the problem happens when the project is being opened. The EditorSettings::save method begin but never ends before the process is killed by Android.

When it works:

07-20 23:12:27.156 11685 11730 I godot   : Editing project: /storage/emulated/0/Documents/godot-test
07-20 23:12:27.223 11685 11730 I godot   : Saving editor settings...
07-20 23:12:27.225 11685 11730 I godot   : Saving: /data/data/org.godotengine.editor.v4.debug/files/config/godot/editor_settings-4.3.tres
07-20 23:12:27.236 11685 11730 I godot   : Saving editor settings... DONE!
07-20 23:12:27.253 11755 11755 I AndroidRuntime: VM exiting with result code 0, cleanup skipped.
07-20 23:12:27.527 11794 11844 I godot   : Godot Engine v4.3.beta.custom_build.a0943acda (2024-07-19 15:31:49 UTC) - https://godotengine.org
07-20 23:12:27.627 11794 11844 I godot   : Vulkan 1.1.177 - Forward Mobile - Using Device #0: ARM - Mali-G57 MC2
07-20 23:12:28.905 11794 11844 I godot   : 
07-20 23:12:29.144 11794 11844 I godot   : Selected screen scale:  1.79999995231628
07-20 23:12:29.312 11794 11844 I godot   : Selected screen scale:  1.79999995231628
07-20 23:12:37.755 11794 11844 I godot   : Saving editor settings...
07-20 23:12:37.755 11794 11844 I godot   : Saving: /data/data/org.godotengine.editor.v4.debug/files/config/godot/editor_settings-4.3.tres
07-20 23:12:37.760 11794 11844 I godot   : Selected screen scale:  1.79999995231628
07-20 23:12:37.771 11794 11844 I godot   : Saving editor settings... DONE

When it corrupts the settings file: ('Saving editor settings... DONE!' is never printed and afterward the file is empty. I printed the content of the file at the line 'USER ERROR: Content:')

07-20 23:19:22.068 15449 15499 I godot   : Editing project: /storage/emulated/0/Documents/godot-test
07-20 23:19:22.142 15449 15499 I godot   : Saving editor settings...
07-20 23:19:22.143 15449 15499 I godot   : Saving: /data/data/org.godotengine.editor.v4.debug/files/config/godot/editor_settings-4.3.tres
07-20 23:19:22.153 15547 15547 I AndroidRuntime: VM exiting with result code 0, cleanup skipped.
07-20 23:19:22.503 15590 15639 I godot   : Godot Engine v4.3.beta.custom_build.a0943acda (2024-07-19 15:31:49 UTC) - https://godotengine.org
07-20 23:19:22.579 15590 15639 I godot   : Vulkan 1.1.177 - Forward Mobile - Using Device #0: ARM - Mali-G57 MC2
07-20 23:19:23.989 15590 15639 I godot   : 
07-20 23:19:24.252 15590 15639 E godot   : USER ERROR: ERROR RESOURCE: /data/data/org.godotengine.editor.v4.debug/files/config/godot/editor_settings-4.3.tres
07-20 23:19:24.252 15590 15639 E godot   :    at: open (scene\resources\resource_format_text.cpp:1061)
07-20 23:19:24.253 15590 15639 E godot   : USER ERROR: Content: 
07-20 23:19:24.253 15590 15639 E godot   :    at: open (scene\resources\resource_format_text.cpp:1064)
07-20 23:19:24.253 15590 15639 E godot   : USER ERROR: /data/data/org.godotengine.editor.v4.debug/files/config/godot/editor_settings-4.3.tres:1 - Parse Error: 
07-20 23:19:24.253 15590 15639 E godot   :    at: open (scene\resources\resource_format_text.cpp:1065)
07-20 23:19:24.254 15590 15639 E godot   : USER ERROR: Failed loading resource: /data/data/org.godotengine.editor.v4.debug/files/config/godot/editor_settings-4.3.tres. Make sure resources have been imported by opening the project in the editor at least once.
07-20 23:19:24.254 15590 15639 E godot   :    at: _load (core\io\resource_loader.cpp:284)

To test my hypothesis, I added a 5 sec wait time in ResourceFormatSaverTextInstance::save after opening the file in write mode. After that, I was able to reproduce the problem almost each time, just by opening a project from the Project Manager. The project crashes on opening the first time.

I think Android does not always wait for all the resources to finish there destruction before killing the process. The EditorSettings::save that corrupts the file is in EditorSettings::destroy which is called in ProjectManager::~ProjectManager. Weirdly, the EditorSettings::destroy in EditorNode::~EditorNode seems always to be executed completely.

I'm absolutely not an Android programmer so I don't known if something could be done to force Android to wait before killing the process, but I guess the easy fix should be to remove the EditorSettings::destroy in the destructor of ProjectManager::~ProjectManager and execute it elsewhere (I'm not even sure it is useful).

I let an expert work on that, I hope my debugging could help with this Release Blocker issue.

Alex2782 commented 1 month ago

Maybe Godot should not react so sensitively if the file editor_settings-4.3.tres is faulty and ask the user? Try again or load default settings.

I could also reproduce it from 1 second delay. If the delay is removed, the file remains faulty on Android. On Windows 11 there are only problems as long as the delay is present. (Windows Defender could possibly also cause a delay).

Error ResourceFormatSaverTextInstance::save(const String &p_path, const Ref<Resource> &p_resource, uint32_t p_flags) {
    if (p_path.ends_with(".tscn")) {
        packed_scene = p_resource;
    }

    Error err;
    Ref<FileAccess> f = FileAccess::open(p_path, FileAccess::WRITE, &err);
    ERR_FAIL_COND_V_MSG(err, ERR_CANT_OPEN, "Cannot save file '" + p_path + "'.");
    Ref<FileAccess> _fref(f);

    //print_line("BEGIN DELAY: ", OS::get_singleton()->get_ticks_usec());
    //OS::get_singleton()->delay_usec(1000000); // 1 000 000 = 1 sec
    //print_line("END DELAY: ", OS::get_singleton()->get_ticks_usec());

Hilderin commented 1 month ago

There is already a fallback to manage if the settings resource is invalid but it was broken by #90875.

This line was added before checking if the resource is null in EditorSettings::create:

singleton->set_path(get_newest_settings_path()); // Settings can be loaded from older version file, so make sure it's newest.

That could cause the editor to crash and never do the goto fail:

singleton = ResourceLoader::load(config_file_path, "EditorSettings");
singleton->set_path(get_newest_settings_path()); // Settings can be loaded from older version file, so make sure it's newest.

if (singleton.is_null()) {
    ERR_PRINT("Could not load editor settings from path: " + config_file_path);
    goto fail;
}

I'll create a PR to fix that! Technically, it could also happen on any platform. That will not fix the problem where the editor settings file get corrupted on Android, by at least, the editor will no crash on startup.

akien-mga commented 1 month ago

I think Android does not always wait for all the resources to finish there destruction before killing the process. The EditorSettings::save that corrupts the file is in EditorSettings::destroy which is called in ProjectManager::~ProjectManager. Weirdly, the EditorSettings::destroy in EditorNode::~EditorNode seems always to be executed completely.

That reminds me of #84839, and bug reports in the past (maybe some still current) about the Editor Settings getting wiped for no obvious reason when closing or opening the editor.

Sounds like we should look into making things more reliable when it comes to destroying EditorSettings at the right time.

m4gr3d commented 1 month ago

Sounds like we should look into making things more reliable when it comes to destroying EditorSettings at the right time.

Shouldn't the filesystem/on_save/safe_save_on_backup_then_rename editor setting prevent this type of issues?

m4gr3d commented 1 month ago

I'll create a PR to fix that! Technically, it could also happen on any platform. That will not fix the problem where the editor settings file get corrupted on Android, by at least, the editor will no crash on startup.

Thanks for the fix @Hilderin. I think I may have an idea what's the root of the issue on Android. I'll work on a fix.

Zireael07 commented 1 month ago

Why is this closed if the error itself is not fixed, just the crash?

m4gr3d commented 1 month ago

I'll create a PR to fix that! Technically, it could also happen on any platform. That will not fix the problem where the editor settings file get corrupted on Android, by at least, the editor will no crash on startup.

Thanks for the fix @Hilderin. I think I may have an idea what's the root of the issue on Android. I'll work on a fix.

I believe I have a fix for the root cause with https://github.com/godotengine/godot/pull/94661. Still need to do some validation tests to confirm, at which point I'll take the PR out of draft.

@Alex2782 Can you check if https://github.com/godotengine/godot/pull/94661 addresses the issue when you add the 1 second delay.

godotengine / godot