LibreELEC.tv [BUG] service.libreelec.settings: crash kodi on shutdown/reboot

Describe the bug

Hello, I am currently modifying the addon service.libreelec.settings to adapt it to a Kodi installation on Debian 10 in order to benefit from the good support of bluetooth via this addon without reinventing the wheel myself. This is a personal use for the moment. I am facing a long time bug causing a crash/segfault of kodi in case of reboot or shutdown of the system initiated from the interface.

Similar problems seem to be solved in the past by several commits (non exhaustive list) and linked to the use of D-Bus: https://github.com/xbmc/xbmc/pull/17718 https://forum.kodi.tv/showthread.php?tid=343069&pid=2934136#pid2934136

This problem is exclusively due to the addon because it does not occur in its absence.

To Reproduce

The message "## LibreELEC Addon ## STOP SERVICE DONE !" appears in the kodi log which does not display any error. The oe.stop_service() method is therefore correctly executed: https://github.com/LibreELEC/service.libreelec.settings/blob/8b1efa30632dd4b5c0493cfab2cc940a927392de/service.py#L104

Steps to avoid the crash:

Since the following service stop code is trivial (end of Monitor.run() method) and unlikely to be involved, I decided to explicitly remove the global variables created in dbus_utils.py

https://github.com/LibreELEC/service.libreelec.settings/blob/master/resources/lib/dbus_utils.py#L118-L122

Lines added at the end of: https://github.com/LibreELEC/service.libreelec.settings/blob/8b1efa30632dd4b5c0493cfab2cc940a927392de/service.py#L78

# module header
import gc
gc.set_debug(gc.DEBUG_LEAK)

...
# end of Monitor.run()
del service_thread
del dbus_utils.LOOP_THREAD
del dbus_utils.LOOP
del dbus_utils.BUS

n = gc.collect()
xbmc.log("Unreachable objects: " + str(n))
xbmc.log("Remaining Garbage: " + str(len(gc.garbage)))

Only del dbus_utils.BUS followed by a collection seems really useful.

Here is the log:

## LibreELEC Addon ## STOP SERVICE DONE !
ERROR <general>: Exception ignored in:
ERROR <general>: <function Connection.__del__ at 0x7f233eb88488>
ERROR <general>:

ERROR <general>: Traceback (most recent call last):
ERROR <general>:   File "/home/pi/.local/lib/python3.7/site-packages/ravel.py", line 287, in __del__
ERROR <general>:
ERROR <general>: remove_listeners(self._client_dispatch, [])
ERROR <general>:
ERROR <general>:   File "/home/pi/.local/lib/python3.7/site-packages/ravel.py", line 268, in remove_listeners
ERROR <general>:
ERROR <general>: for interface in level.interfaces.values() :
ERROR <general>:
ERROR <general>: AttributeError
ERROR <general>: :
ERROR <general>: '_ClientDispatchNode' object has no attribute 'interfaces'

DEBUG <general>: Unreachable objects: 310
DEBUG <general>: Remaining Garbage: 0

The dbus connection object does not seem to be deleted correctly, even if it is explicitly requested with del. The _ClientDispatchNode object in does not indeed contain an interfaces attribute, but I don't know enough about the dbussy package and its ravel module to say. Besides, the documentation is sometimes minimal...

The problem seems to be due to a failure to clean the variables for a reason that I can not figure out. I hope that this will put you on the track of a definitive resolution of the problem related to the management of dbus.

Informations

LE Version: _
Hardware Platform: _
LE settings: Taken from https://github.com/LibreELEC/LibreELEC.tv/issues/4547 service.libreelec.settings-10.0-20210809.zip
dbussy version: 1.3 (from pypi)
Python: 3.7 (debian buster)

Additional notes

I also found a typo in this code:

https://github.com/LibreELEC/service.libreelec.settings/blob/8b1efa30632dd4b5c0493cfab2cc940a927392de/resources/lib/dbus_utils.py#L85-L87

https://github.com/LibreELEC/service.libreelec.settings/blob/8b1efa30632dd4b5c0493cfab2cc940a927392de/resources/lib/dbus_utils.py#L49-L55

This is the worst way to cast a boolean to a string in Python, the syntax should be simply: str(int(data))

Sep 16 '21 17:09 ysard

Linked WIP fix: https://github.com/LibreELEC/service.libreelec.settings/pull/245

Nov 09 '21 23:11 heitbaum

I'm adding some more recent logs.

Shutdown Kodi with `del` on `BUS` variable

2021-11-09 18:59:14.561 T:878     DEBUG <general>: ## LibreELEC Addon ## STOP SERVICE DONE !
2021-11-09 18:59:14.562 T:878     DEBUG <general>: SETTINGS: Service_Thread.stop -
2021-11-09 18:59:14.562 T:878     DEBUG <general>: SETTINGS: Service_Thread.stop < <Service_Thread(Thread-2, started daemon 140271913600768)>
2021-11-09 18:59:14.562 T:912      INFO <general>: SETTINGS: run # Received exit
2021-11-09 18:59:14.562 T:912     DEBUG <general>: SETTINGS: Service_Thread.run > None
2021-11-09 18:59:14.562 T:878     DEBUG <general>: SETTINGS: Service_Thread.stop > None
2021-11-09 18:59:14.562 T:878     DEBUG <general>: SETTINGS: LoopThread.stop -
2021-11-09 18:59:14.562 T:878     DEBUG <general>: SETTINGS: LoopThread.stop < <LoopThread(Thread-1, started 140271925925632)>
2021-11-09 18:59:14.754 T:907     DEBUG <general>: SETTINGS: LoopThread.run > None
2021-11-09 18:59:14.754 T:878     DEBUG <general>: SETTINGS: LoopThread.stop > None
2021-11-09 18:59:14.785 T:878     DEBUG <general>: SETTINGS: Monitor.run > None
2021-11-09 18:59:14.785 T:878      INFO <general>: CPythonInvoker(2, /home/pi/.kodi/addons/service.libreelec.settings/service.py): script successfully run
2021-11-09 18:59:14.786 T:878     DEBUG <general>: onExecutionDone(2, /home/pi/.kodi/addons/service.libreelec.settings/service.py)
2021-11-09 18:59:14.786 T:878     DEBUG <general>: .
2021-11-09 18:59:14.805 T:878      INFO <general>: Python interpreter interrupted by user
2021-11-09 18:59:14.805 T:804     DEBUG <general>: CPythonInvoker(2, /home/pi/.kodi/addons/service.libreelec.settings/service.py): script termination took 250ms
2021-11-09 18:59:14.806 T:804     DEBUG <general>: CServiceAddonManager: stopping service.xbmc.versioncheck.
2021-11-09 18:59:14.806 T:878     DEBUG <general>: Thread LanguageInvoker 140272801400576 terminating
2021-11-09 18:59:14.806 T:804      INFO <general>: CServiceAddonManager: failed to stop service.xbmc.versioncheck (may have ended)
2021-11-09 18:59:14.806 T:851     DEBUG <general>: Thread ActiveAE 140274460374784 terminating
2021-11-09 18:59:14.818 T:852     DEBUG <general>: Thread AESink 140274451982080 terminating
2021-11-09 18:59:15.043 T:808     DEBUG <general>: Sink changed
2021-11-09 18:59:15.044 T:804      INFO <general>: Application stopped
2021-11-09 18:59:15.254 T:804     DEBUG <general>: LogindUPowerSyscall - inhibit lock taken, fd 4
2021-11-09 18:59:15.324 T:804     DEBUG <general>: ------ Window Init (DialogBusy.xml) ------
2021-11-09 18:59:15.324 T:804      INFO <general>: XBApplicationEx: destroying...
2021-11-09 18:59:15.325 T:873     DEBUG <general>: Thread PeripEventScan 140273241093888 terminating
2021-11-09 18:59:15.340 T:867     DEBUG <general>: Thread PeripBusUSBUdev 140273266272000 terminating
2021-11-09 18:59:15.341 T:868     DEBUG <general>: Thread PeripBusCEC 140273257879296 terminating
2021-11-09 18:59:15.341 T:869     DEBUG <general>: Thread PeripBusAddon 140273249486592 terminating
2021-11-09 18:59:15.559 T:804      INFO <general>: unload skin
2021-11-09 18:59:15.561 T:804     DEBUG <general>: ------ Window Deinit (DialogButtonMenu.xml) ------
2021-11-09 18:59:15.561 T:804     DEBUG <general>: ------ Window Deinit (Home.xml) ------
2021-11-09 18:59:15.561 T:804     DEBUG <general>: FreeVisualisation() done
2021-11-09 18:59:15.568 T:804     DEBUG <general>: Skipped 1 duplicate messages..
2021-11-09 18:59:15.568 T:804     DEBUG <general>: ------ Window Deinit (DialogBusy.xml) ------
2021-11-09 18:59:15.571 T:804     DEBUG <general>: CloseBundle - Closed bundle
2021-11-09 18:59:15.576 T:804      INFO <general>: Unloaded skin
2021-11-09 18:59:15.578 T:804      INFO <general>: unload sections
2021-11-09 18:59:15.580 T:804     DEBUG <general>: LogindUPowerSyscall - delay lock sleep released
2021-11-09 18:59:15.580 T:804     DEBUG <general>: LogindUPowerSyscall - delay lock shutdown released
2021-11-09 18:59:15.582 T:874     DEBUG <general>: Thread Timer 140272826578688 terminating
2021-11-09 18:59:15.583 T:809     DEBUG <general>: Thread Lirc 140274468767488 terminating
2021-11-09 18:59:15.584 T:804     DEBUG <general>: object 0 --> 0 instances
2021-11-09 18:59:15.584 T:804     DEBUG <general>: object 1 --> 0 instances
2021-11-09 18:59:15.584 T:804     DEBUG <general>: object 2 --> 0 instances
2021-11-09 18:59:15.584 T:804     DEBUG <general>: object 3 --> 0 instances
2021-11-09 18:59:15.584 T:804     DEBUG <general>: object 4 --> 0 instances
2021-11-09 18:59:15.584 T:804     DEBUG <general>: object 5 --> 0 instances
2021-11-09 18:59:15.584 T:804     DEBUG <general>: object 6 --> 0 instances
2021-11-09 18:59:15.584 T:804     DEBUG <general>: object 7 --> 0 instances
2021-11-09 18:59:15.584 T:804     DEBUG <general>: object 8 --> 0 instances
2021-11-09 18:59:15.584 T:804     DEBUG <general>: object 9 --> 0 instances
2021-11-09 18:59:15.587 T:804      INFO <general>: XRANDR: /usr/lib/x86_64-linux-gnu/kodi/kodi-xrandr --screen 0 --output HDMI-1 --mode 0x81

Shutdown Kodi without `del` on `BUS` variable

2021-11-09 18:45:05.503 T:3046    DEBUG <general>: ## LibreELEC Addon ## STOP SERVICE DONE !
2021-11-09 18:45:05.503 T:3046    DEBUG <general>: SETTINGS: Service_Thread.stop -
2021-11-09 18:45:05.503 T:3046    DEBUG <general>: SETTINGS: Service_Thread.stop < <Service_Thread(Thread-2, started daemon 139997634230016)>
2021-11-09 18:45:05.503 T:3059     INFO <general>: SETTINGS: run # Received exit
2021-11-09 18:45:05.503 T:3059    DEBUG <general>: SETTINGS: Service_Thread.run > None
2021-11-09 18:45:05.503 T:3046    DEBUG <general>: SETTINGS: Service_Thread.stop > None
2021-11-09 18:45:05.503 T:3046    DEBUG <general>: SETTINGS: LoopThread.stop -
2021-11-09 18:45:05.503 T:3046    DEBUG <general>: SETTINGS: LoopThread.stop < <LoopThread(Thread-1, started 139997647357696)>
2021-11-09 18:45:06.053 T:3055    DEBUG <general>: SETTINGS: LoopThread.run > None
2021-11-09 18:45:06.054 T:3046    DEBUG <general>: SETTINGS: LoopThread.stop > None
2021-11-09 18:45:06.054 T:3046    DEBUG <general>: SETTINGS: Monitor.run > None
2021-11-09 18:45:06.054 T:3046     INFO <general>: CPythonInvoker(2, /home/pi/.kodi/addons/service.libreelec.settings/service.py): script successfully run
2021-11-09 18:45:06.054 T:3046    DEBUG <general>: onExecutionDone(2, /home/pi/.kodi/addons/service.libreelec.settings/service.py)
2021-11-09 18:45:06.054 T:3046    DEBUG <general>: .
2021-11-09 18:45:06.083 T:3046     INFO <general>: Python interpreter interrupted by user
2021-11-09 18:45:06.083 T:3022    DEBUG <general>: CPythonInvoker(2, /home/pi/.kodi/addons/service.libreelec.settings/service.py): script termination took 585ms
2021-11-09 18:45:06.083 T:3022    DEBUG <general>: CServiceAddonManager: stopping service.xbmc.versioncheck.
2021-11-09 18:45:06.083 T:3046    DEBUG <general>: Thread LanguageInvoker 139998527211264 terminating
2021-11-09 18:45:06.083 T:3022     INFO <general>: CServiceAddonManager: failed to stop service.xbmc.versioncheck (may have ended)
2021-11-09 18:45:06.083 T:3027    DEBUG <general>: Thread ActiveAE 140000183580416 terminating
2021-11-09 18:45:06.117 T:3028    DEBUG <general>: Thread AESink 140000175187712 terminating
2021-11-09 18:45:06.313 T:3025    DEBUG <general>: Sink changed
2021-11-09 18:45:06.314 T:3022     INFO <general>: Application stopped

=> nothing more, the app crashed

Nov 11 '21 04:11 ysard

I've removed LE 10 and 11 labels. This is reported for debian buster with Python: 3.7 (and likely without our asyncio patch).

IMO there is no report for LE.

Feedback is always welcome and we should test the resulting dbussy fix better sooner than later in nightlies.

Nov 11 '21 18:11 mglae

Is this still an issue?

Feb 17 '22 11:02 heitbaum

Assuming that this is no longer a problem. If still an issue - please update and reopen the issue.

Sep 06 '23 08:09 heitbaum

LibreELEC.tv LibreELEC.tv copied to clipboard

[BUG] service.libreelec.settings: crash kodi on shutdown/reboot

Describe the bug

To Reproduce

Steps to avoid the crash:

Informations

Additional notes

Shutdown Kodi with del on BUS variable

Shutdown Kodi without del on BUS variable

LibreELEC.tv
LibreELEC.tv copied to clipboard

Shutdown Kodi with `del` on `BUS` variable

Shutdown Kodi without `del` on `BUS` variable