On Tue, 2013-08-06 at 12:05 -0300, Jo?o Paulo Rechi Vita wrote:
> On Mon, Jul 29, 2013 at 8:40 AM, Tanu Kaskinen
> <tanu.kaskinen at linux.intel.com> wrote:
> > On Thu, 2013-07-25 at 01:44 -0300, Jo?o Paulo Rechi Vita wrote:
> >> On Mon, Jul 22, 2013 at 7:33 AM, Tanu Kaskinen
> >> <tanu.kaskinen at linux.intel.com> wrote:
> >> > On Fri, 2013-07-12 at 15:06 -0300, jprvita at gmail.com wrote:
> >> >> +static int parse_device_property(pa_bluetooth_device *d, DBusMessageIter *i, bool is_property_change) {
> >> >> + const char *key;
> >> >> + DBusMessageIter variant_i;
> >> >> +
> >> >> + pa_assert(d);
> >> >> +
> >> >> + key = pa_bluetooth_dbus_check_variant_property(i);
> >> >> + if (key == NULL) {
> >> >> + pa_log_error("Received invalid property for device %s", d->path);
> >> >> + return -1;
> >> >> + }
> >> >> +
> >> >> + dbus_message_iter_recurse(i, &variant_i);
> >> >> +
> >> >> + switch (dbus_message_iter_get_arg_type(&variant_i)) {
> >> >> +
> >> >> + case DBUS_TYPE_STRING: {
> >> >> + const char *value;
> >> >> + dbus_message_iter_get_basic(&variant_i, &value);
> >> >> +
> >> >> + if (pa_streq(key, "Alias")) {
> >> >> + pa_xfree(d->alias);
> >> >> + d->alias = pa_xstrdup(value);
> >> >> + } else if (pa_streq(key, "Address")) {
> >> >> + if (is_property_change) {
> >> >> + pa_log_error("Device property 'Address' expected to be constant but changed for %s", d->path);
> >> >> + return -1;
> >> >> + }
> >> >> +
> >> >> + if (d->address) {
> >> >> + pa_log_error("Device %s: Received a duplicate Address property.", d->path);
> >> >> + return -1;
> >> >> + }
> >> >> +
> >> >> + d->address = pa_xstrdup(value);
> >> >> + }
> >> >> +
> >> >> + pa_log_debug("%s: %s", key, value);
> >> >
> >> > Please use proper sentences in the log. Or is this a temporary log
> >> > message that you just forgot to remove from the final patch?
> >> >
> >>
> >> This is usually received when the device is created, together with a
> >> lot of other properties, so I think is better to minimize verbosity
> >> here. What I'll change to improve this scenario is add a log in the
> >> beginning of the function with the device path.
> >
> > I would actually prefer to drop the message altogether. If the property
> > is interesting to us, its value will probably appear elsewhere anyway
> > (when the property changes, a change message should be printed, and when
> > receiving the initial properties, the properties should be printed once
> > the parsing is complete). This will also print properties that aren't
> > interesting to us, which just adds noise, and it's not even consistent,
> > because only string and uint32 properties will be printed.
> >
>
> This piece of code will actually do exactly as you described as
> desired, it will print only the properties that are interesting to us,
No, it prints all string and uint32 properties that bluetoothd sends us,
regardless of whether we are interested in them or not (Icon is one
example of an uninteresting property).
> when the property changes, or when receiving the initial properties.
> This function, parse_device_property(), is only called from
> parse_device_properties(), which in turn is only called on the
> following situations: 1) when parsing all the interfaces and
> properties in the reply of a GetManagedObjects() call; 2) when parsing
> all the interfaces and properties that came with an InterfacesAdded
> signal; and 3) when a
> org.freedesktop.DBus.Properties.PropertiesChanged signal is received,
> with a dictionary containing the changed properties with the new
> values. Note that in 3 we'll only print a debug message with the
> property and value for the properties which the change have been
> notified in that message.
I explained my point badly. The way I would like property changes to be
logged is in a helper function, for example set_alias(), which would
print "Device %s alias changed from '%s' to '%s'." (The helper would
also check whether the alias actually changed, and fire a hook, so the
function wouldn't exist just for printing a fancy log message.) If we
had that, then printing the alias also where you currently print it
would be redundant. When a new device appears, we could parse all
properties silently, and if all properties are parsed successfully, we
could then log a message like this: "Device %s created. alias=%s
address=%s class=%u"
I admit that the logs actually look much better than what I thought when
I first complained about this code. If you don't like to do the changes
that I suggest, I'm OK with leaving the code as it is (the inconsistency
regarding uninteresting properties bothers me, though - only properties
that happen to have type string or uint32 will be logged).
> A debug log of these situations will look like this (I've now added
> the message that says "Properties changed in device %s"):
>
> - with the device already created prior to PulseAudio's start
>
> (1)
> D: [memcheck-amd64-] bluez5-util.c: Device
> /org/bluez/hci0/dev_00_0D_3C_B1_B5_5C found
> D: [memcheck-amd64-] bluez5-util.c: Address: 00:0D:3C:B1:B5:5C
> D: [memcheck-amd64-] bluez5-util.c: Name: Nokia BH-503
> D: [memcheck-amd64-] bluez5-util.c: Alias: Nokia BH-503
> D: [memcheck-amd64-] bluez5-util.c: Class: 2360324
> D: [memcheck-amd64-] bluez5-util.c: Icon: audio-card
> D: [memcheck-amd64-] bluez5-util.c: UUIDs: 00001108-0000-1000-8000-00805f9b34fb
> D: [memcheck-amd64-] bluez5-util.c: UUIDs: 0000110b-0000-1000-8000-00805f9b34fb
> D: [memcheck-amd64-] bluez5-util.c: UUIDs: 0000110c-0000-1000-8000-00805f9b34fb
> D: [memcheck-amd64-] bluez5-util.c: UUIDs: 0000110d-0000-1000-8000-00805f9b34fb
> D: [memcheck-amd64-] bluez5-util.c: UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
> D: [memcheck-amd64-] bluez5-util.c: UUIDs: 0000111e-0000-1000-8000-00805f9b34fb
>
> - during device creation
>
> (First the user put the adapter in inquiry mode, to find visible
> devices nearby. When the device is found the device object is created
> BlueZ and the following messages are printed.)
>
> (2)
> D: [memcheck-amd64-] bluez5-util.c: Device
> /org/bluez/hci0/dev_00_23_7F_20_43_F5 found
> D: [memcheck-amd64-] bluez5-util.c: Address: 00:23:7F:20:43:F5
> D: [memcheck-amd64-] bluez5-util.c: Name: 8XXPlantronics
> D: [memcheck-amd64-] bluez5-util.c: Alias: 8XXPlantronics
> D: [memcheck-amd64-] bluez5-util.c: Class: 2360324
> D: [memcheck-amd64-] bluez5-util.c: Icon: audio-card
>
> (And only after the device is paired the services are resolved and the
> UUIDs are emitted.)
>
> (3)
> D: [memcheck-amd64-] bluez5-util.c: Properties changed in device
> /org/bluez/hci0/dev_00_23_7F_20_43_F5
> D: [memcheck-amd64-] bluez5-util.c: UUIDs: 00001108-0000-1000-8000-00805f9b34fb
> D: [memcheck-amd64-] bluez5-util.c: UUIDs: 0000110b-0000-1000-8000-00805f9b34fb
> D: [memcheck-amd64-] bluez5-util.c: UUIDs: 0000110e-0000-1000-8000-00805f9b34fb
> D: [memcheck-amd64-] bluez5-util.c: UUIDs: 0000111e-0000-1000-8000-00805f9b34fb
>
> >> >> +
> >> >> + pa_log_debug("%s: %d", key, value);
> >> >> + break;
> >> >> + }
> >> >> +
> >> >> + case DBUS_TYPE_ARRAY: {
> >> >> + DBusMessageIter ai;
> >> >> + dbus_message_iter_recurse(&variant_i, &ai);
> >> >> +
> >> >> + if (dbus_message_iter_get_arg_type(&ai) == DBUS_TYPE_STRING && pa_streq(key, "UUIDs")) {
> >> >> + while (dbus_message_iter_get_arg_type(&ai) != DBUS_TYPE_INVALID) {
> >> >> + pa_bluetooth_uuid *node;
> >> >> + const char *value;
> >> >> +
> >> >> + dbus_message_iter_get_basic(&ai, &value);
> >> >> +
> >> >> + if (pa_bluetooth_uuid_has(d->uuids, value)) {
> >> >> + dbus_message_iter_next(&ai);
> >> >> + continue;
> >> >> + }
> >> >> +
> >> >> + node = pa_bluetooth_uuid_new(value);
> >> >> + PA_LLIST_PREPEND(pa_bluetooth_uuid, d->uuids, node);
> >> >> +
> >> >> + pa_log_debug("%s: %s", key, value);
> >> >> + dbus_message_iter_next(&ai);
> >> >
> >> > This code only adds UUIDs to pa_bluetooth_device, never removes them. Is
> >> > this intentional? If so, I think a comment explaining the rationale
> >> > would be good.
> >> >
> >> > There aren't any hooks that would be fired when the properties (Alias,
> >> > Class, UUIDs) change. Perhaps you implement them in some later patches?
> >> >
> >>
> >> This is used to create card profiles on load of module-bluez5-device.
> >> It is possible (although not likely) that a device change the
> >> implemented UUIDs during the connection lifetime. Alias can change,
> >> but I think this should be handled in a separate patch (I've not
> >> written that yet).
> >
> > It's not clear what changes you plan to do (as separate patches or
> > otherwise). If it's possible that UUIDs get removed, we should handle
> > that.
> >
>
> Sorry, I wasn't clear enough. It's possible that a remote device
> removes a UUID from its list of supported services. But in BlueZ we'll
> never detect this situation, so the UUIDs property will not change in
> the device object. What will happen is that if BlueZ tries to connect
> to that service the connection will fail. I agree it's an
> implementation detail, but if we write code to handle UUIDs removal it
> will never be exercised with the current BlueZ implementation.
What's the problem with having untested code in this case? There is a
risk that the code doesn't work if BlueZ some day starts to support
removing UUIDs? If we don't implement support for it, then we know for
sure that the code won't work.
--
Tanu
