search

blueman-project / blueman

Blueman is a GTK+ Bluetooth Manager
GNU General Public License v3.0
1.26k stars 191 forks source link

Blueman applet quit unexpectedly #2201

Closed m0nkeyc0de closed 7 months ago

m0nkeyc0de commented 10 months ago

blueman: blueman-1:2.3.5-8.fc39 BlueZ: bluez-5.70-3.fc39.x86_64 Distribution: Fedora 39 Desktop environment: gnome-shell-45.1-1.fc39.x86_64

Blueman applet usually crashes after logon at startup or while updating packages. Could not reproduce the issue by starting it manually in debug mode. The issue happens regularly. I already opened a Fedora bug here but I've no hope someone is going to look or it over there.

The failure reason is a Python exception regarding UTF-8 decoding but I'm unable to find out where and why. For example:

'utf-8' codec can't decode byte 0xe1 in position 4: invalid continuation byte

There isn't much information in the Fedora "Problem Report" tool. I'd be more that happy to help finding out the root cause but I can't find where this applet is started and how to enable debug logs to a file.

cschramm commented 10 months ago

This might just be #1241 / #620. I don't think the application actually crashes, does it?

m0nkeyc0de commented 10 months ago

This might just be #1241 / #620. I don't think the application actually crashes, does it?

The blueman-applet service is dead. So I guess the application isn't running.

$ systemctl --user status blueman-applet.service 
○ blueman-applet.service - Bluetooth management applet
     Loaded: loaded (/usr/lib/systemd/user/blueman-applet.service; static)
    Drop-In: /usr/lib/systemd/user/service.d
             └─10-timeout-abort.conf
     Active: inactive (dead)

I coudn't tell from the GUI if this is the case or not because I even don't know how where and how it's supposed to be.

I can systematically reproduce it when I manually turn off bluetooth before turning off my laptop : at reboot the issue happens.

I would not call it a harmless exception (as seen in #1241) as I have a notification almost each time I boot, telling me this piece of software has crashed. If it's harmless I shouldn't be bothered with it.

The bad thing about it is that there isn't the full Python exception to find out which line of code provokes this error.

m0nkeyc0de commented 10 months ago

Tried to add '--loglevel DEBUG' to the systemd unit but there aren't more logs in journalctl. It even seems no logs are produced at all.

Tried to catch the exception and write the traceback to a file in /tmp by modifying the blueman-applet executable, without any success.

I'd like to help to debug this issue but blueman-applet seems hard to debug, sadly (and it's not new according to #459)

cschramm commented 10 months ago

The systemd unit is a dbus service that invokes the application when its well-known name gets addressed on the bus. I'm not familiar with Fedora things, but most probably /etc/xdg/autostart/blueman.desktop is what causes blueman-applet autostart. I fail to make sense of the static keyword in your systemctl output, though. Tools like ps can tell you if blueman-applet is running, no matter how it gets invoked.

I would not call it a harmless exception (as seen in #1241) as I have a notification almost each time I boot, telling me this piece of software has crashed. If it's harmless I shouldn't be bothered with it.

The notification is not coming from blueman. It's some Fedora tool, I guess ABRT, that - assuming that it is the harmless exception, originating from a GLib bug - catches things that are not of interest. I don't know how the system is supposed to work, but probably there should be some kind of allowlist either distributed with ABRT or the blueman package that can be used to override such "false positives". Well, in the end it would be an ABRT bug anyway. The tool tells you that blueman-applet quit while it's probably still running, so it's straight up lying to you.

What most likely happens is that GLib tries to deliver some event to the application's mainloop and fails to do so. That's why you will not be able to catch anything as it does not happen in our code. It should be catchable in PyGObject code, I guess.

Anyway, my guess is that it does not happen in main due to #2009.

engn33r commented 9 months ago

I have been getting what may be a similar error blueman: blueman 2.3.5-3 BlueZ: bluez 5.68-0ubuntu1.1 Distro: Ubuntu 23.10

I get the same 'utf-8' codec can't decode byte 0xe1 in position 4: invalid continuation byte error and I see the same result from systemctl --user status blueman-applet.service after this error happens. I am not sure why the applet service is dead because the blueman manager continues running during this entire time, without any apparent down time. And I can see blueman applet in the output of ps x | grep blue.

This issue is usually possible for me to recreate when I pair Samsung Buds Pro 2 earbuds to the system. These earbuds work fine on all my other devices, but since about 1 month ago I cannot get A2DP working on this device. I assumed the error was related to this inability to use a certain profile after I repaired the headphones.

m0nkeyc0de commented 9 months ago

I think I found a way to reproduce the issue, as I noticed it also happened while updating OS packages.

When restarting the bluetooth service with sudo systemctl restart bluetooth I get the "blueman applet quit unexpectedly" notification, but only the first time I do it. If I repeat the command it doesn't happen again.

Then when I log-out and log-in again, sometimes the notification appears, sometimes not. But by restarting the bluetooth service I can make it appear once again.

It seems that this blueman applet crash occurs if bluetooth service restarts (for any reason) after the applet is loaded in Gnome, like it were a child process also dying when its parent get killed.

EDIT: the blueman-applet PID doesn't change when provoking error message by restarting bluetooth service. The process doesn't crash but Gnome thinks it does. This is quite a bit strange.

m0nkeyc0de commented 9 months ago

I could get some (I hope) interesting logs with journalctl -f while provoking the issue.

jan 01 15:17:28 fedora systemd[1]: blueman-mechanism.service: Deactivated successfully.
jan 01 15:17:40 fedora bluetoothd[16493]: Terminating
jan 01 15:17:40 fedora systemd[1]: Stopping bluetooth.service - Bluetooth service...
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSource/ldac
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSink/aptx_hd
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSource/aptx_hd
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSink/aptx
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSource/aptx
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSink/aac
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSource/aac
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSink/sbc
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSource/sbc
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSink/sbc_xq
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSource/sbc_xq
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSource/aptx_ll_1
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSource/aptx_ll_0
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSource/aptx_ll_duplex_1
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSource/aptx_ll_duplex_0
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSource/faststream
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSource/faststream_duplex
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSink/opus_05
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSource/opus_05
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSink/opus_05_duplex
jan 01 15:17:41 fedora bluetoothd[16493]: Endpoint unregistered: sender=:1.790 path=/MediaEndpoint/A2DPSource/opus_05_duplex
jan 01 15:17:41 fedora bluetoothd[16493]: Battery Provider Manager destroyed
jan 01 15:17:41 fedora bluetoothd[16493]: Stopping SDP server
jan 01 15:17:41 fedora bluetoothd[16493]: Exit
jan 01 15:17:41 fedora systemd[1]: bluetooth.service: Deactivated successfully.
jan 01 15:17:41 fedora systemd[1]: Stopped bluetooth.service - Bluetooth service.
jan 01 15:17:41 fedora systemd[1]: Starting bluetooth.service - Bluetooth service...
jan 01 15:17:41 fedora blueman-tray[19170]: gtk_widget_get_scale_factor: assertion 'GTK_IS_WIDGET (widget)' failed
jan 01 15:17:41 fedora blueman.desktop[18728]: blueman-applet 15.17.41 WARNING  DiscvManager:119 update_menuitems: warning: Adapter is None
jan 01 15:17:41 fedora python3[18728]: detected unhandled Python exception in '/usr/bin/blueman-applet'
jan 01 15:17:41 fedora bluetoothd[19557]: Bluetooth daemon 5.71
jan 01 15:17:41 fedora systemd[1]: Started bluetooth.service - Bluetooth service.
jan 01 15:17:41 fedora bluetoothd[19557]: Starting SDP server
jan 01 15:17:41 fedora bluetoothd[19557]: src/plugin.c:plugin_init() System does not support csip plugin
jan 01 15:17:41 fedora bluetoothd[19557]: profiles/audio/micp.c:micp_init() D-Bus experimental not enabled
jan 01 15:17:41 fedora bluetoothd[19557]: src/plugin.c:plugin_init() System does not support micp plugin
jan 01 15:17:41 fedora bluetoothd[19557]: src/plugin.c:plugin_init() System does not support vcp plugin
jan 01 15:17:41 fedora bluetoothd[19557]: src/plugin.c:plugin_init() System does not support mcp plugin
jan 01 15:17:41 fedora bluetoothd[19557]: src/plugin.c:plugin_init() System does not support bass plugin
jan 01 15:17:41 fedora bluetoothd[19557]: src/plugin.c:plugin_init() System does not support bap plugin
jan 01 15:17:41 fedora bluetoothd[19557]: Bluetooth management interface 1.22 initialized
jan 01 15:17:41 fedora bluetoothd[19557]: src/adapter.c:reset_adv_monitors_complete() Failed to reset Adv Monitors: Failed (0x03)
jan 01 15:17:41 fedora bluetoothd[19557]: Battery Provider Manager created
jan 01 15:17:41 fedora bluetoothd[19557]: Failed to clear UUIDs: Failed (0x03)
jan 01 15:17:41 fedora bluetoothd[19557]: Failed to add UUID: Failed (0x03)
jan 01 15:17:41 fedora bluetoothd[19557]: Failed to add UUID: Failed (0x03)
jan 01 15:17:41 fedora bluetoothd[19557]: Failed to add UUID: Failed (0x03)
jan 01 15:17:41 fedora blueman.desktop[18728]: UnicodeDecodeError: 'utf-8' codec can't decode byte 0xf6 in position 1: invalid start byte
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSource/ldac
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSink/aptx_hd
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSource/aptx_hd
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSink/aptx
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSource/aptx
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSink/aac
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSource/aac
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSink/sbc
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSource/sbc
jan 01 15:17:41 fedora blueman.desktop[18728]: blueman-applet 15.17.41 WARNING  DiscvManager:119 update_menuitems: warning: Adapter is None
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSink/sbc_xq
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSource/sbc_xq
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSource/aptx_ll_1
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSource/aptx_ll_0
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSource/aptx_ll_duplex_1
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSource/aptx_ll_duplex_0
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSource/faststream
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSource/faststream_duplex
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSink/opus_05
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSource/opus_05
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSink/opus_05_duplex
jan 01 15:17:41 fedora bluetoothd[19557]: Endpoint registered: sender=:1.790 path=/MediaEndpoint/A2DPSource/opus_05_duplex
jan 01 15:17:41 fedora blueman.desktop[18728]: UnicodeDecodeError: 'utf-8' codec can't decode byte 0xed in position 1: invalid continuation byte
jan 01 15:17:41 fedora blueman.desktop[18728]: blueman-applet 15.17.41 WARNING  DiscvManager:119 update_menuitems: warning: Adapter is None
jan 01 15:17:41 fedora blueman.desktop[18728]: blueman-applet 15.17.41 WARNING  PowerManager:203 on_adapter_property_changed: adapter powered on while in off state, turning bluetooth on
jan 01 15:17:41 fedora abrt-server[19558]: Can't parse stacktrace: Line 3, column 78: Traceback header not found.
jan 01 15:17:41 fedora systemd[1]: Starting blueman-mechanism.service - Bluetooth management mechanism...
jan 01 15:17:41 fedora blueman-tray[19170]: gtk_widget_get_scale_factor: assertion 'GTK_IS_WIDGET (widget)' failed
jan 01 15:17:41 fedora systemd[1]: Started blueman-mechanism.service - Bluetooth management mechanism.
jan 01 15:17:41 fedora audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=blueman-mechanism comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
jan 01 15:17:41 fedora abrt-server[19558]: In format file '/etc/libreport/plugins/catalog_python3_format.conf':
jan 01 15:17:41 fedora abrt-server[19558]:         Undefined variable 'exception_type' outside [[ ]] brackets
jan 01 15:17:41 fedora abrt-server[19558]: Can't parse backtrace: Line 3, column 78: Traceback header not found.
jan 01 15:17:41 fedora abrt-notification[19601]: [🡕] Process 18728 (blueman-applet) of user 1000 encountered an uncaught  exception
jan 01 15:17:41 fedora blueman-tray[19170]: gtk_widget_get_scale_factor: assertion 'GTK_IS_WIDGET (widget)' failed
cschramm commented 9 months ago

I can only repeat what I already wrote: It's #1241 / #620. The application does not crash at all. It's a harmless exception from GLib code. Fedora's ABRT picks it up and lies to you. I assume that's somehow handleable by Fedora's maintainers in their blueman or ABRT packages. It should not happen in our main branch since #2009 changed the code in a way that should not trigger the GLib bug anymore.

engn33r commented 9 months ago

If the main branch has a fix, is there a plan to create a new release soon, so the changes from #2009 and other updates are more widely adopted?

cschramm commented 9 months ago

@engn33r: Sure, it will be contained in 2.4, but there is no schedule.

m0nkeyc0de commented 9 months ago

Thanks for the information and the work done @cschramm Once blueman 2.4 is released and available in Fedora repos, I'll watch the state of the issue and provide a feedback.

github-actions[bot] commented 7 months ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.