Connecting Bluetooth audio devices (pulseaudio + bluez)

lance 2017-10-31 20:48:32 UTC #1

My team is trying to connect Bluetooth audio devices such as an AmazonBasics Bluetooth Speaker to an Ubuntu Core host. We have verified separately that the bluez snap and the pulseaudio snap work for us. However, the pulseaudio snap seems to be missing the required modules for working with Bluetooth audio devices.

We are seeing the same kind of error message as in this Stack Overflow thread:

The accepted solution there suggests that we should load the pulseaudio module module-bluetooth-discover, but this is not installed anywhere with the pulseaudio or bluez snaps. I would guess for Bluetooth audio to work, the pulseaudio snap first needs to incorporate these modules (module-bluetooth-discover.so, module-bluetooth-policy.so, module-bluez5-device.so, module-bluez5-discover.so).

Is this something that could be added to the pulseaudio snap? Thanks!

ogra 2017-11-01 10:18:41 UTC #2

$ ls /snap/pulseaudio/current/usr/lib/pulse-8.0/modules/*blue*
ls: cannot access '/snap/pulseaudio/current/usr/lib/pulse-8.0/modules/*blue*': No such file or directory
$ snap interfaces|grep pulse|grep blue
$

There is indeed neither any of the bluetooth modules nor is there any ability to connect pulse to the bluez service … we should definitely add this … (thanks a lot for reporting)

morphis 2017-11-01 10:21:52 UTC #3

We miss bluetooth support in the pulseaudio snap at the moment. The source for the pulseaudio snap is available on https://code.launchpad.net/~snappy-hwe-team/snappy-hwe-snaps/+git/pulseaudio/+ref/master

It would be great if you can help adding the necessary bits into the snap. We currently disable BlueZ support explicitly but enabling it here https://git.launchpad.net/~snappy-hwe-team/snappy-hwe-snaps/+git/pulseaudio/tree/snapcraft.yaml#n124 would be a good first step. If you install a pulse and a bluez snap in devmode you should be already able to do basic testing of this. Once that works we can do any further interface adjustments if needed.

ogra 2017-11-01 10:24:33 UTC #4

i guess only bluez5 though (as that is what the bluez snap contains)

morphis 2017-11-01 10:24:51 UTC #5

Correct. BlueZ 5.x support should be enough.

lance 2017-11-01 14:23:36 UTC #6

Thanks for the suggestions. I am looking into that now. I found that the BlueZ support also depends on D-Bus. Perhaps we will also need to change the bluez snap to add a dbus interface.

morphis 2017-11-01 15:54:29 UTC #7

The bluez snap already has a dbus endpoint. It doesn’t use a dbus type slot as all necessary DBus rules are built directly into the bluez interface. See https://github.com/snapcore/snapd/blob/master/interfaces/builtin/bluez.go

lance 2017-11-01 21:08:20 UTC #8

When I asked about that, I was seeing an error that I thought might be related to DBus, but it turns out to be unrelated. I made some progress on this with the changes here: https://github.com/lhartung/pulseaudio-snap/commit/d0a6a7708e9a26a088bc7df8d715a93f6151f54a

Right now, I am running bluez in devmode as well. We might need an apparmor change to handle these types of messages:

[ 1273.103620] audit: type=1107 audit(1509570212.606:154): pid=1249 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/Profile/HSPAGProfile" interface="org.bluez.Profile1" member="NewConnection" mask="send" name=":1.10" pid=1735 label="snap.bluez.bluez" peer_pid=3097 peer_label="unconfined"
[ 1273.364662] audit: type=1107 audit(1509570212.870:155): pid=1249 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/MediaEndpoint/A2DPSource" interface="org.bluez.MediaEndpoint1" member="SelectConfiguration" mask="send" name=":1.10" pid=1735 label="snap.bluez.bluez" peer_pid=3097 peer_label="unconfined"

jdstrand 2017-11-01 22:25:12 UTC #9

This should be fixed in 2.29. Can you test the core snap from the candidate channel?

lance 2017-11-02 17:16:01 UTC #10

Thanks. That does seem to resolve the apparmor messages.

Further along… I am able to pair and connect some devices, but they immediately disconnect after about one second. I noticed a variety of messages in syslog such as the following:

Nov  2 16:59:09 localhost bluetoothd[2097]: Endpoint replied with an error: org.freedesktop.DBus.Error.AccessDenied
Nov  2 16:59:14 localhost kernel: [ 2870.458699] Bluetooth: hci0 SCO packet for unknown connection handle 63
Nov  2 16:59:15 localhost bluetoothd[2097]: Unable to get io data for Headset Voice gateway: getpeername: Transport endpoint is not connected (107)

I am just throwing that out there in case someone here recognizes the symptoms. The same USB Bluetooth dongle and Bluetooth speaker work perfectly on Ubuntu 16.04 Desktop.

lance 2018-01-04 20:43:17 UTC #11

@ogra Thanks for pulling my changes into the pulseaudio snap. It looks like the functionality we need is almost all in place. I am testing with the versions of bluez, pulseaudio, and core in the edge channel, and it is mostly working. However, I do still need to install both bluez and pulseaudio in devmode to avoid apparmor rejections. It may be that the 2.29 update to core fixed some but not all of the rejects. I also found that I need to modify /etc/dbus-1/system.d/snap.bluez.bluez.conf to get audio devices working.

When pulseaudio starts up and loads the module-bluetooth-discover module, it connects to bluez over dbus. There are numerous apparmor messages related to that.

Jan 04 20:36:42 localhost.localdomain audit[1579]: AVC apparmor="ALLOWED" operation="connect" profile="snap.pulseaudio.pulseaudio" name="/run/dbus/system_bus_socket" pid=1579 comm="pulseaudio" requested_mask="wr" denied_mask="wr" fsuid=0 ouid=0
Jan 04 20:36:42 localhost.localdomain audit[1579]: AVC apparmor="ALLOWED" operation="file_perm" profile="snap.pulseaudio.pulseaudio" name="/run/dbus/system_bus_socket" pid=1579 comm="pulseaudio" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jan 04 20:36:42 localhost.localdomain audit[1173]: USER_AVC pid=1173 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/org/freedesktop/DBus" interface="org.freedesktop.DBus" member="Hello" mask="send" name="org.freedesktop.DBus" pid=1579 label="snap.pulseaudio.pulseaudio" peer_label="unconfined"
Jan 04 20:36:42 localhost.localdomain audit[1173]: USER_AVC pid=1173 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/org/freedesktop/DBus" interface="org.freedesktop.DBus" member="AddMatch" mask="send" name="org.freedesktop.DBus" pid=1579 label="snap.pulseaudio.pulseaudio" peer_label="unconfined"
Jan 04 20:36:42 localhost.localdomain audit[1173]: USER_AVC pid=1173 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/" interface="org.freedesktop.DBus.ObjectManager" member="GetManagedObjects" mask="send" name="org.bluez" pid=1579 label="snap.pulseaudio.pulseaudio" peer_pid=1583 peer_label="snap.bluez.bluez"
Jan 04 20:36:42 localhost.localdomain audit[1173]: USER_AVC pid=1173 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/" interface="org.freedesktop.DBus.ObjectManager" member="GetManagedObjects" name=":1.8" mask="receive" pid=1583 label="snap.bluez.bluez" peer_pid=1579 peer_label="snap.pulseaudio.pulseaudio"
Jan 04 20:36:42 localhost.localdomain audit[1173]: USER_AVC pid=1173 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/org/freedesktop/DBus" interface="org.freedesktop.DBus" member="RequestName" mask="send" name="org.freedesktop.DBus" pid=1579 label="snap.pulseaudio.pulseaudio" peer_label="unconfined"
Jan 04 20:36:42 localhost.localdomain audit[1173]: USER_AVC pid=1173 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/org/bluez/hci0" interface="org.bluez.Media1" member="RegisterEndpoint" mask="send" name="org.bluez" pid=1579 label="snap.pulseaudio.pulseaudio" peer_pid=1583 peer_label="snap.bluez.bluez"
Jan 04 20:36:42 localhost.localdomain audit[1173]: USER_AVC pid=1173 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/org/bluez/hci0" interface="org.bluez.Media1" member="RegisterEndpoint" name=":1.8" mask="receive" pid=1583 label="snap.bluez.bluez" peer_pid=1579 peer_label="snap.pulseaudio.pulseaudio"
Jan 04 20:36:42 localhost.localdomain audit[1173]: USER_AVC pid=1173 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/org/bluez" interface="org.bluez.ProfileManager1" member="RegisterProfile" mask="send" name="org.bluez" pid=1579 label="snap.pulseaudio.pulseaudio" peer_pid=1583 peer_label="snap.bluez.bluez"
Jan 04 20:36:42 localhost.localdomain audit[1173]: USER_AVC pid=1173 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/org/bluez" interface="org.bluez.ProfileManager1" member="RegisterProfile" name=":1.8" mask="receive" pid=1583 label="snap.bluez.bluez" peer_pid=1579 peer_label="snap.pulseaudio.pulseaudio"
Jan 04 20:36:42 localhost.localdomain audit[1173]: USER_AVC pid=1173 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_signal"  bus="system" path="/org/bluez/hci0" interface="org.freedesktop.DBus.Properties" member="PropertiesChanged" mask="send" name="org.freedesktop.DBus" pid=1583 label="snap.bluez.bluez" peer_pid=1579 peer_label="snap.pulseaudio.pulseaudio"
Jan 04 20:36:42 localhost.localdomain audit[1173]: USER_AVC pid=1173 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_signal"  bus="system" path="/org/bluez/hci0" interface="org.freedesktop.DBus.Properties" member="PropertiesChanged" name=":1.7" mask="receive" pid=1579 label="snap.pulseaudio.pulseaudio" peer_pid=1583 peer_label="snap.bluez.bluez"

Then there are a number of messages related to communication with the Bluetooth device.

Jan 04 19:50:35 localhost.localdomain audit[1217]: USER_AVC pid=1217 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/MediaEndpoint/A2DPSource" interface="org.bluez.MediaEndpoint1" member="SelectConfiguration" mask="send" name=":1.11" pid=1772 label="snap.bluez.bluez" peer_pid=1758 peer_label="snap.pulseaudio.pulseaudio"
                                                    exe="/usr/bin/dbus-daemon" sauid=100 hostname=? addr=? terminal=?'
Jan 04 19:50:35 localhost.localdomain audit[1217]: USER_AVC pid=1217 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/MediaEndpoint/A2DPSource" interface="org.bluez.MediaEndpoint1" member="SelectConfiguration" name=":1.10" mask="receive" pid=1758 label="snap.pulseaudio.pulseaudio" peer_pid=1772 peer_label="snap.bluez.bluez"
                                                    exe="/usr/bin/dbus-daemon" sauid=100 hostname=? addr=? terminal=?'
Jan 04 19:50:35 localhost.localdomain audit[1217]: USER_AVC pid=1217 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_signal"  bus="system" path="/" interface="org.freedesktop.DBus.ObjectManager" member="InterfacesAdded" mask="send" name="org.freedesktop.DBus" pid=1772 label="snap.bluez.bluez" peer_pid=1758 peer_label="snap.pulseaudio.pulseaudio"
                                                    exe="/usr/bin/dbus-daemon" sauid=100 hostname=? addr=? terminal=?'
Jan 04 19:50:35 localhost.localdomain audit[1217]: USER_AVC pid=1217 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_signal"  bus="system" path="/" interface="org.freedesktop.DBus.ObjectManager" member="InterfacesAdded" name=":1.10" mask="receive" pid=1758 label="snap.pulseaudio.pulseaudio" peer_pid=1772 peer_label="snap.bluez.bluez"
                                                    exe="/usr/bin/dbus-daemon" sauid=100 hostname=? addr=? terminal=?'
Jan 04 19:50:35 localhost.localdomain audit[1217]: USER_AVC pid=1217 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/MediaEndpoint/A2DPSource" interface="org.bluez.MediaEndpoint1" member="SetConfiguration" mask="send" name=":1.11" pid=1772 label="snap.bluez.bluez" peer_pid=1758 peer_label="snap.pulseaudio.pulseaudio"
                                                    exe="/usr/bin/dbus-daemon" sauid=100 hostname=? addr=? terminal=?'
Jan 04 19:50:35 localhost.localdomain audit[1217]: USER_AVC pid=1217 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_method_call"  bus="system" path="/MediaEndpoint/A2DPSource" interface="org.bluez.MediaEndpoint1" member="SetConfiguration" name=":1.10" mask="receive" pid=1758 label="snap.pulseaudio.pulseaudio" peer_pid=1772 peer_label="snap.bluez.bluez"
                                                    exe="/usr/bin/dbus-daemon" sauid=100 hostname=? addr=? terminal=?'
Jan 04 19:52:35 localhost.localdomain audit[1217]: USER_AVC pid=1217 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_signal"  bus="system" path="/org/bluez/hci0/dev_FC_58_FA_CF_57_09" interface="org.freedesktop.DBus.Properties" member="PropertiesChanged" mask="send" name="org.freedesktop.DBus" pid=1772 label="snap.bluez.bluez" peer_pid=1758 peer_label="snap.pulseaudio.pulseaudio"
                                                    exe="/usr/bin/dbus-daemon" sauid=100 hostname=? addr=? terminal=?'
Jan 04 19:52:35 localhost.localdomain audit[1217]: USER_AVC pid=1217 uid=100 auid=4294967295 ses=4294967295 msg='apparmor="ALLOWED" operation="dbus_signal"  bus="system" path="/org/bluez/hci0/dev_FC_58_FA_CF_57_09" interface="org.freedesktop.DBus.Properties" member="PropertiesChanged" name=":1.10" mask="receive" pid=1758 label="snap.pulseaudio.pulseaudio" peer_pid=1772 peer_label="snap.bluez.bluez"
                                                    exe="/usr/bin/dbus-daemon" sauid=100 hostname=? addr=? terminal=?'
Jan 04 19:54:40 localhost.localdomain audit[2586]: AVC apparmor="ALLOWED" operation="recvmsg" profile="snap.pulseaudio.pulseaudio" pid=2586 comm="bluetooth" family="bluetooth" sock_type="seqpacket" protocol=2 requested_mask="receive" denied_mask="receive"
Jan 04 19:54:40 localhost.localdomain audit[2586]: AVC apparmor="ALLOWED" operation="sendmsg" profile="snap.pulseaudio.pulseaudio" pid=2586 comm="bluetooth" family="bluetooth" sock_type="seqpacket" protocol=2 requested_mask="send" denied_mask="send"

Finally, I did need to edit “/etc/dbus-1/system.d/snap.bluez.bluez.conf” in order to get things working. I added the following two lines inside the first policy block.

<allow send_interface="org.bluez.MediaEndpoint1"/>
<allow send_interface="org.bluez.MediaPlayer1"/>

I noticed that these two lines are present on my Ubuntu Desktop workstation but not in Ubuntu Core and that the contents of this file are automatically generated on system boot. Are those dbus rules specified in the core snap or in the bluez snap?

jdstrand 2018-01-04 21:35:24 UTC #12

It seems the pulseaudio snap should ‘plugs: [ bluez ]’.

jdstrand 2018-01-04 21:36:39 UTC #13

The core snap: https://github.com/snapcore/snapd/blob/master/interfaces/builtin/bluez.go#L178

lance 2018-01-05 19:38:35 UTC #14

Thanks, that is super helpful. I created a PR on snapd to add the dbus rules (https://github.com/snapcore/snapd/pull/4448) and will do some more testing with the pulseaudio snap.