Bug: exception during teardown of QModelMenu with submenus

[tlambert03]

          Oh while you're here, I noticed that you can't build a `QModelMenu` for submenus because during teardown error results:

see: https://github.com/napari/napari/pull/4865/files#r1288031823

Originally posted by @lucyleeow in #142 (comment)

@lucyleeow, can you make a quick example of this bug? I see the traceback you posted, but it's hard to determine exactly what you ran to get it.

[lucyleeow]

Sorry, I've been trying and failing to make a min reproducible example of the bug (I realise I don't understand it well).

In the mean time, in case you wanted to take a look, I re-created the original error in napari. Using this branch in my fork (just built a submenu QModelMenu in _qt_main_window), running the test: napari/_qt/dialogs/_tests/test_reader_dialog.py::test_open_with_dialog_choices_persist

[tlambert03]

thanks! that's sufficient. Fix coming in #151

[lucyleeow]

Thanks, I was trying to reproduce by manually running rebuild on menu then submenu but I missed the event where the menu was removed.

[tlambert03]

a quick tip there: the most useful information for an error that occurs during a callback connected to psygnal Signal will usually come one frame higher in the stack trace. So, in your test error:

napari/_qt/dialogs/_tests/test_reader_dialog.py .E                                                                                [0/1]
napari/_qt/dialogs/_tests/test_reader_dialog.py:170 test_open_with_dialog_choices_persist - psygnal._exceptions.EmitLoopErro…
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> traceback >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>

>   ???

src/psygnal/_signal.py:990:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
src/psygnal/_weak_callback.py:377: in cb
    ???
../app-model/src/app_model/backends/qt/_qmenu.py:123: in _on_registry_changed
    self.rebuild()
../app-model/src/app_model/backends/qt/_qmenu.py:105: in rebuild
    _rebuild(
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

menu = <app_model.backends.qt._qmenu.QModelMenu object at 0x13c44a7a0>, app = Application('test_app')
menu_id = <MenuId.FILE_SAMPLES: 'napari/file/samples'>, include_submenus = True, exclude = None

    def _rebuild(
        menu: QMenu | QToolBar,
        app: Application,
        menu_id: str,
        include_submenus: bool = True,
        exclude: Optional[Collection[str]] = None,
    ) -> None:
        """Rebuild menu by looking up `menu` in `Application`'s menu_registry."""
>       menu.clear()
E       RuntimeError: wrapped C/C++ object of type QModelMenu has been deleted

../app-model/src/app_model/backends/qt/_qmenu.py:314: RuntimeError

The above exception was the direct cause of the following exception:

_npe2pm = <npe2._pytest_plugin.TestPluginManager object at 0x13793d0f0>

    @pytest.fixture
    def builtins(_npe2pm: TestPluginManager):
>       with _npe2pm.tmp_plugin(package='napari') as plugin:

napari/conftest.py:287:
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
../../../miniforge3/envs/napari/lib/python3.10/site-packages/npe2/_dynamic_plugin.py:132: in __exit__
    self.cleanup()
../../../miniforge3/envs/napari/lib/python3.10/site-packages/npe2/_dynamic_plugin.py:90: in cleanup
    self.plugin_manager.unregister(self.manifest.name)
../../../miniforge3/envs/napari/lib/python3.10/site-packages/npe2/_plugin_manager.py:364: in unregister
    self.deactivate(key)
../../../miniforge3/envs/napari/lib/python3.10/site-packages/npe2/_plugin_manager.py:433: in deactivate
    ctx._dispose()
../../../miniforge3/envs/napari/lib/python3.10/site-packages/npe2/_plugin_manager.py:713: in _dispose
    self._disposables.pop()()
../app-model/src/app_model/registries/_menus_reg.py:71: in _dispose
    self.menus_changed.emit(changed_ids)
src/psygnal/_signal.py:945: in emit
    ???
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

>   ???
E   psygnal._exceptions.EmitLoopError: calling <psygnal._weak_callback._WeakMethod object at 0x13c2c9ec0>
   with args=({<MenuId.FILE_SAMPLES: 'napari/file/samples'>},) caused RuntimeError:
   wrapped C/C++ object of type QModelMenu has been deleted.

src/psygnal/_signal.py:992: EmitLoopError

So, if you go one above "The above exception was the direct cause of the following exception: you'll see that the real error was in calling menu.clear() inside of the _rebuild() function, and that was called by QModelMenu.rebuild (line 105), and that in turn was called by QModelMenu._on_registry_changed (line 123). That last bit is your key there. Cause you can look to see what event is connected to _on_registry_changed, and there is only one: self._app.menus.menus_changed.connect(self._on_registry_changed) on line 64.

not like that's super clear 😂 ... but just a general tip to "look one higher" in the traceback :)

[lucyleeow]

Thanks! I guessed from the traceback that prior to the _rebuild() -> menu.clear(), the submenu had already been destroyed, I assume with the parent menu. I didn't work out what previous event caused the parent menu to be destroyed?

I see _on_registry_changed loops through all changed_ids and runs rebuild and tried to run rebuild on parent menu then submenu (in my min reproducer) but that did not work. Which makes sense as this wouldn't cause the parent menu to be destroyed before trying to rebuild the submenu. I saw the failure was during 'teardown' of the test so maybe the destroy was part of the clean up of make_napari_viewer? 😕

[lucyleeow]

I can understand that once the parent menu is destroyed, a menus_changed event gets emitted? Which causes rebuild of the submeu. But I just didn't follow where the parent menu was destroyed?

[tlambert03]

I didn't work out what previous event caused the parent menu to be destroyed? I saw the failure was during 'teardown' of the test so maybe the destroy was part of the clean up of make_napari_viewer?

ah, yep! the thing that started it all off was the with _npe2pm.tmp_plugin(package='napari') as plugin: context manager. When that context exits, it sets off a chain of cleanup:

../../../miniforge3/envs/napari/lib/python3.10/site-packages/npe2/_dynamic_plugin.py:132: in __exit__
    self.cleanup()
../../../miniforge3/envs/napari/lib/python3.10/site-packages/npe2/_dynamic_plugin.py:90: in cleanup
    self.plugin_manager.unregister(self.manifest.name)
../../../miniforge3/envs/napari/lib/python3.10/site-packages/npe2/_plugin_manager.py:364: in unregister
    self.deactivate(key)
../../../miniforge3/envs/napari/lib/python3.10/site-packages/npe2/_plugin_manager.py:433: in deactivate
    ctx._dispose()
../../../miniforge3/envs/napari/lib/python3.10/site-packages/npe2/_plugin_manager.py:713: in _dispose
    self._disposables.pop()()
../app-model/src/app_model/registries/_menus_reg.py:71: in _dispose
    self.menus_changed.emit(changed_ids)

so, i guess you could say it all starts with npe2 DynamicPlugin.__exit__
https://github.com/napari/npe2/blob/main/src/npe2/_dynamic_plugin.py#L132

[lucyleeow]

Ahhh that makes sense. For parent menus, no menus_changed event is emitted because that menu has been removed from the registry (?) but for parent menus with a submenu, the parent is removed from the registry but the submenu isn't (?) so menus_changed event is emitted with submenu as changed_ids ?

[lucyleeow]

Sorry, still confused about this. I can see that in MenusRegistry once all the menu items belonging to a key are removed, that key is deleted:

app-model/src/app_model/registries/_menus_reg.py

Lines 68 to 70 in 0140de7

	for id_ in changed_ids:
	if not self._menu_items.get(id_):
	del self._menu_items[id_]

But how would this result in deletion of the QModelMenu for the submenu?

The DynamicPlugin.cleanup() func and all follow on functions seem to be dealing with updating registries. I can't find where the QModelMenu for the submenu would be deleted?

Also I realise this would not be related to the parent menu ('napari/files' in this case) as removing a plugin is not going to result in that menu being deleted.

[tlambert03]

I can't find where the QModelMenu for the submenu would be deleted

generally speaking, for all instances of QObject and any of it's subclasses (which is basically every object in Qt), as soon as the last pointer to the object gets garbage collected, Qt will delete the object. So very often, you're not going to be looking for an explicit delete call anywhere, but rather figuring out why/where the last reference to the object got removed. The problem occurs when you're holding onto a Python reference to a Qt object that has been destroyed on the C++ side

Here's a somewhat contrived example that you can run:

from qtpy.QtWidgets import QApplication, QMainWindow, QPushButton

app = QApplication([])

window = QMainWindow()
btn1 = QPushButton("1")
btn2 = QPushButton("2")

# here window is assigned as the parent of btn1
window.setCentralWidget(btn1)
# because we can only have one central widget, btn1 is removed from window
# and Qt cleans up the memory for us
btn1.clicked.connect(lambda: window.setCentralWidget(btn2))
# but when we try to click on the new button, we have problem
# becuase our python pointer `btn1` now points to a deleted object
btn2.clicked.connect(lambda: window.setCentralWidget(btn1))

window.show()
app.exec()

on the second button click, you'll get:

Traceback (most recent call last):
  File "/Users/talley/dev/self/app-model/x.py", line 10, in <lambda>
    btn2.clicked.connect(lambda: window.setCentralWidget(btn1))
                                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
RuntimeError: wrapped C/C++ object of type QPushButton has been deleted
zsh: abort      python x.py

But note that we never actually "deleted" btn1 anywhere.

... so in this case, I would have to dig a bit deeper into the cleanup chain to tell you what race condition caused the QModelMenu to be deleted before that final callback was received. It's definitely not in the bit of code you linked there in the registries (nothing outside of the qt module would result in a qt object getting deleted like this...), but that bit of code is getting called after the Qt object was deleted (somewhere else) and that's the problem. not sure where that somewhere else is. I am curious and will try to find it, but it's also not terribly unusual to just catch the runtime error and be done with it :)

[tlambert03]

one more thing worth mentioning here...
there is a line that was designed to prevent this in _qmenu here

class QModelMenu(QMenu):
    def __init__(self):
        ...
        self.destroyed.connect(self._disconnect)
        # ----------------------

    def _disconnect(self) -> None:
        self._app.menus.menus_changed.disconnect(self._on_registry_changed)

but clearly the _disconnect callback connected to the destroyed signal is getting called to late to catch that last _rebuild call

[lucyleeow]

Ahh okay thanks, this was very enlightening. And yes, now that I know this, I can understand that one would usually just catch the error and leave it at that. Thank you!