kevincar/bless

DBus.Error.AccessDenied - not allowed to own the service "org.bluez.TestService"

Closed this issue ยท 21 comments

The problem
Bless fails to launch on Linux with the error: txdbus.error.RemoteError: org.freedesktop.DBus.Error.AccessDenied: Connection ":1.136" is not allowed to own the service "org.bluez.TestService" due to security policies in the configuration file

Not sure if this is an invalid call, or if it actually needs a system config change. In addition I did run it as root one time, but no difference.

Reproduction
Simply run an example script: server.py or gattserver.py.

Expected behavior
Working bless on Linux.

Full log

$ python gattserver.py
DEBUG:asyncio:Using selector: EpollSelector
Traceback (most recent call last):
  File "/home/jk/Hobby/BMS-ble/ble-serial/gattserver.py", line 87, in <module>
    loop.run_until_complete(run(loop))
  File "/usr/lib/python3.9/asyncio/base_events.py", line 642, in run_until_complete
    return future.result()
  File "/home/jk/Hobby/BMS-ble/ble-serial/gattserver.py", line 66, in run
    await server.add_gatt(gatt)
  File "/home/jk/Hobby/BMS-ble/venv/lib/python3.9/site-packages/bless/backends/server.py", line 223, in add_gatt
    await self.add_new_service(service_uuid)
  File "/home/jk/Hobby/BMS-ble/venv/lib/python3.9/site-packages/bless/backends/bluezdbus/server.py", line 148, in add_new_service
    await service.init(self)
  File "/home/jk/Hobby/BMS-ble/venv/lib/python3.9/site-packages/bless/backends/bluezdbus/service.py", line 42, in init
    gatt_service: BlueZGattService = await bluez_server.app.add_service(self._uuid)
  File "/home/jk/Hobby/BMS-ble/venv/lib/python3.9/site-packages/bless/backends/bluezdbus/dbus/application.py", line 85, in add_service
    await self.bus.requestBusName(self.destination).asFuture(self.loop)
txdbus.error.RemoteError: org.freedesktop.DBus.Error.AccessDenied: Connection ":1.136" is not allowed to own the service "org.bluez.TestService" due to security policies in the configuration file

Desktop (please complete the following information):

  • OS: Arch Linux
  • BlueZ 5.62

Additional context
Tried it in addition on Ubuntu 21.10 and got exactly the same error.
It works flawlessly on Windows 10, so my hardware definitely supports it.

Also I see that it is a DBus error, thrown by txdbus. Since bleak switched away from it (see issue here) now to dbus-next, might it make sense to switch here too?

Edit: It works on my system with this code, which uses standard python-dbus.

Thanks @Jakeler for reporting this! I agree that switching to dubs-next in order to conform to siimilar bleak development is preferable to keep development for clients and servers similar. If you'd like to adjust the code and attempt to implement a switch to dubs-next or python-dbus, go for it. Otherwise, I'll probably get started on this in the next week or so.

Yeah, I think dbus-next is the best fit, because it properly integrates asyncio and is also used by bleak.
python-dbus requires GLib.MainLoop and feels quite outdated on the other hand, could actually even cause conflicts with two event loops, would need another thread, etc...
So I will do a first attempt with dbus-next then and create a PR if I make progress this week. Thanks for all your work!

@Jakeler, I made an attempt to switch to dbus-next. See the 60-dbus-next branch.

I'm still unsure whether this switch will actually address the issue you came across on permissions though. Let me know if you still see that behavior with this change. Any additions you have on your end are also welcome still.

Nice, thanks!
This still does not solve this issue though. I digged a while in the dbus documentation and configs, now it makes actually a lot of sense: /usr/share/dbus-1/system.conf

    <!-- Holes must be punched in service configuration files for
         name ownership and sending method calls -->
    <deny own="*"/>

/usr/share/dbus-1/system.d/bluetooth.conf

  <!-- ../system.conf have denied everything, so we just punch some holes -->
  <policy user="root">
    <allow own="org.bluez"/>
    ...

It is actually important for security, so not any unprivileged program can take over names of system services.

I found 4 calls to Messagebus.request_name() in bless and to be honest I don't understand why they are in there. A unique name (for example :1.394) gets dynamically assigned for every bus connection, that is enough to setup a BLE server. It allows to export the required objects with the paths.

So I tried patching it out, but then I have problems with get_obj() of service and characteristic:

Exception: Rejected send message, 1 matched rules; type="method_call", sender=":1.330" (uid=1000 pid=107006 comm="python examples/server.py ") interface="org.freedesktop.DBus.Properties" member="GetAll" error name="(unset)" requested_reply="0" destination=":1.330" (uid=1000 pid=107006 comm="python examples/server.py ")

Which also makes sense, because sending on the system bus is only allowed to whitelisted destinations. But again I don't understand why this is even done in bless, should the local object (self) not already contain all data? Then these remote calls that basically do introspection on itself could also be removed.

PS: A workaround would be to change the system config, adding something like this:

  <policy user="jake">
    <allow own="org.bluez.TestService"/>
    <allow send_destination="org.bluez.TestService"/>
  </policy>

With that I can get it to start up, would not recommend it though, as it should not be required.

PS: A workaround would be to change the system config, adding something like this:

Having this problem on rpi, untill a better solution is available, this workaround is fine for me. Thanks!!

Question: I would expect the client to see the service TestService, but my client sees the ble-ADDRESS.
What parameter did I not specify?

@Jakeler thanks for that run down. I'm certainly not well versed in D-bus, the current dbus-next implementation was a quick spin up based on experimenting and putting together a bluez advertisement using the command line, so the calls to request_name were used to export and expose each service and characteristc object on the D-Bus. So even though there are only 4 calls, they could be called as many times as services/characteristics are implemented by the end user. But as you suggest that this may not be necessary, I'll explore other methods:

Security Issue

I'll see if I can get the implementation working not he Session bus as opposed to the system bus. Will need to ensure that access to the hardware bluetooth hci adapter on the D-Bus is still accessible with a SESSION bus type.

Self introspection & Virtualization

Perhaps keeping all the GATT service and characteristic information off the D-Bus will release the need to place the services on the D-Bus at all (via request_name).

@Jakeler Alright, I think I've got this resolved. The app now exposes all services and characteristics on the primary org.bluez dbus connection/object rather than it's own (previously org.bluez.<app_name>. This should remove the security issues you brought up. Can you confirm using the latest pull on 60-dbus-next branch?

Good news, I will test Monday

Hi @kevincar

With @Jakeler's solution:

  • The master branch and develop branch work
  • The 60-dbus-next branch does not: clsBleServer._Server(); start() exception Connection ":1.198" is not allowed to own the service "org.bluez" due to security policies in the configuration file

/etc/dbus-1/system.d/bluetooth.conf

<!-- This configuration file specifies the required security policies
     for Bluetooth core daemon to work. -->

<!DOCTYPE busconfig PUBLIC "-//freedesktop//DTD D-BUS Bus Configuration 1.0//EN"
 "http://www.freedesktop.org/standards/dbus/1.0/busconfig.dtd">
<busconfig>

  <!-- ../system.conf have denied everything, so we just punch some holes -->

  <policy user="root">
    <allow own="org.bluez"/>
    <allow send_destination="org.bluez"/>
    <allow send_interface="org.bluez.Agent1"/>
    <allow send_interface="org.bluez.MediaEndpoint1"/>
    <allow send_interface="org.bluez.MediaPlayer1"/>
    <allow send_interface="org.bluez.Profile1"/>
    <allow send_interface="org.bluez.GattCharacteristic1"/>
    <allow send_interface="org.bluez.GattDescriptor1"/>
    <allow send_interface="org.bluez.LEAdvertisement1"/>
    <allow send_interface="org.freedesktop.DBus.ObjectManager"/>
    <allow send_interface="org.freedesktop.DBus.Properties"/>
  </policy>

  <!-- allow users of bluetooth group to communicate -->
  <policy group="bluetooth">
    <allow send_destination="org.bluez"/>
  </policy>

  <policy at_console="true">
    <allow send_destination="org.bluez"/>
  </policy>

  <!-- allow users of lp group (printing subsystem) to
       communicate with bluetoothd -->
  <policy group="lp">
    <allow send_destination="org.bluez"/>
  </policy>

  <policy context="default">
    <deny send_destination="org.bluez"/>
  </policy>


  <policy user="pi">
    <allow own="org.bluez.FortiusAntTrainer"/>
    <allow send_destination="org.bluez.FortiusAntTrainer"/>
  </policy>
</busconfig>

@WouterJD are you able to share your fulll log of that exception?

The logging (only) provides:

INFO:root:clsBleServer.Open()
DEBUG:asyncio:Using selector: EpollSelector
INFO:root:clsBleServer._Server(FortiusAntTrainer)
INFO:root:clsBleServer._Server(): self.BlessServer.add_gatt()
INFO:root:clsBleServer._Server(): self.BlessServer.start()
ERROR:root:clsBleServer._Server(); start() exception Connection ":1.215" is not allowed to own the service "org.bluez" due to security policies in the configuration file
ERROR:root:, Bluetooth interface n/a; BLE-5 required!
INFO:root:clsBleServer._Server(): 1 second loop untill Close() called
INFO:root:clsBleServer._Server() ended

Note that my "main" contains, is that not correct?
logging.basicConfig(level=logging.DEBUG)

Sorry, I meant if you could show your error trace? Similar to Jakeler's above

Also, just to double check, your 60-dbus-next is up-to-date?

I install with pip3 install --force-reinstall git+https://github.com/kevincar/bless.git@60-dbus-next so I assume yes.

You main the stack trace ... I will remove the try and get it for you

Exception in thread Thread-1:
Traceback (most recent call last):
  File "/usr/lib/python3.7/threading.py", line 917, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.7/threading.py", line 865, in run
    self._target(*self._args, **self._kwargs)
  File "/home/pi/FortiusANT/pythoncode/FTMSserverClass.py", line 140, in _OpenThread
    self.loop.run_until_complete(self._Server())
  File "/usr/lib/python3.7/asyncio/base_events.py", line 584, in run_until_complete
    return future.result()
  File "/home/pi/FortiusANT/pythoncode/FTMSserverClass.py", line 184, in _Server
    await self.BlessServer.start()
  File "/home/pi/.local/lib/python3.7/site-packages/bless/backends/bluezdbus/server.py", line 85, in start
    await self.bus.request_name(self.app.destination)
  File "/home/pi/.local/lib/python3.7/site-packages/dbus_next/aio/message_bus.py", line 246, in request_name
    return await future
  File "/home/pi/.local/lib/python3.7/site-packages/dbus_next/message_bus.py", line 292, in reply_notify
    BaseMessageBus._check_method_return(reply, err, 'u')
  File "/home/pi/.local/lib/python3.7/site-packages/dbus_next/message_bus.py", line 615, in _check_method_return
    raise DBusError._from_message(msg)
dbus_next.errors.DBusError: Connection ":1.216" is not allowed to own the service "org.bluez" due to security policies in the configuration file

Stack trace now integrated in logging for future issues

2022-03-28 22:11:35,210: [FortiusAnt, INFO] clsBleServer.Open()
2022-03-28 22:11:35,212: [asyncio, DEBUG] Using selector: EpollSelector
2022-03-28 22:11:35,214: [FortiusAnt, INFO] clsBleServer._Server(FortiusAntTrainer)
2022-03-28 22:11:35,215: [FortiusAnt, INFO] clsBleServer._Server(): self.BlessServer.add_gatt()
2022-03-28 22:11:35,308: [FortiusAnt, INFO] clsBleServer._Server(): self.BlessServer.start()
2022-03-28 22:11:35,323: [FortiusAnt, INFO] Traceback (most recent call last):

2022-03-28 22:11:35,323: [FortiusAnt, INFO]   File "/home/pi/FortiusANT/pythoncode/bleBlessClass.py", line 188, in _Server
    await self.BlessServer.start()

2022-03-28 22:11:35,324: [FortiusAnt, INFO]   File "/home/pi/.local/lib/python3.7/site-packages/bless/backends/bluezdbus/server.py", line 85, in start
    await self.bus.request_name(self.app.destination)

2022-03-28 22:11:35,324: [FortiusAnt, INFO]   File "/home/pi/.local/lib/python3.7/site-packages/dbus_next/aio/message_bus.py", line 246, in request_name
    return await future

2022-03-28 22:11:35,324: [FortiusAnt, INFO]   File "/home/pi/.local/lib/python3.7/site-packages/dbus_next/message_bus.py", line 292, in reply_notify
    BaseMessageBus._check_method_return(reply, err, 'u')

2022-03-28 22:11:35,325: [FortiusAnt, INFO]   File "/home/pi/.local/lib/python3.7/site-packages/dbus_next/message_bus.py", line 615, in _check_method_return
    raise DBusError._from_message(msg)

2022-03-28 22:11:35,325: [FortiusAnt, INFO] dbus_next.errors.DBusError: Connection ":1.258" is not allowed to own the service "org.bluez" due to security policies in the configuration file

2022-03-28 22:11:35,325: [FortiusAnt, INFO] clsBleServer._Server(); start() exception Connection ":1.258" is not allowed to own the service "org.bluez" due to security policies in the configuration file
2022-03-28 22:11:35,326: [FortiusAnt, INFO] , Bluetooth interface n/a; BLE-5 required!
2022-03-28 22:11:35,326: [FortiusAnt, INFO] clsBleServer._Server(): 1 second loop untill Close() called
2022-03-28 22:11:35,327: [FortiusAnt, INFO] clsBleServer._Server() ended
2022-03-28 22:11:36,215: [FortiusAnt, INFO] clsBleServer.Close()

I saw that you got rid off the most request_name calls, that is good! Now there is only one left that causes this:
https://github.com/kevincar/bless/blob/60-dbus-next/bless/backends/bluezdbus/server.py#L85
It is also not needed and not allowed on the system bus, especially for a existing system service name like org.bluez.
Otherwise the following call to org.bluez.GattManager1.RegisterApplication looks fine, should be enough to activate the exported app object.
So the fix seems to be to simply remove that request. Then it starts up - at least in my quick test, connection works and the services show up.
Only problem is that it does not react to read/writes with the example, even though I can see that bluez sends messages to the app (checked with sudo dbus-monitor --system "sender=org.bluez")

I found I had extra permissions in my bluetooth.conf as follows:

...
  <policy context="default">
    <allow send_destination="org.bluez"/>
  </policy>
...

I switched this back to deny. However, have you both added your users to be apart of the bluetooth group? Otherwise, I can't even introspect on the org.bluez connection.

No, I did not add my user to a bluetooth group (on Arch it does not even exist). Also I am running the default config from the bluez package, which directly takes the dbus config from upstream: https://github.com/bluez/bluez/blob/5.63/src/bluetooth.conf
So the allow send_destination="org.bluez" is normal and should be there.

Otherwise sending (method calls) are globally denied on the system bus, you can see this in the system.conf again:

<deny send_type="method_call"/>

Introspect is also just a method call on interface org.freedesktop.DBus.Introspectable. So it is required to punch a hole there with bluetooth.conf, also for the following method calls that register the advertsiment, app etc.

The system config is well commented in general, for example everyone can receive:

    <!-- All messages may be received by default -->
    <allow receive_type="method_call"/>
    <allow receive_type="method_return"/>

Back to the bluetooth.conf:

  <policy user="root">
    ...
    <allow send_interface="org.bluez.GattCharacteristic1"/>
    ...

root/bluez is allowed to send to specific interfaces, that explains why this works:

method call time=1648574035.379263 sender=:1.100 -> destination=:1.178 serial=922 path=/org/bluez/TestService/service0001/char0001; interface=org.bluez.GattCharacteristic1; member=WriteValue
   array of bytes [
      0f
   ]
   array [
      dict entry(
         string "device"
         variant             object path "/org/bluez/hci0/dev_45_F4_23_78_40_18"
      )
      dict entry(
         string "link"
         variant             string "LE"
      )
      dict entry(
         string "mtu"
         variant             uint16 517
      )
   ]

method call time=1648574144.052803 sender=:1.100 -> destination=:1.178 serial=923 path=/org/bluez/TestService/service0001/char0001; interface=org.bluez.GattCharacteristic1; member=ReadValue
   array [
      dict entry(
         string "device"
         variant             object path "/org/bluez/hci0/dev_45_F4_23_78_40_18"
      )
      dict entry(
         string "link"
         variant             string "LE"
      )
      dict entry(
         string "mtu"
         variant             uint16 517
      )
   ]

Here bluez was setup as server and a client read/writes a value, bluez forwards the event to the actual application.
Sender is org.bluez which resolves to the unique name :1.100, that is what dbus-monitor --system "sender=org.bluez" displays. Destination is bless, which got the unique name :1.178 from dbus in this case (and requested no well known name, how it should be).

I hope this explanation helps a bit. dbus is indeed quite confusing, but I can recommend to launch some working programs and watch with dbus-monitor. Also graphical d-feet is useful to check bus names, interfaces etc.

The setup from bless is fine I think, just have to figure out why it does not handle the received method calls.

Wauw @kevincar @Jakeler that's a lot of information.
Is bless now ready for testing and what should I do?
Please suggest.

Apologies for the hiatus. Just removed the remaining request name call.

I also found that my permissions issue was related to running bless as an ssh user is different than running it otherwise and fixed that. I can read, write, request, and notify now.

If there are no issues remaining with the security here, I'll push this through.

I can confirm that this fixed the error and runs with default config (without security implications), thank you so much!
To get it running on my system it only needed a few other adjustments, see my PR #85.