Hello,
I followed the instructions at
https://wiki.ubuntu.com/DebuggingBluetooth#On_Ubuntu_Desktop and was able to capture verbose logging for both pulseaudio and Bluetooth. When my device disconnects I see corresponding errors like "bluetoothd: Abort: Connection timed out (110)" but I don't know what to do about it. If anyone has any ideas, I'll appreciate the help. I'll reiterate that these earbuds worked fine on my previous PC with the same USB Bluetooth adapter and an older Debian (8 or 9, don't remember which). So I don't think it's the hardware.
This is the btmon trace captured while my earbuds were connected but acting wonky (Gnome speaker test caused the desktop to freeze up for several seconds and then no sound was played). After a few attempts running the speaker test, the device abruptly disconnected.
< HCI Command: LE Set Scan Enable (0x08|0x000c) plen 2 #1668 [hci0] 145.606613
Scanning: Disabled (0x00)
Filter duplicates: Disabled (0x00)
> HCI Event: Command Complete (0x0e) plen 4 #1669 [hci0] 145.608746
LE Set Scan Enable (0x08|0x000c) ncmd 1
Status: Success (0x00)
< HCI Command: Inquiry (0x01|0x0001) plen 5 #1670 [hci0] 145.608928
Access code: 0x9e8b33 (General Inquiry)
Length: 5.12s (0x04)
Num responses: 0
> HCI Event: Command Status (0x0f) plen 4 #1671 [hci0] 145.609745
Inquiry (0x01|0x0001) ncmd 1
Status: Success (0x00)
= bluetoothd: Suspend: Connection timed out (110) 149.464773
< HCI Command: Read Clock Offset (0x01|0x001f) plen 2 #1672 [hci0] 149.464997
Handle: 11
> HCI Event: Command Status (0x0f) plen 4 #1673 [hci0] 149.465710
Read Clock Offset (0x01|0x001f) ncmd 1
Status: Success (0x00)
< HCI Command: Disconnect (0x01|0x0006) plen 3 #1674 [hci0] 149.465774
Handle: 11
Reason: Remote User Terminated Connection (0x13)
> HCI Event: Command Status (0x0f) plen 4 #1675 [hci0] 149.467708
Disconnect (0x01|0x0006) ncmd 1
Status: Success (0x00)
> HCI Event: Inquiry Complete (0x01) plen 1 #1676 [hci0] 150.732751
Status: Success (0x00)
@ MGMT Event: Discovering (0x0013) plen 2 {0x0002} [hci0] 150.732829
Address type: 0x07
BR/EDR
LE Public
LE Random
Discovery: Disabled (0x00)
@ MGMT Event: Discovering (0x0013) plen 2 {0x0001} [hci0] 150.732829
Address type: 0x07
BR/EDR
LE Public
LE Random
Discovery: Disabled (0x00)
= bluetoothd: Abort: Connection timed out (110)
--------------------------------------
Below is the syslog and corresponding btmon trace captured while the earbuds were trusted and paired, but I was unable to get them connected using bluetoothctl. In the btmon trace, I see errors like "Remote User Terminated Connection (0x13)" and "Connection terminated by remote host (0x03)" but I do not know what is causing them.
Oct 2 11:25:45 debian bluetoothd[2924]: src/device.c:connect_profiles() /org/bluez/hci0/dev_9B_1F_48_B8_55_F6 (all), client :1.719
Oct 2 11:25:45 debian bluetoothd[2924]: src/device.c:connect_profiles() Resolving services for /org/bluez/hci0/dev_9B_1F_48_B8_55_F6
Oct 2 11:25:47 debian bluetoothd[2924]: src/adapter.c:connected_callback() hci0 device 9B:1F:48:B8:55:F6 connected eir_len 12
Oct 2 11:25:47 debian pulseaudio[1381]: (3949.171| 46.364) D: [pulseaudio] bluez5-util.c: Properties changed in device /org/bluez/hci0/dev_9B_1F_48_B8_55_F6
Oct 2 11:25:53 debian bluetoothd[2924]: src/adapter.c:dev_disconnected() Device 9B:1F:48:B8:55:F6 disconnected, reason 3
Oct 2 11:25:53 debian bluetoothd[2924]: src/adapter.c:adapter_remove_connection()
Oct 2 11:25:53 debian bluetoothd[2924]: plugins/policy.c:disconnect_cb() reason 3
Oct 2 11:25:53 debian bluetoothd[2924]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 9B:1F:48:B8:55:F6 type 0 status 0xe
Oct 2 11:25:53 debian bluetoothd[2924]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e
Oct 2 11:25:53 debian bluetoothd[2924]: src/device.c:device_bonding_failed() status 14
Oct 2 11:25:53 debian bluetoothd[2924]: src/adapter.c:resume_discovery()
Oct 2 11:25:54 debian pulseaudio[1381]: (3955.310| 6.138) D: [pulseaudio] bluez5-util.c: Properties changed in device /org/bluez/hci0/dev_9B_1F_48_B8_55_F6
Oct 2 11:25:56 debian bluetoothd[2924]: src/adapter.c:connected_callback() hci0 device 9B:1F:48:B8:55:F6 connected eir_len 12
Oct 2 11:25:56 debian pulseaudio[1381]: (3958.007| 2.697) D: [pulseaudio] bluez5-util.c: Properties changed in device /org/bluez/hci0/dev_9B_1F_48_B8_55_F6
Oct 2 11:26:02 debian bluetoothd[2924]: src/adapter.c:dev_disconnected() Device 9B:1F:48:B8:55:F6 disconnected, reason 3
Oct 2 11:26:02 debian bluetoothd[2924]: src/adapter.c:adapter_remove_connection()
Oct 2 11:26:02 debian pulseaudio[1381]: (3964.113| 6.105) D: [pulseaudio] bluez5-util.c: Properties changed in device /org/bluez/hci0/dev_9B_1F_48_B8_55_F6
Oct 2 11:26:02 debian bluetoothd[2924]: plugins/policy.c:disconnect_cb() reason 3
Oct 2 11:26:02 debian bluetoothd[2924]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 9B:1F:48:B8:55:F6 type 0 status 0xe
Oct 2 11:26:02 debian bluetoothd[2924]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e
Oct 2 11:26:02 debian bluetoothd[2924]: src/device.c:device_bonding_failed() status 14
Oct 2 11:26:02 debian bluetoothd[2924]: src/adapter.c:resume_discovery()
Oct 2 11:26:02 debian bluetoothd[2924]: 9B:1F:48:B8:55:F6: error updating services: Connection reset by peer (104)
Oct 2 11:26:02 debian bluetoothd[2924]: src/device.c:device_svc_resolved() /org/bluez/hci0/dev_9B_1F_48_B8_55_F6 err -104
< HCI Command:... (0x01|0x0005) plen 13 #643 [hci0] 2019-10-02 11:25:45.221687
Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Packet type: 0xcc18
DM1 may be used
DH1 may be used
DM3 may be used
DH3 may be used
DM5 may be used
DH5 may be used
Page scan repetition mode: R2 (0x02)
Page scan mode: Mandatory (0x00)
Clock offset: 0x0000
Role switch: Allow slave (0x01)
> HCI Event: Command St.. (0x0f) plen 4 #644 [hci0] 2019-10-02 11:25:45.222905
Create Connection (0x01|0x0005) ncmd 1
Status: Success (0x00)
> HCI Event: Connect C.. (0x03) plen 11 #645 [hci0] 2019-10-02 11:25:47.837940
Status: Success (0x00)
Handle: 12
Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Link type: ACL (0x01)
Encryption: Disabled (0x00)
< HCI Command: R.. (0x01|0x001b) plen 2 #646 [hci0] 2019-10-02 11:25:47.838133
Handle: 12
> HCI Event: Command St.. (0x0f) plen 4 #647 [hci0] 2019-10-02 11:25:47.838932
Read Remote Supported Features (0x01|0x001b) ncmd 1
Status: Success (0x00)
< HCI Command: W.. (0x03|0x001a) plen 1 #648 [hci0] 2019-10-02 11:25:47.839005
Scan enable: No Scans (0x00)
> HCI Event: Command Co.. (0x0e) plen 4 #649 [hci0] 2019-10-02 11:25:47.839932
Write Scan Enable (0x03|0x001a) ncmd 1
Status: Success (0x00)
> HCI Event: Max Slots... (0x1b) plen 3 #650 [hci0] 2019-10-02 11:25:47.841934
Handle: 12
Max slots: 5
> HCI Event: Read Remo.. (0x0b) plen 11 #651 [hci0] 2019-10-02 11:25:47.853962
Status: Success (0x00)
Handle: 12
Features: 0xbf 0xfe 0x8d 0xfa 0x88 0x2d 0x79 0x83
3 slot packets
5 slot packets
Encryption
Slot offset
Timing accuracy
Role switch
Sniff mode
Power control requests
Channel quality driven data rate (CQDDR)
SCO link
HV2 packets
HV3 packets
u-law log synchronous data
A-law log synchronous data
CVSD synchronous data
Power control
Transparent synchronous data
Broadcast Encryption
Enhanced Data Rate ACL 2 Mbps mode
Enhanced inquiry scan
Interlaced inquiry scan
Interlaced page scan
RSSI with inquiry results
Extended SCO link (EV3 packets)
AFH capable slave
3-slot Enhanced Data Rate ACL packets
5-slot Enhanced Data Rate ACL packets
Pause encryption
AFH capable master
Enhanced Data Rate eSCO 2 Mbps mode
Extended Inquiry Response
Secure Simple Pairing
Encapsulated PDU
Erroneous Data Reporting
Non-flushable Packet Boundary Flag
Link Supervision Timeout Changed Event
Inquiry TX Power Level
Extended features
< HCI Command: R.. (0x01|0x001c) plen 3 #652 [hci0] 2019-10-02 11:25:47.853979
Handle: 12
Page: 1
> HCI Event: Command St.. (0x0f) plen 4 #653 [hci0] 2019-10-02 11:25:47.854914
Read Remote Extended Features (0x01|0x001c) ncmd 1
Status: Success (0x00)
> HCI Event: Read Remo.. (0x23) plen 13 #654 [hci0] 2019-10-02 11:25:47.859956
Status: Success (0x00)
Handle: 12
Page: 1/1
Features: 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00
Secure Simple Pairing (Host Support)
< HCI Command:... (0x01|0x0019) plen 10 #655 [hci0] 2019-10-02 11:25:47.860002
Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Page scan repetition mode: R2 (0x02)
Page scan mode: Mandatory (0x00)
Clock offset: 0x0000
< ACL Data TX: Han.. flags 0x00 dlen 10 #656 [hci0] 2019-10-02 11:25:47.860007
L2CAP: Information Request (0x0a) ident 1 len 2
Type: Extended features supported (0x0002)
> HCI Event: Command St.. (0x0f) plen 4 #657 [hci0] 2019-10-02 11:25:47.860893
Remote Name Request (0x01|0x0019) ncmd 1
Status: Success (0x00)
> HCI Event: Remote N.. (0x07) plen 255 #658 [hci0] 2019-10-02 11:25:47.881944
Status: Success (0x00)
Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Name: BT910
@ MGMT Event: De.. (0x000b) plen 25 {0x0002} [hci0] 2019-10-02 11:25:47.881960
BR/EDR Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Flags: 0x00000000
Data length: 12
Name (complete): BT910
Class: 0x240404
Major class: Audio/Video (headset, speaker, stereo, video, vcr)
Minor class: Wearable Headset Device
Rendering (Printing, Speaker)
Audio (Speaker, Microphone, Headset)
@ MGMT Event: De.. (0x000b) plen 25 {0x0001} [hci0] 2019-10-02 11:25:47.881960
BR/EDR Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Flags: 0x00000000
Data length: 12
Name (complete): BT910
Class: 0x240404
Major class: Audio/Video (headset, speaker, stereo, video, vcr)
Minor class: Wearable Headset Device
Rendering (Printing, Speaker)
Audio (Speaker, Microphone, Headset)
< ACL Data TX: Han.. flags 0x00 dlen 12 #659 [hci0] 2019-10-02 11:25:51.870582
L2CAP: Connection Request (0x02) ident 2 len 4
PSM: 1 (0x0001)
Source CID: 64
> HCI Event: Disconnect.. (0x05) plen 4 #660 [hci0] 2019-10-02 11:25:53.973940
Status: Success (0x00)
Handle: 12
Reason: Remote User Terminated Connection (0x13)
@ MGMT Event: Dev.. (0x000c) plen 8 {0x0002} [hci0] 2019-10-02 11:25:53.973979
BR/EDR Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Reason: Connection terminated by remote host (0x03)
@ MGMT Event: Dev.. (0x000c) plen 8 {0x0001} [hci0] 2019-10-02 11:25:53.973979
BR/EDR Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Reason: Connection terminated by remote host (0x03)
< HCI Command: W.. (0x03|0x001a) plen 1 #661 [hci0] 2019-10-02 11:25:54.022697
Scan enable: Page Scan (0x02)
> HCI Event: Command Co.. (0x0e) plen 4 #662 [hci0] 2019-10-02 11:25:54.023895
Write Scan Enable (0x03|0x001a) ncmd 1
Status: Success (0x00)
< HCI Command:... (0x01|0x0005) plen 13 #663 [hci0] 2019-10-02 11:25:54.023967
Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Packet type: 0xcc18
DM1 may be used
DH1 may be used
DM3 may be used
DH3 may be used
DM5 may be used
DH5 may be used
Page scan repetition mode: R2 (0x02)
Page scan mode: Mandatory (0x00)
Clock offset: 0x0000
Role switch: Allow slave (0x01)
> HCI Event: Command St.. (0x0f) plen 4 #664 [hci0] 2019-10-02 11:25:54.024891
Create Connection (0x01|0x0005) ncmd 1
Status: Success (0x00)
> HCI Event: Connect C.. (0x03) plen 11 #665 [hci0] 2019-10-02 11:25:56.672946
Status: Success (0x00)
Handle: 12
Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Link type: ACL (0x01)
Encryption: Disabled (0x00)
< HCI Command: R.. (0x01|0x001b) plen 2 #666 [hci0] 2019-10-02 11:25:56.673140
Handle: 12
> HCI Event: Command St.. (0x0f) plen 4 #667 [hci0] 2019-10-02 11:25:56.673897
Read Remote Supported Features (0x01|0x001b) ncmd 1
Status: Success (0x00)
< HCI Command: W.. (0x03|0x001a) plen 1 #668 [hci0] 2019-10-02 11:25:56.673970
Scan enable: No Scans (0x00)
> HCI Event: Command Co.. (0x0e) plen 4 #669 [hci0] 2019-10-02 11:25:56.674892
Write Scan Enable (0x03|0x001a) ncmd 1
Status: Success (0x00)
> HCI Event: Max Slots... (0x1b) plen 3 #670 [hci0] 2019-10-02 11:25:56.677930
Handle: 12
Max slots: 5
> HCI Event: Read Remo.. (0x0b) plen 11 #671 [hci0] 2019-10-02 11:25:56.688939
Status: Success (0x00)
Handle: 12
Features: 0xbf 0xfe 0x8d 0xfa 0x88 0x2d 0x79 0x83
3 slot packets
5 slot packets
Encryption
Slot offset
Timing accuracy
Role switch
Sniff mode
Power control requests
Channel quality driven data rate (CQDDR)
SCO link
HV2 packets
HV3 packets
u-law log synchronous data
A-law log synchronous data
CVSD synchronous data
Power control
Transparent synchronous data
Broadcast Encryption
Enhanced Data Rate ACL 2 Mbps mode
Enhanced inquiry scan
Interlaced inquiry scan
Interlaced page scan
RSSI with inquiry results
Extended SCO link (EV3 packets)
AFH capable slave
3-slot Enhanced Data Rate ACL packets
5-slot Enhanced Data Rate ACL packets
Pause encryption
AFH capable master
Enhanced Data Rate eSCO 2 Mbps mode
Extended Inquiry Response
Secure Simple Pairing
Encapsulated PDU
Erroneous Data Reporting
Non-flushable Packet Boundary Flag
Link Supervision Timeout Changed Event
Inquiry TX Power Level
Extended features
< HCI Command: R.. (0x01|0x001c) plen 3 #672 [hci0] 2019-10-02 11:25:56.688956
Handle: 12
Page: 1
> HCI Event: Command St.. (0x0f) plen 4 #673 [hci0] 2019-10-02 11:25:56.689923
Read Remote Extended Features (0x01|0x001c) ncmd 1
Status: Success (0x00)
> HCI Event: Read Remo.. (0x23) plen 13 #674 [hci0] 2019-10-02 11:25:56.694963
Status: Success (0x00)
Handle: 12
Page: 1/1
Features: 0x01 0x00 0x00 0x00 0x00 0x00 0x00 0x00
Secure Simple Pairing (Host Support)
< HCI Command:... (0x01|0x0019) plen 10 #675 [hci0] 2019-10-02 11:25:56.695006
Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Page scan repetition mode: R2 (0x02)
Page scan mode: Mandatory (0x00)
Clock offset: 0x0000
< ACL Data TX: Han.. flags 0x00 dlen 10 #676 [hci0] 2019-10-02 11:25:56.695011
L2CAP: Information Request (0x0a) ident 1 len 2
Type: Extended features supported (0x0002)
> HCI Event: Command St.. (0x0f) plen 4 #677 [hci0] 2019-10-02 11:25:56.695956
Remote Name Request (0x01|0x0019) ncmd 1
Status: Success (0x00)
> HCI Event: Remote N.. (0x07) plen 255 #678 [hci0] 2019-10-02 11:25:56.716936
Status: Success (0x00)
Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Name: BT910
@ MGMT Event: De.. (0x000b) plen 25 {0x0002} [hci0] 2019-10-02 11:25:56.716969
BR/EDR Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Flags: 0x00000000
Data length: 12
Name (complete): BT910
Class: 0x240404
Major class: Audio/Video (headset, speaker, stereo, video, vcr)
Minor class: Wearable Headset Device
Rendering (Printing, Speaker)
Audio (Speaker, Microphone, Headset)
@ MGMT Event: De.. (0x000b) plen 25 {0x0001} [hci0] 2019-10-02 11:25:56.716969
BR/EDR Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Flags: 0x00000000
Data length: 12
Name (complete): BT910
Class: 0x240404
Major class: Audio/Video (headset, speaker, stereo, video, vcr)
Minor class: Wearable Headset Device
Rendering (Printing, Speaker)
Audio (Speaker, Microphone, Headset)
< ACL Data TX: Han.. flags 0x00 dlen 12 #679 [hci0] 2019-10-02 11:26:00.830607
L2CAP: Connection Request (0x02) ident 2 len 4
PSM: 1 (0x0001)
Source CID: 64
> HCI Event: Disconnect.. (0x05) plen 4 #680 [hci0] 2019-10-02 11:26:02.824947
Status: Success (0x00)
Handle: 12
Reason: Remote User Terminated Connection (0x13)
@ MGMT Event: Dev.. (0x000c) plen 8 {0x0002} [hci0] 2019-10-02 11:26:02.824985
BR/EDR Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Reason: Connection terminated by remote host (0x03)
@ MGMT Event: Dev.. (0x000c) plen 8 {0x0001} [hci0] 2019-10-02 11:26:02.824985
BR/EDR Address: 9B:1F:48:B8:55:F6 (OUI 9B-1F-48)
Reason: Connection terminated by remote host (0x03)
= bluetoothd: 9B:1F:48:B8:55:F6: error updating... 2019-10-02 11:26:02.825623
< HCI Command: W.. (0x03|0x001a) plen 1 #681 [hci0] 2019-10-02 11:26:02.862646
Scan enable: Page Scan (0x02)
> HCI Event: Command Co.. (0x0e) plen 4 #682 [hci0] 2019-10-02 11:26:02.863930
Write Scan Enable (0x03|0x001a) ncmd 1
Status: Success (0x00)