I get this sort of message regularly in my logcheck reports: > Jan 11 20:32:04 gentoo dbus-daemon[2520]: [system] Rejected send message, 0 > matched rules; type="method_return", sender=":1.34" (uid=0 pid=27198 > comm="/var/tmp/portage/net-wireless/bluez-5.47-r1/work/b") > interface="(unset)" member="(unset)" error name="(unset)" requested_reply="0" > destination=":1.35" (uid=1000 pid=27229 comm="python3.5 ") Which is DBUS rejecting a bluetoothd response to a request from a user application (blueman-applet in my case). This python snippet reproduces it: > Python 3.5.4 (default, Jan 6 2018, 03:17:39) > [GCC 7.2.0] on linux > Type "help", "copyright", "credits" or "license" for more information. > >>> from blueman.bluez.Manager import Manager > >>> mgr=Manager() > >>> adpt=mgr.get_adapters() > >>> print(adpt[0].get("Powered")) > False > >>> adpt[0].set("Powered", False) That last line results in the error being sent to the syslog. I debugged it a little, and I have come to the conclusion that this is because bluetoothd is generating a DBUS message response even when one has not been requested (i.e. the NO_REPLY flag) - and so DBUS policy blocks the message and raises the error. It seems that, somewhat strangely, there are two places in the bluez code that can generate a response message. The first is object.c:process_message. This function correctly checks the NO_REPLY flag (dbus_message_get_no_reply), and discards the prepared response if it is set. However, following the code deeper, it seems the set operation itself - object.c:g_dbus_pending_property_success - can also directly send to the bus instead of returning a prepared message as would be expected given the behaviour of the above caller function - eventual caller (process_message). Here's the full call stack: > #0 g_dbus_pending_property_success (id=id@entry=7) at gdbus/object.c:456 > #1 0x00005555555b28c6 in property_set_mode (adapter=0x555555850860, > setting=setting@entry=1, value=<optimized out>, > id=7) at src/adapter.c:2625 > #2 0x00005555555b2a96 in property_set_powered (property=<optimized out>, > iter=<optimized out>, id=<optimized out>, > user_data=<optimized out>) at src/adapter.c:2711 > #3 0x00005555555dce58 in properties_set (connection=0x555555847ac0, > message=0x55555584eff0, user_data=<optimized out>) > at gdbus/object.c:922 > #4 0x00005555555dd226 in process_message (connection=0x555555847ac0, > message=0x55555584eff0, > method=0x555555833b68 <properties_methods+40>, iface_user_data=<optimized > out>) at gdbus/object.c:256 > #5 0x00005555555dd6b2 in generic_message (connection=0x555555847ac0, > message=0x55555584eff0, user_data=<optimized out>) > at gdbus/object.c:1080 > #6 0x00007ffff789e953 in _dbus_object_tree_dispatch_and_unlock () from > /usr/lib64/libdbus-1.so.3 > #7 0x00007ffff788ef0b in dbus_connection_dispatch () from > /usr/lib64/libdbus-1.so.3 > #8 0x00005555555da1cd in message_dispatch (data=0x555555847ac0) at > gdbus/mainloop.c:72 > #9 0x00007ffff7b10645 in g_main_context_dispatch () from > /usr/lib64/libglib-2.0.so.0 > #10 0x00007ffff7b109e8 in g_main_context_iterate.isra () from > /usr/lib64/libglib-2.0.so.0 > #11 0x00007ffff7b10cf2 in g_main_loop_run () from /usr/lib64/libglib-2.0.so.0 > #12 0x000055555559b60d in main (argc=<optimized out>, argv=<optimized out>) > at src/main.c:781 Note, once again, both process_message (stack frame #4) and g_dbus_pending_property_success (stack frame #4) contain code to send a response to the message, but only the latter checks the NO_REPLY flag. It seems to me that the code was designed for the methods called by process_message to return a response to the caller, not generate it themselves, and somewhere this idea has been broken. I haven't checked whether there are any code paths that could generate a double message (that is, send one now as well as return one to caller), but if so this would also generate a DBUS error (as the second response would no longer be a "requested reply".
> Note, once again, both process_message (stack frame #4) and > g_dbus_pending_property_success (stack frame #4) Should read: > Note, once again, both process_message (stack frame #4) and > g_dbus_pending_property_success (stack frame #0) Sorry!
Seems nobody is interested in this, despite the effort I put in to track down the source of the problem.
Created attachment 273905 [details] Fix replying to messages marked with NOREPLY
Any chance to get the above patch tested?
Sure, I can try it out - I just need to remove my temporary logcheck rule and build with the patch. I'll try and do it this weekend.
Yes, this prevents the error on my system. It's fine for a patch for now - but I also think that the question I raised regarding the apparently two contradictory designs that both exist in the code should be considered.