Bug 1929434

Summary: Bluetooth device disconnects & reconnects randomly
Product: [Fedora] Fedora Reporter: Dustin <d.nisbetjones>
Component: linux-firmwareAssignee: David Woodhouse <dwmw2>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 33CC: bnocera, christian-nils.boda, dwmw2, dzickus, guillaume, harzyto, jacob.majors, jakob, jforbes, josearod, jwboyer, kernel-maint, khowell, laura, mschmidt.mailbox, nweinber, pasik, pbrobinson, pmendezh, sejug, spacewar, stephenfin, tonyg, t_srv, yarnsphere
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Unspecified   
Whiteboard:
Fixed In Version: linux-firmware-20210511-120.fc34 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2021-05-14 17:50:17 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
journalctl capturing disconnect/reconnect of bluetooth devices none

Description Dustin 2021-02-16 21:49:18 UTC 
Description of problem: After a recent suite of updates, my Bluetooth headphones (Soundcore Life Q20) randomly disconnect and then reconnect. I don't see any active errors in the reporting program but in the logs I do see the following in the logs:

13:41:24 kernel: input: Soundcore Life Q20 (AVRCP) as /devices/virtual/input/input46

This is repeated every few minutes, presumably with the different disconnects?

How reproducible: I cannot actively reproduce this bug. It's random

This appears to be limited to my system with Fedora 33 only as I have tested the device with other systems
Comment 1 jakob 2021-02-17 12:50:47 UTC 
I am experiencing the same issue since a recent kernel update.

Kernel: 5.10.15-200.fc33.x86_64
bluez: 5.55-1.fc33

Here are the debug logs from a disconnect and reconnect
[...]
Feb 17 13:39:09 honestmistake bluetoothd[31536]: src/adapter.c:dev_disconnected() Device EC:AA:25:F3:1D:09 disconnected, reason 1
Feb 17 13:39:09 honestmistake bluetoothd[31536]: src/adapter.c:adapter_remove_connection()
Feb 17 13:39:09 honestmistake bluetoothd[31536]: plugins/policy.c:disconnect_cb() reason 1
Feb 17 13:39:09 honestmistake bluetoothd[31536]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr EC:AA:25:F3:1D:09 type 0 status 0xe
Feb 17 13:39:09 honestmistake bluetoothd[31536]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e
Feb 17 13:39:09 honestmistake bluetoothd[31536]: src/device.c:device_bonding_failed() status 14
Feb 17 13:39:09 honestmistake bluetoothd[31536]: src/adapter.c:resume_discovery()
Feb 17 13:39:09 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: STREAMING -> IDLE
Feb 17 13:39:09 honestmistake bluetoothd[31536]: profiles/audio/transport.c:media_transport_remove_owner() Transport /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep1/fd0 Owner :1.118
Feb 17 13:39:09 honestmistake bluetoothd[31536]: profiles/audio/transport.c:media_owner_free() Owner :1.118
Feb 17 13:39:09 honestmistake bluetoothd[31536]: profiles/audio/transport.c:transport_set_state() State changed /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep1/fd0: TRANSPORT_STATE_ACTIVE -> TRANSPORT_STATE_IDLE
Feb 17 13:39:09 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:a2dp_sep_unlock() SEP 0x561cd44d8640 unlocked
Feb 17 13:39:09 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_unref() 0x561cd44f66f0: ref=1
Feb 17 13:39:09 honestmistake bluetoothd[31536]: src/service.c:change_state() 0x561cd44ea0c0: device EC:AA:25:F3:1D:09 profile a2dp-sink state changed: connected -> disconnected (0)
Feb 17 13:39:09 honestmistake bluetoothd[31536]: plugins/policy.c:policy_disconnect() /org/bluez/hci0/dev_EC_AA_25_F3_1D_09 profile avrcp-controller
Feb 17 13:39:09 honestmistake bluetoothd[31536]: src/service.c:change_state() 0x561cd44ea620: device EC:AA:25:F3:1D:09 profile avrcp-controller state changed: connected -> disconnecting (0)
Feb 17 13:39:09 honestmistake bluetoothd[31536]: profiles/audio/avrcp.c:avrcp_disconnect() path /org/bluez/hci0/dev_EC_AA_25_F3_1D_09
Feb 17 13:39:09 honestmistake bluetoothd[31536]: src/service.c:change_state() 0x561cd44e16c0: device EC:AA:25:F3:1D:09 profile audio-avrcp-target state changed: connected -> disconnected (0)
Feb 17 13:39:09 honestmistake bluetoothd[31536]: src/service.c:change_state() 0x561cd44ea620: device EC:AA:25:F3:1D:09 profile avrcp-controller state changed: disconnecting -> disconnected (0)
Feb 17 13:39:09 honestmistake bluetoothd[31536]: profiles/audio/avrcp.c:controller_destroy() 0x561cd44f6f80
Feb 17 13:39:09 honestmistake bluetoothd[31536]: profiles/audio/avrcp.c:target_destroy() 0x561cd44d7100
Feb 17 13:39:09 honestmistake bluetoothd[31536]: profiles/audio/avctp.c:avctp_set_state() AVCTP Disconnected
Feb 17 13:39:09 honestmistake bluetoothd[31536]: profiles/audio/avctp.c:avctp_disconnected() AVCTP: closing uinput for EC:AA:25:F3:1D:09
Feb 17 13:39:10 honestmistake /usr/libexec/gdm-x-session[2944]: (II) config/udev: removing device Galaxy Buds (1D09) (AVRCP)
Feb 17 13:39:10 honestmistake /usr/libexec/gdm-x-session[2944]: (**) Option "fd" "148"
Feb 17 13:39:10 honestmistake /usr/libexec/gdm-x-session[2944]: (II) event24 - Galaxy Buds (1D09) (AVRCP): device removed
Feb 17 13:39:10 honestmistake /usr/libexec/gdm-x-session[2944]: (II) UnloadModule: "libinput"
Feb 17 13:39:10 honestmistake /usr/libexec/gdm-x-session[2944]: (II) systemd-logind: releasing fd for 13:88
Feb 17 13:39:10 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_unref() 0x561cd44f66f0: ref=0
Feb 17 13:39:10 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_ref() 0x561cd44f66f0: ref=1
Feb 17 13:39:10 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:set_disconnect_timer() timeout 0
Feb 17 13:39:10 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_ref() 0x561cd44f66f0: ref=2
Feb 17 13:39:10 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:connection_lost() Disconnected from EC:AA:25:F3:1D:09
Feb 17 13:39:10 honestmistake bluetoothd[31536]: profiles/audio/sink.c:sink_set_state() State changed /org/bluez/hci0/dev_EC_AA_25_F3_1D_09: SINK_STATE_PLAYING -> SINK_STATE_DISCONNECTED
Feb 17 13:39:10 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:channel_remove() chan 0x561cd44e9de0
Feb 17 13:39:10 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_unref() 0x561cd44f66f0: ref=1
Feb 17 13:39:10 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_unref() 0x561cd44f66f0: ref=0
Feb 17 13:39:10 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_free() 0x561cd44f66f0
Feb 17 13:39:10 honestmistake gsd-media-keys[3499]: Unable to get default sink
Feb 17 13:39:14 honestmistake bluetoothd[31536]: src/adapter.c:connected_callback() hci0 device EC:AA:25:F3:1D:09 connected eir_len 5
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:confirm_cb() AVDTP: incoming connect from EC:AA:25:F3:1D:09
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/sink.c:sink_set_state() State changed /org/bluez/hci0/dev_EC_AA_25_F3_1D_09: SINK_STATE_DISCONNECTED -> SINK_STATE_CONNECTING
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_connect_cb() AVDTP: connected signaling channel to EC:AA:25:F3:1D:09
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_connect_cb() AVDTP imtu=672, omtu=679
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_register_remote_sep() seid 1 type 1 media 0 delay_reporting true
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:register_remote_sep() Found remote SEP: /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep1
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_register_remote_sep() seid 2 type 1 media 0 delay_reporting true
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:register_remote_sep() Found remote SEP: /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep2
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_register_remote_sep() seid 3 type 1 media 0 delay_reporting true
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:register_remote_sep() Found remote SEP: /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep3
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_register_remote_sep() seid 4 type 1 media 0 delay_reporting true
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:register_remote_sep() Found remote SEP: /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep4
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_register_remote_sep() seid 5 type 1 media 0 delay_reporting true
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:register_remote_sep() Found remote SEP: /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep5
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_register_remote_sep() seid 6 type 1 media 0 delay_reporting true
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:register_remote_sep() Found remote SEP: /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep6
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_ref() 0x561cd44f66f0: ref=1
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:set_disconnect_timer() timeout 1
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avctp.c:avctp_confirm_cb() AVCTP: incoming connect from EC:AA:25:F3:1D:09
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avctp.c:avctp_set_state() AVCTP Connecting
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avctp.c:avctp_connect_cb() AVCTP: connected to EC:AA:25:F3:1D:09
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avctp.c:init_uinput() AVRCP: uinput initialized for Galaxy Buds (1D09)
Feb 17 13:39:14 honestmistake kernel: input: Galaxy Buds (1D09) (AVRCP) as /devices/virtual/input/input32
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avrcp.c:controller_init() 0x561cd44da270 version 0x0105
Feb 17 13:39:14 honestmistake bluetoothd[31536]: src/service.c:change_state() 0x561cd44e16c0: device EC:AA:25:F3:1D:09 profile audio-avrcp-target state changed: disconnected -> connected (0)
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avrcp.c:target_init() 0x561cd44e8e50 version 0x0105
Feb 17 13:39:14 honestmistake bluetoothd[31536]: src/service.c:change_state() 0x561cd44ea620: device EC:AA:25:F3:1D:09 profile avrcp-controller state changed: disconnected -> connected (0)
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avctp.c:avctp_set_state() AVCTP Connected
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avrcp.c:handle_vendordep_pdu() AVRCP PDU 0x10, company 0x001958 len 0x0001
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avrcp.c:avrcp_handle_get_capabilities() id=3
Feb 17 13:39:14 honestmistake bluetoothd[31536]: profiles/audio/avrcp.c:handle_vendordep_pdu() AVRCP PDU 0x31, company 0x001958 len 0x0005
Feb 17 13:39:14 honestmistake systemd-logind[1082]: Watching system buttons on /dev/input/event24 (Galaxy Buds (1D09) (AVRCP))
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (II) config/udev: Adding input device Galaxy Buds (1D09) (AVRCP) (/dev/input/event24)
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (**) Galaxy Buds (1D09) (AVRCP): Applying InputClass "evdev keyboard catchall"
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (**) Galaxy Buds (1D09) (AVRCP): Applying InputClass "libinput keyboard catchall"
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (**) Galaxy Buds (1D09) (AVRCP): Applying InputClass "system-keyboard"
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (II) Using input driver 'libinput' for 'Galaxy Buds (1D09) (AVRCP)'
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (II) systemd-logind: got fd for /dev/input/event24 13:88 fd 137 paused 0
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (**) Galaxy Buds (1D09) (AVRCP): always reports core events
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (**) Option "Device" "/dev/input/event24"
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (**) Option "_source" "server/udev"
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (II) event24 - Galaxy Buds (1D09) (AVRCP): is tagged by udev as: Keyboard
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (II) event24 - Galaxy Buds (1D09) (AVRCP): device is a keyboard
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (II) event24 - Galaxy Buds (1D09) (AVRCP): device removed
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (**) Option "config_info" "udev:/sys/devices/virtual/input/input32/event24"
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (II) XINPUT: Adding extended input device "Galaxy Buds (1D09) (AVRCP)" (type: KEYBOARD, id 25)
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (**) Option "xkb_layout" "gb,de"
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (**) Option "xkb_variant" ","
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (II) event24 - Galaxy Buds (1D09) (AVRCP): device is a keyboard
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (II) event24 - Galaxy Buds (1D09) (AVRCP): device removed
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (**) Option "config_info" "udev:/sys/devices/virtual/input/input32/event24"
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (II) XINPUT: Adding extended input device "Galaxy Buds (1D09) (AVRCP)" (type: KEYBOARD, id 25)
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (**) Option "xkb_layout" "gb,de"
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (**) Option "xkb_variant" ","
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (II) event24 - Galaxy Buds (1D09) (AVRCP): is tagged by udev as: Keyboard
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[2944]: (II) event24 - Galaxy Buds (1D09) (AVRCP): device is a keyboard
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[36486]: The XKEYBOARD keymap compiler (xkbcomp) reports:
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[36486]: > Internal error:   Could not resolve keysym XF86FullScreen
Feb 17 13:39:14 honestmistake /usr/libexec/gdm-x-session[36486]: Errors from xkbcomp are not fatal to the X server
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_ref() 0x561cd44f66f0: ref=2
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_ref() 0x561cd44f66f0: ref=3
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setup_ref() 0x561cd44db800: ref=1
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_unref() 0x561cd44f66f0: ref=2
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:discover_cb() version 0x0103 err (nil)
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/sink.c:discovery_complete() Discovery complete
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setup_ref() 0x561cd44db800: ref=2
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setup_ref() 0x561cd44db800: ref=3
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/media.c:media_endpoint_async_call() Calling SelectConfiguration: name = :1.118 path = /MediaEndpoint/A2DPSource/sbc
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setup_unref() 0x561cd44db800: ref=2
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:a2dp_config() a2dp_config: selected SEP 0x561cd44d8640
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setup_ref() 0x561cd44db800: ref=3
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_set_configuration() 0x561cd44f66f0: int_seid=2, acp_seid=1
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setup_unref() 0x561cd44db800: ref=2
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setup_unref() 0x561cd44db800: ref=1
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:session_cb()
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_parse_resp() SET_CONFIGURATION request succeeded
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setconf_cfm() Source 0x561cd44d8640: Set_Configuration_Cfm
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setup_ref() 0x561cd44db800: ref=2
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/media.c:media_endpoint_async_call() Calling SetConfiguration: name = :1.118 path = /MediaEndpoint/A2DPSource/sbc
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: IDLE -> CONFIGURED
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setup_unref() 0x561cd44db800: ref=1
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:session_cb()
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_parse_resp() OPEN request succeeded
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_connect_cb() AVDTP: connected transport channel to EC:AA:25:F3:1D:09
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:handle_transport_connect() Flushable packets enabled
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:handle_transport_connect() sk 48, omtu 679, send buffer size 106496
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:open_cfm() Source 0x561cd44d8640: Open_Cfm
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setup_unref() 0x561cd44db800: ref=0
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setup_free() 0x561cd44db800
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_unref() 0x561cd44f66f0: ref=1
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: CONFIGURED -> OPEN
Feb 17 13:39:15 honestmistake bluetoothd[31536]: src/service.c:change_state() 0x561cd44ea0c0: device EC:AA:25:F3:1D:09 profile a2dp-sink state changed: disconnected -> connected (0)
Feb 17 13:39:15 honestmistake bluetoothd[31536]: plugins/policy.c:service_cb() Added a2dp-sink reconnect 0
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/sink.c:sink_set_state() State changed /org/bluez/hci0/dev_EC_AA_25_F3_1D_09: SINK_STATE_CONNECTING -> SINK_STATE_CONNECTED
Feb 17 13:39:15 honestmistake bluetoothd[31536]: profiles/audio/transport.c:transport_update_playing() /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep1/fd1 State=TRANSPORT_STATE_IDLE Playing=0
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/transport.c:media_owner_create() Owner created: sender=:1.118
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_ref() 0x561cd44f66f0: ref=2
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:a2dp_sep_lock() SEP 0x561cd44d8640 locked
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_ref() 0x561cd44f66f0: ref=3
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setup_ref() 0x561cd4516500: ref=1
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/transport.c:transport_set_state() State changed /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep1/fd1: TRANSPORT_STATE_IDLE -> TRANSPORT_STATE_REQUESTING
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/transport.c:media_request_create() Request created: method=Acquire id=8
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/transport.c:media_owner_add() Owner :1.118 Request Acquire
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/transport.c:media_transport_set_owner() Transport /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep1/fd1 Owner :1.118
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:session_cb()
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_parse_resp() START request succeeded
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:start_cfm() Source 0x561cd44d8640: Start_Cfm
Feb 17 13:39:18 honestmistake bluetoothd[31536]: /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep1/fd1: fd(48) ready
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/transport.c:media_owner_remove() Owner :1.118 Request Acquire
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/transport.c:transport_set_state() State changed /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep1/fd1: TRANSPORT_STATE_REQUESTING -> TRANSPORT_STATE_ACTIVE
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setup_unref() 0x561cd4516500: ref=0
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/a2dp.c:setup_free() 0x561cd4516500
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_unref() 0x561cd44f66f0: ref=2
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/avdtp.c:avdtp_sep_set_state() stream state changed: OPEN -> STREAMING
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/sink.c:sink_set_state() State changed /org/bluez/hci0/dev_EC_AA_25_F3_1D_09: SINK_STATE_CONNECTED -> SINK_STATE_PLAYING
Feb 17 13:39:18 honestmistake bluetoothd[31536]: profiles/audio/transport.c:transport_update_playing() /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep1/fd1 State=TRANSPORT_STATE_ACTIVE Playing=1
Feb 17 13:39:18 honestmistake rtkit-daemon[914]: Supervising 13 threads of 8 processes of 1 users.
Feb 17 13:39:18 honestmistake rtkit-daemon[914]: Successfully made thread 36501 of process 3260 (/usr/bin/pulseaudio) owned by '1000' RT at priority 5.
Feb 17 13:39:18 honestmistake rtkit-daemon[914]: Supervising 14 threads of 8 processes of 1 users.
[...]
Comment 2 Peter Robinson 2021-02-27 22:14:27 UTC 
You don't mention the bluetooth host controller. Please provide the details of that and "rpm -q linux-firmware"
Comment 3 Dustin 2021-02-27 22:50:18 UTC 
Output from bluetoothctl list:
Controller B8:9A:2A:BB:B3:67 Swift 3 [default]

linux-firmware-20210208-117.fc33.noarch
Comment 4 Peter Robinson 2021-02-28 09:17:46 UTC 
> Output from bluetoothctl list:
> Controller B8:9A:2A:BB:B3:67 Swift 3 [default]

Can you give the matching output from lsusb?
Comment 5 Dustin 2021-02-28 15:14:55 UTC 
Bus 001 Device 004: ID 8087:0029 Intel Corp. AX200 Bluetooth
Comment 6 Dustin 2021-03-01 04:33:54 UTC 
It's still early to say for certain but it appears that the updates pushed out today fixed the issue. I saw an update to Bluez included in that so perhaps it's all sorted. I will update this again in 24 hours.
Comment 7 jakob 2021-03-01 10:46:10 UTC 
bluetooth controller: ID 8087:0029 Intel Corp. AX200 Bluetooth
firmware: linux-firmware-20210208-117.fc33.noarch


I just upgraded bluez to 5.56 and now seem to have a new failure mode. Bluetooth disconnects randomly and is unable to reconnect, but keeps trying. Manually disconnecting and reconnecting fixes it.

[...]
Mar 01 11:00:50 honestmistake bluetoothd[904]: /org/bluez/hci0/dev_EC_AA_25_F3_1D_09/sep1/fd0: fd(40) ready
Mar 01 11:36:31 honestmistake bluetoothd[904]: profiles/audio/avdtp.c:avdtp_connect_cb() connect to EC:AA:25:F3:1D:09: Operation already in progress (114)
Mar 01 11:36:33 honestmistake bluetoothd[904]: src/service.c:btd_service_connect() a2dp-sink profile connect failed for EC:AA:25:F3:1D:09: Device or resource busy
Mar 01 11:36:33 honestmistake bluetoothd[904]: plugins/policy.c:reconnect_timeout() Reconnecting services failed: Device or resource busy (16)
Mar 01 11:36:34 honestmistake bluetoothd[904]: profiles/audio/a2dp.c:a2dp_select_capabilities() Unable to select SEP
Mar 01 11:36:46 honestmistake bluetoothd[904]: profiles/audio/a2dp.c:a2dp_select_capabilities() Unable to select SEP
Mar 01 11:37:01 honestmistake bluetoothd[904]: profiles/audio/a2dp.c:a2dp_select_capabilities() Unable to select SEP
Mar 01 11:37:16 honestmistake bluetoothd[904]: profiles/audio/a2dp.c:a2dp_select_capabilities() Unable to select SEP
Mar 01 11:37:31 honestmistake bluetoothd[904]: profiles/audio/a2dp.c:a2dp_select_capabilities() Unable to select SEP
Mar 01 11:37:46 honestmistake bluetoothd[904]: profiles/audio/a2dp.c:a2dp_select_capabilities() Unable to select SEP
Mar 01 11:38:01 honestmistake bluetoothd[904]: profiles/audio/a2dp.c:a2dp_select_capabilities() Unable to select SEP
Mar 01 11:38:16 honestmistake bluetoothd[904]: profiles/audio/a2dp.c:a2dp_select_capabilities() Unable to select SEP
Mar 01 11:38:31 honestmistake bluetoothd[904]: profiles/audio/a2dp.c:a2dp_select_capabilities() Unable to select SEP
Mar 01 11:38:46 honestmistake bluetoothd[904]: profiles/audio/a2dp.c:a2dp_select_capabilities() Unable to select SEP
Mar 01 11:39:01 honestmistake bluetoothd[904]: profiles/audio/a2dp.c:a2dp_select_capabilities() Unable to select SEP
Mar 01 11:39:16 honestmistake bluetoothd[904]: profiles/audio/a2dp.c:a2dp_select_capabilities() Unable to select SEP
[...]
Comment 8 jakob 2021-03-01 14:40:49 UTC 
Here is the same thing happening with debug logging turned on https://pastebin.com/raw/3pQm5d3v

The only thing needed to solve this state is "bluetoothctl connect <device>"
Comment 9 Dustin 2021-03-02 02:00:24 UTC 
I can report that after 24 hours or so the problem DOES persist but is much more infrequent. I've had one disconnect all this time since the update compared to many times an hour.
Comment 10 jacob.majors 2021-03-09 05:38:50 UTC 
Created attachment 1761909 [details]
journalctl capturing disconnect/reconnect of bluetooth devices
Comment 11 jacob.majors 2021-03-09 05:39:16 UTC 
(In reply to jacob.majors from comment #10)
> Created attachment 1761909 [details]
> journalctl capturing disconnect/reconnect of bluetooth devices

I am seeing similar issues with bluetooth devices disconnecting and seeming to lag on reconnect. I just updated this evening after finding this bug, and it seemed improved (less frequent), but when reading an article for a couple minutes and not using either device I noticed both were unresponsive; mouse cursor was frozen on the screen.

linux-firmware-20210208-117.fc33.noarch
Bus 001 Device 006: ID 0a5c:21e8 Broadcom Corp. BCM20702A0 Bluetooth 4.0
bluez.x86_64  5.56-1.fc33
Comment 12 Dustin 2021-03-11 04:26:50 UTC 
(In reply to Dustin from comment #9)
> I can report that after 24 hours or so the problem DOES persist but is much
> more infrequent. I've had one disconnect all this time since the update
> compared to many times an hour.

After a set of updates today the problem has become much more frequent again for what it's worth.
Comment 13 Peter Robinson 2021-03-11 08:17:15 UTC 
> After a set of updates today the problem has become much more frequent again
> for what it's worth.

What updates changed, and from what version to what version? bluez/kernel/linux-firmware?
Comment 14 Dustin 2021-03-11 15:52:19 UTC 
I believe the only applicable changes were to the kernel, which is now 5.10.21. Bluez and Linux Firmware remain the same
Comment 15 jakob 2021-03-25 22:18:51 UTC 
Can I do anything to help debug this?
Comment 16 christian-nils 2021-03-28 20:53:01 UTC 
Hi,

I have a similar issue since 2021-03-02. My Sony WH-1000XM3 worked perfectly in A2DP mode. After that date, I started to have frequent disconnections daily. I have upgraded to Fedora 34 two days ago, I still have the same random disconnections.

When in HSP profile, I never experience the issue.

The following packages were updated/installed

on 2021-03-01:
- bluez 5.55 -> 5.56
- kernel-5.10.18

on 2021-03-02:
- kernel-5.10.19

Checking my journal log, it seems that I was running on the kernel 5.10.18 when the first disconnections happen (bluez was 5.56).

Can I help anyhow to solve this issue?

Thanks!
Comment 17 christian-nils 2021-03-28 21:21:37 UTC 
To add to my comment #16, my current configuration:

bluetooth controller: ID 8087:0029 Intel Corp. AX200 Bluetooth
linux-firmware: linux-firmware-20210315-119.fc34.noarch
bluez.x86_64: 5.56.4.fc34
kernel: 5.11.10-300.fc34.x86_64
Comment 18 Marco Schmidt 2021-04-05 14:20:19 UTC 
Hi all,

it seems to me the guys from Intel need to fix their firmware. I've experienced the same random disconnects while streaming audio (starting 6-8 weeks ago). I'm almost sure it is connected to the linux-firmware update on 2021-02-08 for Intel AX200/201/210 devices. 
I'm also on F34 now with updates-testing enabled, using a recent Intel NUC box with AX201 wireless chipset. I removed the linux-firmware package and manually copied the older firmware from december (https://git.kernel.org/pub/scm/linux/kernel/git/firmware/linux-firmware.git) to /lib/firmware/Intel. 
Problem "solved". Intel CS is aware of the problem but wanted me to test the situation on Windows... 

Prior to that I enabled debugging of bluetoothd - the only additional info I could get was that the device randomly ran into a timeout and disconnected. But you acn see that also in the first post (discon with "reason 1" -> timeout). I've found other users with the same problem - see https://bbs.archlinux.org/viewtopic.php?id=263040&p=3 Most of them also reverted their firmware, some say it's solved completely, some say it's only much less frequent. 

Regards
Comment 19 Raphael 2021-04-15 07:43:56 UTC 
(In reply to Marco Schmidt from comment #18)
> Hi all,
> 
> it seems to me the guys from Intel need to fix their firmware. I've
> experienced the same random disconnects while streaming audio (starting 6-8
> weeks ago). I'm almost sure it is connected to the linux-firmware update on
> 2021-02-08 for Intel AX200/201/210 devices. 
> I'm also on F34 now with updates-testing enabled, using a recent Intel NUC
> box with AX201 wireless chipset. I removed the linux-firmware package and
> manually copied the older firmware from december
> (https://git.kernel.org/pub/scm/linux/kernel/git/firmware/linux-firmware.
> git) to /lib/firmware/Intel. 
> Problem "solved". Intel CS is aware of the problem but wanted me to test the
> situation on Windows... 
> 
> Prior to that I enabled debugging of bluetoothd - the only additional info I
> could get was that the device randomly ran into a timeout and disconnected.
> But you acn see that also in the first post (discon with "reason 1" ->
> timeout). I've found other users with the same problem - see
> https://bbs.archlinux.org/viewtopic.php?id=263040&p=3 Most of them also
> reverted their firmware, some say it's solved completely, some say it's only
> much less frequent. 
> 
> Regards

Thank you Marco. Are you in touch with Intel on this? What is the progress? Is there any place where this can be tracked? This has been going on for months now and is getting more and more frustrating (esp. in a world of video conferencing).

There is another very active discussion on the pipewire repo discussing exactly this issue: https://gitlab.freedesktop.org/pipewire/pipewire/-/issues/732
One of them issued a kernel bug report (and included a btmon log): https://bugzilla.kernel.org/show_bug.cgi?id=212387

I have the feeling that all this effort should be more concentrated as this affects a lot of users on a lot of different distros.
Comment 20 Marco Schmidt 2021-04-15 19:04:21 UTC 
(In reply to Raphael from comment #19)
> Thank you Marco. Are you in touch with Intel on this? What is the progress?
> Is there any place where this can be tracked? This has been going on for
> months now and is getting more and more frustrating (esp. in a world of
> video conferencing).
> 
> There is another very active discussion on the pipewire repo discussing
> exactly this issue:
> https://gitlab.freedesktop.org/pipewire/pipewire/-/issues/732
> One of them issued a kernel bug report (and included a btmon log):
> https://bugzilla.kernel.org/show_bug.cgi?id=212387
> 
> I have the feeling that all this effort should be more concentrated as this
> affects a lot of users on a lot of different distros.

Hi Raphael, thanks for providing those links. I was already aware of the latter, the log is pretty much identical to the first post - connection timeout out of nowhere. Pulseaudio and pipewire error messages seem to be mere symptoms to that.
Someone in the pipewire thread linked to identical issues in pulseaudio - see here https://gitlab.freedesktop.org/pulseaudio/pulseaudio/-/issues/1155
And the most recent comments there indicate a new firmware update (only for AX201 devices) - https://lore.kernel.org/linux-firmware/20210409132204.31191-1-kiran.k@intel.com/
I'm still fine on the 20201218 fw version at the moment.

There's also a lot going on on the linux-bluetooth mailing list https://marc.info/?l=linux-bluetooth&r=1&b=202104&w=2 There are a lot of Intel devs involved, so I guess it's just a matter of time until this is properly solved. They really should have enough information to reproduce this internally but they don't provide change logs ;-)
Comment 21 Raphael 2021-04-17 17:35:09 UTC 
(In reply to Marco Schmidt from comment #20)
> (In reply to Raphael from comment #19)
> > Thank you Marco. Are you in touch with Intel on this? What is the progress?
> > Is there any place where this can be tracked? This has been going on for
> > months now and is getting more and more frustrating (esp. in a world of
> > video conferencing).
> > 
> > There is another very active discussion on the pipewire repo discussing
> > exactly this issue:
> > https://gitlab.freedesktop.org/pipewire/pipewire/-/issues/732
> > One of them issued a kernel bug report (and included a btmon log):
> > https://bugzilla.kernel.org/show_bug.cgi?id=212387
> > 
> > I have the feeling that all this effort should be more concentrated as this
> > affects a lot of users on a lot of different distros.
> 
> Hi Raphael, thanks for providing those links. I was already aware of the
> latter, the log is pretty much identical to the first post - connection
> timeout out of nowhere. Pulseaudio and pipewire error messages seem to be
> mere symptoms to that.
> Someone in the pipewire thread linked to identical issues in pulseaudio -
> see here https://gitlab.freedesktop.org/pulseaudio/pulseaudio/-/issues/1155
> And the most recent comments there indicate a new firmware update (only for
> AX201 devices) -
> https://lore.kernel.org/linux-firmware/20210409132204.31191-1-kiran.k@intel.
> com/
> I'm still fine on the 20201218 fw version at the moment.
> 
> There's also a lot going on on the linux-bluetooth mailing list
> https://marc.info/?l=linux-bluetooth&r=1&b=202104&w=2 There are a lot of
> Intel devs involved, so I guess it's just a matter of time until this is
> properly solved. They really should have enough information to reproduce
> this internally but they don't provide change logs ;-)

Thank you, it is good to know that somewhere someone is working on a solution. Hopefully it will be resolved soon.
Comment 22 Marco Schmidt 2021-04-20 20:41:53 UTC 
It seems the issues are fixed with the latest firmware :)  2nd day without interruptions with this one: https://git.kernel.org/pub/scm/linux/kernel/git/firmware/linux-firmware.git/commit/?id=73144e02dcff54529ab42d951de682740d204180
Only for AX201 devices at the moment.
Comment 23 Nathan Weinberg 2021-04-21 03:32:27 UTC 
Seeing the same issue also with Soundcore Life Q20s

Kernel: 5.11.14-200.fc33.x86_64
Firmware Version: linux-firmware-20210315-119.fc33.noarch
Comment 24 Raphael 2021-04-21 11:11:56 UTC 
(In reply to Marco Schmidt from comment #22)
> It seems the issues are fixed with the latest firmware :)  2nd day without
> interruptions with this one:
> https://git.kernel.org/pub/scm/linux/kernel/git/firmware/linux-firmware.git/
> commit/?id=73144e02dcff54529ab42d951de682740d204180
> Only for AX201 devices at the moment.

Good news, I hope AX200 follows and a release is on the horizon. I am still doubtful though.
Comment 25 Peter Robinson 2021-05-12 16:55:25 UTC 
*** Bug 1959825 has been marked as a duplicate of this bug. ***
Comment 26 Fedora Update System 2021-05-12 19:32:09 UTC 
FEDORA-2021-93247f3274 has been submitted as an update to Fedora 34. https://bodhi.fedoraproject.org/updates/FEDORA-2021-93247f3274
Comment 27 Fedora Update System 2021-05-13 02:15:43 UTC 
FEDORA-2021-93247f3274 has been pushed to the Fedora 34 testing repository.
Soon you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2021-93247f3274`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2021-93247f3274

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.
Comment 28 Fedora Update System 2021-05-14 17:50:17 UTC 
FEDORA-2021-93247f3274 has been pushed to the Fedora 34 stable repository.
If problem still persists, please make note of it in this bug report.
Comment 29 Dustin 2021-05-14 21:58:29 UTC 
Fixed! Thank you to everyone
Comment 30 Dimitar 2022-10-30 12:28:53 UTC 
I still have this issue on:
- Fedora 36 with Gnome
- Linux 5.19.16-200.fc36.x86_64
- CPU: 11th Gen Intel® Core™ i5-1135G7 × 8
- Device: realme buds air 2
- I think I am running with pipewire
- bluez 5.65

Logs from `journalctl | grep -i “blue*” `:
```
окт 30 14:10:41 fedora bluetoothd[782]: profiles/audio/avdtp.c:cancel_request() Suspend: Connection timed out (110)
окт 30 14:10:42 fedora bluetoothd[782]: profiles/audio/avdtp.c:handle_unanswered_req() No reply to Suspend request
окт 30 14:10:42 fedora bluetoothd[782]: src/profile.c:ext_io_disconnected() Unable to get io data for Hands-Free Voice gateway: getpeername: Transport endpoint is not connected (107)
окт 30 14:10:44 fedora bluetoothd[782]: plugins/policy.c:reconnect_timeout() Reconnecting services failed: Operation already in progress (114)
```