bluetoothd: connect/disconnect - "AVRCP PDU parameters length don't match"

Bug #2051993 reported by ^rooker
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
bluez-btsco (Ubuntu)
New
Undecided
Unassigned

Bug Description

I'm trying to connect to a bluetooth speaker.

The device is found, I can pair and connect - the speaker even (literally) "says": 'connected', and /var/syslog confirms that. All looks great; pulseaudio switches to the new audio sink - then "connected: no".

/var/syslog also contains *a lot of messages* regarding that connection (will post separately).

UPDATE: After adding "auto_switch=false" to my pulseaudio where it auto-loads the "bluetooth-policy" module, then `sysctl restart bluetooth` and `pulseaudio -k`: and after some time I *could finally connect* to this (and other) bluetooth speaker devices that just would never stay connected, but reconnect or bail out all the time.

I have no idea what I have done to fix this.
Basically, I copy/pasted from: https://askubuntu.com/questions/1205749/how-permanently-remove-or-disable-hsp-hfp-bluetooth-profile

I don't know yet, if this is reboot safe.
I dare to try, before I haven't understood what happened here.

I'm grateful for any insights or tips to get this "fixed" upstream?
Thank you.

Here's what I've modified in `/etc/pulse/default.pa`:

```
### Automatically load driver modules for Bluetooth hardware
.ifexists module-bluetooth-policy.so
#ORG: load-module module-bluetooth-policy
load-module module-bluetooth-policy auto_switch=false
.endif
```

--
I'm running Xubuntu 20.04
bluez 5.53-0ubuntu3.7
pulseaudio 1:13.99.1-1ubuntu3.13

Tags: focal
Revision history for this message
^rooker (rooker) wrote :
Download full text (16.6 KiB)

Sorry for the noise, but this info may be useful?
(I've put my bluetoothd into debug verbosity)

Below are parts and the full copy of the /var/syslog part when trying to connect, then disconnecting.

The first part looks really good (IMO).
Then "something" happens - and *disconnected*.

# Highlights (summary):

```
SINK_STATE_DISCONNECTED -> SINK_STATE_CONNECTING
AVDTP: connected signaling channel to 40:EF:4C:C5:1B:6C
DISCOVER request succeeded
SET_CONFIGURATION request succeeded
TRANSPORT_STATE_REQUESTING -> TRANSPORT_STATE_ACTIVE
SINK_STATE_CONNECTED -> SINK_STATE_PLAYING
AVCTP Connected
```

**...followed immediately by:**

```
40:EF:4C:C5:1B:6C: No service update

bluetoothd[1000416]: profiles/audio/avrcp.c:handle_vendordep_pdu() AVRCP PDU 0x10, company 0x001958 len 0x0001
bluetoothd[1000416]: profiles/audio/avrcp.c:handle_vendordep_pdu() AVRCP PDU parameters length don't match
bluetoothd[1000416]: profiles/audio/avrcp.c:handle_vendordep_pdu() AVRCP PDU 0x30, company 0x001958 len 0x0000
```

**And then it all goes down:**

```
Device 40:EF:4C:C5:1B:6C disconnected, reason 0
STREAMING -> IDLE
TRANSPORT_STATE_ACTIVE -> TRANSPORT_STATE_IDLE
connected -> disconnected (0)
disconnecting -> disconnected (0)
AVCTP: closing uinput for 40:EF:4C:C5:1B:6C
acpid: input device has been disconnected, fd 26
SINK_STATE_PLAYING -> SINK_STATE_DISCONNECTED
```

Here's the full log:
=============================

```
Jan 29 19:31:13 silverstar bluetoothd[1000416]: src/device.c:connect_profiles() /org/bluez/hci0/dev_40_EF_4C_C5_1B_6C (all), client :1.291165
Jan 29 19:31:13 silverstar bluetoothd[1000416]: profiles/audio/a2dp.c:a2dp_sink_connect() path /org/bluez/hci0/dev_40_EF_4C_C5_1B_6C
Jan 29 19:31:13 silverstar bluetoothd[1000416]: profiles/audio/avdtp.c:avdtp_ref() 0x562e5c523e10: ref=1
Jan 29 19:31:13 silverstar bluetoothd[1000416]: profiles/audio/avdtp.c:avdtp_ref() 0x562e5c523e10: ref=2
Jan 29 19:31:13 silverstar bluetoothd[1000416]: profiles/audio/a2dp.c:setup_ref() 0x562e5c511f50: ref=1
Jan 29 19:31:13 silverstar bluetoothd[1000416]: profiles/audio/sink.c:sink_set_state() State changed /org/bluez/hci0/dev_40_EF_4C_C5_1B_6C: SINK_STATE_DISCONNECTED -> SINK_STATE_CONNECTING
Jan 29 19:31:13 silverstar bluetoothd[1000416]: profiles/audio/sink.c:sink_connect() stream creation in progress
Jan 29 19:31:13 silverstar bluetoothd[1000416]: src/service.c:change_state() 0x562e5c4ff310: device 40:EF:4C:C5:1B:6C profile a2dp-sink state changed: disconnected -> connecting (0)
Jan 29 19:31:14 silverstar bluetoothd[1000416]: src/adapter.c:connected_callback() hci0 device 40:EF:4C:C5:1B:6C connected eir_len 24
Jan 29 19:31:14 silverstar bluetoothd[1000416]: profiles/audio/avdtp.c:avdtp_connect_cb() AVDTP: connected signaling channel to 40:EF:4C:C5:1B:6C
Jan 29 19:31:14 silverstar bluetoothd[1000416]: profiles/audio/avdtp.c:avdtp_connect_cb() AVDTP imtu=672, omtu=672
Jan 29 19:31:14 silverstar bluetoothd[1000416]: profiles/audio/avdtp.c:avdtp_register_remote_sep() seid 1 type 1 media 0
Jan 29 19:31:14 silverstar bluetoothd[1000416]: profiles/audio/a2dp.c:register_remote_sep() Found remote SEP: /org/bluez/hci0/dev_40_EF_4C_C5_1B_6C/sep1
Jan 29 19:31:15 silverstar blue...

Revision history for this message
^rooker (rooker) wrote :

I found something!
Even with the above mentioned "patch", the connection-behavior was still behaving erratic.

> IT NEEDED MUSIC! :D

Seriously: I happened to have Clementine music player running - playing music *while connecting* to all of these (previously problematic) BT-speakers:

*all of them* work when I play music while connecting.
Awesome.

However: What is the problem with "empty/silent buffers"?

tags: added: focal
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.