Bug/Conflict with Resource Databases Plugin

[ahrbe1]

I bumped into a weird error when trying to add this library to a new/empty project where I had already installed the Resource Databases plugin. (Link: https://github.com/DarthPapalo666/ResourceDatabases)

See this error:

Godot Engine v4.4.dev4.official (c) 2007-present Juan Linietsky, Ariel Manzur & Godot Contributors.
--- Debug adapter server started on port 6008 ---
--- GDScript language server started on port 6005 ---
  res://addons/logger/log-stream.gd:111 - Parse Error: Identifier "Log" not declared in the current scope.
  res://addons/logger/log-stream.gd:114 - Parse Error: Identifier "Log" not declared in the current scope.
  res://addons/logger/plugin.gd:-1 - Compile Error: 
  modules/gdscript/gdscript.cpp:3038 - Failed to load script "res://addons/logger/plugin.gd" with error "Compilation failed".
  res://addons/logger/log-stream.gd:111 - Compile Error: Identifier not found: Log
  res://addons/logger/logger.gd:-1 - Compile Error: 
  modules/gdscript/gdscript.cpp:3038 - Failed to load script "res://addons/logger/logger.gd" with error "Compilation failed".
  modules/gdscript/gdscript.cpp:147 - Parameter "p_script->implicit_initializer" is null.
  res://addons/logger/log-stream.gd:37 - Invalid access to property or key 'default_crash_behavior' on a base object of type 'GDScript'.

Well, that would almost look like the global Log autoload isn't present/enabled -- except it is. The weird part is that implicit initializer stuff. p_script->implicit_initializer appears to be attempting to call an implicit initializer of the superclass, Node.

I've spent some hours this evening going through the source code of this plugin, the Resource Databases plugin, and the gdscript.cpp file, but I haven't found anything obvious. So I'm starting to wonder if something here exposes a bug in godot itself.

Verified on Godot 4.3-offical (windows) and Godot-4.4-dev3

Steps to reproduce:

1. Create a new blank project
2. Add Resource Databases from the asset library
3. Add Log from the asset library
4. Enable both plugins in the settings
5. Reload current project

As an experiment, if I change the following line in log-stream.gd:

- func _init(log_name:String, min_log_level:=LogLevel.DEFAULT, crash_behavior:Callable = default_crash_behavior):
+ func _init(log_name:String, min_log_level:=LogLevel.DEFAULT, crash_behavior = null):

and reload the project, then the error changes to this:

  ...
  modules/gdscript/gdscript.cpp:147 - Parameter "p_script->implicit_initializer" is null.
  res://addons/logger/log-stream.gd:39 - Invalid call. Nonexistent function '_set_level' in base 'Node (logger.gd)'.

Any ideas?

[albinaask]

I my memory serves, the issue is that Godot tries to load the singletons before the rest of the scripts in some edge cases. I think it's fixable through turning the addon off and on again, and then reload the editor, it has fixed itself for me. Good that you bring it up though, it shouldn't be this way.

[ahrbe1]

Interesting. That appears to fix it once. However, if I immediately reload again it comes back. I'll see if I can figure out any workarounds.

[ahrbe1]

I think I found a fix. This looks like it's due to a cyclic reference of Log -> LogStream -> Log.

In log-stream.gd near line 111 there is:

	if log_level > 3 && Log.is_inside_tree() && ProjectSettings.get_setting(settings.PRINT_TREE_ON_ERROR_KEY, settings.PRINT_TREE_ON_ERROR_DEFAULT_VALUE):
		#We want to access the main scene tree since this may be a custom logger that isn't in the main tree.
		print("Main tree: ")
		Log.get_tree().root.print_tree_pretty()
		print("")#Print empty line to mark new message

Where Log is used only on two lines.

As a first attempt, I thought we could break the cyclic link with something like this (abbreviated code shown):

    var log_singleton = get_tree().root.get_node("Log")

    if log_level > 3 && log_singleton.is_inside_tree() && ...:

        # [...]

        log_singleton.get_tree().root.print_tree_pretty()

        # [...]

Though looking at this more closely, it seems like the singleton would be in the tree because we just got it from the tree. So that seems odd. That makes me wonder if the original code was intended to be something like this?

    if log_level > 3 && self.is_inside_tree() && ...:

        # [...]

        get_tree().root.print_tree_pretty()

        # [...]

Removing the direct usage of the Log autoload from this file looks like it would resolve the load issue in my testing so far.

[albinaask]

It was like that at one point, the problem with this implementation is that it doesn't work if the LogStream isn't in the tree. Could you check whether you have the correct singleton loaded under "Project settings"->"Autoload", there should be one called Log. Perhaps this has not been added correctly?`

The editor starting process should go something like the following:

1. editor start.
2. Log Addon start.
3. Log is brought into scope. (here the bug happends)
4. Autoload Singleton is added to tree.
5. Log works.

If you change log_singleton.is_inside_tree to log_singleton!=null. I think it should work better. If it solves it, a pull request would be greatly appreciated. Don't forget to add yourself as an author in the plugin.cfg file in that case.

[ahrbe1]

Further testing indicates that the above issue seems to be intermittent for me. I added another couple of plugins and the issue seems to have gone away. But if I remove them it comes back. Definitely strange. I dont know what Godot's official stance on cyclic loads are. I'd probably vote to avoid them if possible.

Related to this, I just stumbled upon this issue in the godot issue tracker, which looks like it applies to how this plugin installs it's autoload variable:

godotengine/godot-docs#9571

I'm not sure yet if this contributes to the issue I'm seeing, but it does look like we should probably update the code to use _enable_plugin()/_disable_plugin() instead of _enter_tree()/_exit_tree() for the autoloads.

[ahrbe1]

Ok. Nevermind the part about being intermittent. Had a dirty working copy. The issue is still present with additional plugins.

[ahrbe1]

Ok, I see why the implementation is the way it is, and I don't see an easy fix for removing that cyclic dependency and preserving the existing behavior. get_tree() unfortunately reports an error if you call it while not inside the tree (and also returns null), so that won't work.

However, testing with the _enable_plugin()/_disable_plugin() seems to fix the startup error I'm seeing, and also resolves an issue where the editor thinks that the project is modified every time it's loaded (e.g. it prompts you to save if you immediately do a project -> reload after opening). I will submit a PR for that part.

[albinaask]

Please let me know if you have any further issues in this regard since this is a very annoying bug!