https://bugzilla.kernel.org/show_bug.cgi?id=198453 Bug ID: 198453 Summary: bluez generates spurious DBUS messages, causing unexpected syslog events Product: Drivers Version: 2.5 Kernel Version: 4.14.12 Hardware: All OS: Linux Tree: Mainline Status: NEW Severity: normal Priority: P1 Component: Bluetooth Assignee: linux-bluetooth@xxxxxxxxxxxxxxx Reporter: faminebadger@xxxxxxxxxxxxxx Regression: No 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". -- You are receiving this mail because: You are the assignee for the bug.-- To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
