Godot: Editor freeze and memory leak during scene save

Created on 7 Nov 2018  路  31Comments  路  Source: godotengine/godot

Godot version:
de0d30655859a46eaf711e209fe20d9ca60a60f2 (but the issue is present since I'm on 3.1 branch (i switched shortly after alpha1))

OS/device including version:
Ubuntu 18.04, 64bit, GTX1060

Issue description:
Sometimes when I'm saving scene (or more often when it's autosaving during the game/scene launch) the editor is freezing and starting leaking memory fast. When this happens in the terminal there is an infinite loop of Object was deleted while awaiting a callback messages.
I'm unable to reproduce this is any reliable way, opening the issue in hope that other people will share their observations.
might be related to: #21590

Steps to reproduce:

Minimal reproduction project:

bug editor

All 31 comments

Happening too in Windows 10, 64 bits, Intel HD 520 since shortly after Alpha 1

Also happening with alpha2 Win10-64 (while porting a project from 3.0, using GLES3 for now). Systematically appears when saving any scene, even a simple button scene (with 2 nodes: main parent button node, and child label, with a simple gdscript attached to the parent node, which is a tool script that mostly sets label text/font). I don't know how to hunt down this problem, so far making it impossible to use alpha2 (with my code base).

I had a breakpoint in message_queue.cpp at the line where the Object was deleted while awaiting a callback is printed. When I by accident moved one folder in my project into another one (by drag and drop), the error occurred. I'm pasting the stack trace below (sorry for it being in png, I'm not sure how to copy stack from the QT creator):
stack_trace
it was on 6e5872b70978b4ded3ade769ff46a44de6a6eb02

Just started getting this, doing some digging, but this is impossible to work with and should be fixed before official 3.1/beta

I just got this error and crash while saving a scene using master (f34ab4f05dc8ca111628a83a36369ddebb1a0e52):

Object was deleted while awaiting a callback
Object was deleted while awaiting a callback
TOTAL BYTES: 1048560
NULL count: 1
CALL : 64
CALL emit_signal: 56
CALL _update_callback: 11
CALL _update_minimum_size: 4
CALL _sort_children: 1
CALL _update_hover: 16
CALL _cursor_changed_emit: 28
CALL _text_changed_emit: 28
CALL _update_script_names: 1
CALL _script_list_gui_input: 7
CALL _tree_thumbnail_done: 8670
CALL _update_tree: 1
CALL _test_update_tree: 8
CALL _update_bone_list: 1
ERROR: push_call: Message queue out of memory. Try increasing 'message_queue_size_kb' in project settings.
   At: core/message_queue.cpp:56.
Failed method: FileSystemDock:_tree_thumbnail_done target ID: 8099
Object was deleted while awaiting a callback
Object was deleted while awaiting a callback
Object was deleted while awaiting a callback
<snip a lot>
Object was deleted while awaiting a callback
Object was deleted while awaiting a callback
Object was deleted while awaiting a callback
ERROR: resize: Condition ' !_ptrnew ' is true. returned: ERR_OUT_OF_MEMORY
   At: ./core/cowdata.h:273.
handle_crash: Program crashed with signal 11
Dumping the backtrace. Please include this when reporting the bug on https://github.com/godotengine/godot/issues
[1] /lib/x86_64-linux-gnu/libc.so.6(+0x3ef20) [0x7f1b12ef6f20] (??:0)
[2] CowData<RichTextLabel::Line>::size() const (godot/./core/cowdata.h:125)
[3] Vector<RichTextLabel::Line>::size() const (godot/./core/vector.h:87)
[4] RichTextLabel::add_newline() (godot/scene/gui/rich_text_label.cpp:1445)
[5] EditorLog::add_message(String const&, EditorLog::MessageType) (godot/editor/editor_log.cpp:90)
[6] EditorLog::_error_handler(void*, char const*, char const*, int, char const*, char const*, ErrorHandlerType) (godot/editor/editor_log.cpp:45)
[7] _err_print_error(char const*, char const*, int, char const*, ErrorHandlerType) (godot/core/error_macros.cpp:90 (discriminator 4))
[8] CowData<RichTextLabel::Line>::resize(int) (godot/./core/cowdata.h:273 (discriminator 1))
[9] Vector<RichTextLabel::Line>::resize(int) (godot/./core/vector.h:88)
[10] RichTextLabel::add_newline() (godot/scene/gui/rich_text_label.cpp:1448)
[11] EditorLog::add_message(String const&, EditorLog::MessageType) (godot/editor/editor_log.cpp:90)
[12] EditorNode::_print_handler(void*, String const&, bool) (godot/editor/editor_node.cpp:4671 (discriminator 4))
[13] print_line(String) (godot/core/print_string.cpp:87)
[14] MessageQueue::statistics() (godot/core/message_queue.cpp:213 (discriminator 3))
[15] MessageQueue::push_call(unsigned long, StringName const&, Variant const**, int, bool) (godot/core/message_queue.cpp:55)
[16] MessageQueue::push_call(unsigned long, StringName const&, Variant const&, Variant const&, Variant const&, Variant const&, Variant const&) (godot/core/message_queue.cpp:92)
[17] MessageQueue::push_call(Object*, StringName const&, Variant const&, Variant const&, Variant const&, Variant const&, Variant const&) (godot/core/message_queue.cpp:157)
[18] Object::call_deferred(StringName const&, Variant const&, Variant const&, Variant const&, Variant const&, Variant const&) (godot/core/object.cpp:1773)
[19] EditorResourcePreview::queue_resource_preview(String const&, Object*, StringName const&, Variant const&) (godot/editor/editor_resource_preview.cpp:354 (discriminator 10))
[20] FileSystemDock::_create_tree(TreeItem*, EditorFileSystemDirectory*, Vector<String>&) (godot/editor/filesystem_dock.cpp:113 (discriminator 6))
[21] FileSystemDock::_create_tree(TreeItem*, EditorFileSystemDirectory*, Vector<String>&) (godot/editor/filesystem_dock.cpp:84 (discriminator 1))
[22] FileSystemDock::_create_tree(TreeItem*, EditorFileSystemDirectory*, Vector<String>&) (godot/editor/filesystem_dock.cpp:84 (discriminator 1))
[23] FileSystemDock::_update_tree(Vector<String>, bool) (godot/editor/filesystem_dock.cpp:224)
[24] FileSystemDock::_fs_changed() (godot/editor/filesystem_dock.cpp:852 (discriminator 2))
[25] MethodBind0::call(Object*, Variant const**, int, Variant::CallError&) (godot/./core/method_bind.gen.inc:56 (discriminator 4))
[26] Object::call(StringName const&, Variant const**, int, Variant::CallError&) (godot/core/object.cpp:945 (discriminator 1))
[27] Object::emit_signal(StringName const&, Variant const**, int) (godot/core/object.cpp:1231 (discriminator 1))
[28] Object::_emit_signal(Variant const**, int, Variant::CallError&) (godot/core/object.cpp:1160)
[29] MethodBindVarArg<Object>::call(Object*, Variant const**, int, Variant::CallError&) (godot/./core/method_bind.h:343 (discriminator 4))


[30] Object::call(StringName const&, Variant const**, int, Variant::CallError&) (godot/core/object.cpp:945 (discriminator 1))
[31] MessageQueue::_call_function(Object*, StringName const&, Variant const*, int, bool) (godot/core/message_queue.cpp:256)
[32] MessageQueue::flush() (godot/core/message_queue.cpp:302)
[33] SceneTree::iteration(float) (godot/scene/main/scene_tree.cpp:477 (discriminator 2))
[34] Main::iteration() (godot/main/main.cpp:1834)
[35] OS_X11::run() (godot/platform/x11/os_x11.cpp:2821)
[36] godot/bin/godot.x11.tools.64(main+0xdc) [0x1137563] (godot/platform/x11/godot_x11.cpp:56)
[37] /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xe7) [0x7f1b12ed9b97] (??:0)
[38] godot/bin/godot.x11.tools.64(_start+0x2a) [0x11373ca] (??:?)
-- END OF BACKTRACE --

Hi everyone who has gotten this bug in the editor. Were you by chance opening an existing project in a new build of godot that may have different tab/space preference settings?

@dodgyville Yes.
After deleting all temporary files and folders in ../Godot saving seems to work propperly again.

edit: sorry, false alarm. The bug problem still occurs.

@pixelriot wroked for me too.
I had the problem when launching the game from the editor.

I am having the problem again, here my stacktrace

1  MessageQueue::statistics                      message_queue.cpp           213  0x3f4472c 
2  MessageQueue::push_call                       message_queue.cpp           54   0x3f43f3c 
3  MessageQueue::push_call                       message_queue.cpp           91   0x3f45127 
4  MessageQueue::push_call                       message_queue.cpp           157  0x3f45e04 
5  Object::call_deferred                         object.cpp                  1773 0x3f5bb15 
6  EditorResourcePreview::queue_resource_preview editor_resource_preview.cpp 354  0x23570c9 
7  FileSystemDock::_create_tree                  filesystem_dock.cpp         113  0x23d27ae 
8  FileSystemDock::_create_tree                  filesystem_dock.cpp         84   0x23d2302 
9  FileSystemDock::_create_tree                  filesystem_dock.cpp         84   0x23d2302 
10 FileSystemDock::_update_tree                  filesystem_dock.cpp         223  0x23d3e19 
11 FileSystemDock::_fs_changed                   filesystem_dock.cpp         852  0x23dcbda 
12 MethodBind0<FileSystemDock>::call             method_bind.gen.inc         137  0x23fc206 
13 Object::call                                  object.cpp                  945  0x3f522be 
14 Object::emit_signal                           object.cpp                  1231 0x3f54085 
15 Object::_emit_signal                          object.cpp                  1158 0x3f536f9 
16 MethodBindVarArg<Object>::call                method_bind.h               342  0x3f6a058 
17 Object::call                                  object.cpp                  945  0x3f522be 
18 MessageQueue::_call_function                  message_queue.cpp           256  0x3f45f93 
19 MessageQueue::flush                           message_queue.cpp           300  0x3f4624e 
20 SceneTree::iteration                          scene_tree.cpp              476  0x2d776d2 
21 Main::iteration                               main.cpp                    1848 0x1533550 
22 OS_X11::run                                   os_x11.cpp                  2821 0x14fbf0e 
23 main                                          godot_x11.cpp               55   0x14ebe01 

@kubecz3k Apparently now it is possible to copy from qtcreator stack with rightclick > copy to clipboard. I have the latest version available on ArchLinux.

This is probably a good candidate for this bug : https://github.com/godotengine/godot/commit/03563c8ddf748b73c6bef962f14e0e41eac45447#diff-437a2597f8c2e9b25f7b975bbfd73b2e

CC @groud

Possibly related to #23755

Seems like there are issues with FileSystemDock and saving.

@kubecz3k I reverted https://github.com/godotengine/godot/commit/8f3becafeb254b27fdbf8f1e4dfba4feccb6ce23 on my machine and the problem didn't present itself so far. Can I ask you to test on your godot version too?

I have recently deleted some additional files from my project and reimported all the assets and it seems it's way better now (to fresh to be sure). Will check without 8f3beca if I will encounter this again.

@kubecz3k It seems to me that godot is "leaking" files in the .import folder, because it is not removing them when an item is moved, it seems like it creates a new file instead and does no check for orphan ones (EDIT found the issue related #17733).
Might be related to this problem.

@QbieShay if you will still encounter the problem with 8f3beca reverted, try to remove .import folder in your project and let Godot reimport everything. I'm interested if this will improve things for you.
(please make a copy of whole project before you remove .import directory)

@kubecz3k removing the .import should not break anything in the project.

Back on topic, i found out that deleting the folder in ./config/godot/projects makes this problem disappear for a while.

I reverted 8f3beca on my machine and the problem didn't present itself so far. Can I ask you to test on your godot version too?

Assigning @groud for now based on the above - I'm not sure how it relates to this commit exactly, but I am however pretty sure that we do have memory leaks related to the new filesystem dock (as seen by several users when importing the TPS demo, which may also be related to this issue).

If the problem comes from my modification of the FileSystem dock, it is likely related to the thumbnail generation. The problem is that the debug output created when the problem occurs is really light, and does not help a lot :/

@groud I suggest to revert this commit until it is clear where the problem lies since it is significantly slowing the workflow on big projects. I can't provide you a test case but maybe @Faless can? (here his issue https://github.com/godotengine/godot/issues/23755)

This commit is very unlikely to be the direct cause of the problem, which probably might still occur on some situation. I think reverting the commit had no real effect on the project, but it's more likely that the thumbnail generation stabilized after all thumbnails were generated. Maybe you could try delete the godot cache folder and see if this makes the problem reproducible.

I think the problem most likely comes from something like b2633a97b9efa7b926d6682342480c5ccb482369 or 7d59e05ae8cf94470a9853cbe20fd67c14c4571c.

@groud actually it is the other way around: the longer you keep your project 'in use' the more frequent this problem becomes. Deleting the project folder in the .config folder makes the problem go away for a while, I'd say a couple of days (other users reported this behaviour too). I'll tell you in a few days if the problem presents itself again but so far i didn't see it happen.

8f3beca might not be the direct problem but it is, likely, the trigger of it. Maybe there are some interactions introduced in that commit that expose the problem. It is surely worth investigating as 3.1 can't be launched with this issue, in my opinion.

I think it is worth mentioning that when i had this problem i was working with only the tree view of the folders, maybe it has to do with it.

I got the problem today again, and I was able to get the stack trace. This stack is for the scenario when scene gets saved in order to run, it's very similar to the one that @QbieShay provided:

1  MessageQueue::statistics                      message_queue.cpp           213  0x30e1b93 
2  MessageQueue::push_call                       message_queue.cpp           54   0x30e09e7 
3  MessageQueue::push_call                       message_queue.cpp           91   0x30e0e67 
4  MessageQueue::push_call                       message_queue.cpp           157  0x30e1912 
5  Object::call_deferred                         object.cpp                  1773 0x30f3663 
6  EditorResourcePreview::queue_resource_preview editor_resource_preview.cpp 354  0x1c794c2 
7  FileSystemDock::_create_tree                  filesystem_dock.cpp         113  0x1cd83dc 
8  FileSystemDock::_create_tree                  filesystem_dock.cpp         84   0x1cd8108 
9  FileSystemDock::_create_tree                  filesystem_dock.cpp         84   0x1cd8108 
10 FileSystemDock::_create_tree                  filesystem_dock.cpp         84   0x1cd8108 
11 FileSystemDock::_update_tree                  filesystem_dock.cpp         223  0x1cd91c5 
12 FileSystemDock::_fs_changed                   filesystem_dock.cpp         852  0x1ce0229 
13 MethodBind0::call                             method_bind.gen.inc         54   0x11c78bd 
14 Object::call                                  object.cpp                  945  0x30eb69f 
15 Object::emit_signal                           object.cpp                  1231 0x30ed0cb 
16 Object::_emit_signal                          object.cpp                  1158 0x30eca8f 
17 MethodBindVarArg<Object>::call                method_bind.h               342  0x310042e 
18 Object::call                                  object.cpp                  945  0x30eb69f 
19 MessageQueue::_call_function                  message_queue.cpp           256  0x30e248e 
20 MessageQueue::flush                           message_queue.cpp           300  0x30e26fb 
21 SceneTree::iteration                          scene_tree.cpp              476  0x2400499 
22 Main::iteration                               main.cpp                    1834 0x1171d6b 
23 OS_X11::run                                   os_x11.cpp                  2821 0x1145879 
24 main                                          godot_x11.cpp               55   0x11376f3 

it was on 173b342ca738916cf113554291bb11f7cce71043

@kubecz3k @groud reverting 8f3beca apparently did not work, sorry.
@kubecz3k can you inspect which function is being called? For me it is "_tree_thumbnail_done"

image

@QbieShay checked, it's the same method (_tree_thumbnail_done)

Maybe I am wrong, but I suspect that the "Object was deleted while awaiting a callback" message is only a consequence of a crash into the main thread. Indeed, the resource thumbnail generation is made into another thread, so if the main thread crashes, it might still be trying to send the messages back to the main thread, which cannot respond.

I think we should investigate if there is a crash somewhere else, because the callback itself does not look to be the problem.

@groud isn't the deferred function call happening in the main thread?

@groud isn't the deferred function call happening in the main thread?

I don't think so, since the thumbnail creation is done in another thread and the _tree_thumbnail_done function is called when the preview is ready.
Also, the "Object was deleted while awaiting a callback" is triggered if the callback target is destroyed before receiving the message. But the fact is that the target here is the FileSystemDock object, which never gets deleted manually in the code. That's why I suspect this object to be deleted due to a crash in the main thread.
But that's only a possibility, I am not really sure about it.

@groud maybe it is worth to rewrite the code to be single threaded and see what happens.

Without knowing the code, i have the impression that what happens is that the object that should receive the thumbnail (entry in the scene tree) gets destroyed when it gets folded and for some reason saving is folding and unfolding the scene tree. Is that possible?

Looking at the code, seems like the print_line("Object was deleted while awaiting a callback"); message and the whole statistics function are only called when the message queue is out of memory. Is it possible that too many deferred calls are made leading to an OOM?

Also, crashing at line 213 is quite strange, as there is only a print_line there. Given that @dodgyville's stacktrace includes the following error, I think it might be caused from the construction of a String object, but don't trust me on that.

ERROR: resize: Condition ' !_ptrnew ' is true. returned: ERR_OUT_OF_MEMORY
   At: ./core/cowdata.h:273.

It is possible that somehow the arguments passed to call_deferred are getting leaked, but I'm not really sure about that either. In any case, I think that the crash results from the leak.

Without knowing the code, i have the impression that what happens is that the object that should receive the thumbnail (entry in the scene tree) gets destroyed when it gets folded and for some reason saving is folding and unfolding the scene tree. Is that possible?

The target of the callback itself (the FileSystemDock) never gets destroyed, but the tree which gets updated might be destroyed. But to avoid a problem, I used an ID that is incremented every time the Tree gets an update, so that the callback does nothing if the preview is out of date.
It might be somehow the cause of the problem.

Was this page helpful?
0 / 5 - 0 ratings