bug and possible patch for dbus DiscoverServices

bug and possible patch for dbus DiscoverServices

[Tim Renouf]

Hi Bluetooth people

I am investigating a bug where dbus DiscoverServices incorrectly returns
an empty array in some circumstances (see below).

Here is my suggested patch, against BlueZ 4.47 (I don't think there are
any more recent changes in this area):

====
diff -ur ../eclair.old/external/bluetooth/bluez/src/device.c external/bluetooth/bluez/src/device.c
--- ../eclair.old/external/bluetooth/bluez/src/device.c	2009-12-15 13:15:44.000000000 +0000
+++ external/bluetooth/bluez/src/device.c	2010-06-10 11:31:04.000000000 +0100
@@ -1380,6 +1380,7 @@
 {
 	struct browse_req *req = user_data;
 	struct btd_device *device = req->device;
+	sdp_list_t	*records = 0;
 	DBusMessage *reply;
 
 	if (err < 0) {
@@ -1389,6 +1390,7 @@
 	}
 
 	update_services(req, recs);
+	records = req->records;
 
 	if (device->tmp_records && req->records) {
 		sdp_list_free(device->tmp_records,
@@ -1422,7 +1424,7 @@
 
 	if (dbus_message_is_method_call(req->msg, DEVICE_INTERFACE,
 					"DiscoverServices")) {
-		discover_services_reply(req, err, req->records);
+		discover_services_reply(req, err, records);
 		goto cleanup;
 	}
 
====

The problem seems to arise in this bit of search_cb() at device.c:1395:

    if (device->tmp_records && req->records) {
        sdp_list_free(device->tmp_records,
                    (sdp_free_func_t) sdp_record_free);
        device->tmp_records = req->records;
        req->records = NULL;
    }

In the case that device->tmp_records was already set, this zeroes
req->records and so causes the empty array to be returned via dbus a bit
lower down in the function.

I'm not really sure what tmp_records does, and whether it should be
non-zero at this point. So it could be either

1. tmp_records could be non-zero, so search_cb should return the results
even if the above code kicks in and zeroes req->records (that's what my
patch assumes); or

2. tmp_records is supposed to be zero there, so there is a bug
elsewhere. In particular, I have only seen the bug on Android phones,
not on my PC, and a bit of investigation showed that it is some Android
specific code (the new dbus method GetServiceAttributeValue; see the
device.c here:
http://android.git.kernel.org/?p=platform/external/bluez.git;a=blob;f=src/device.c;h=67a77318ad136c12cad96f0e537f8ceac8ae62f0;hb=refs/heads/eclair-bluez
line 789) that sets tmp_records and does not clear it again.

Also, the bug does not appear when the device I am trying to discover
services on is my PC rather than a phone. I suspect the Android
Bluetooth startup sequence only uses this GetServiceAttributeValue on a
remote device with some phone-specific service, so the
device->tmp_records for my PC remains at 0.

I would be grateful for any hints on what tmp_records does, and whether
my patch is correct or whether I should be looking elsewhere.

Thanks.

-tpr

Re: bug and possible patch for dbus DiscoverServices

[Luiz Augusto von Dentz]

Hi,

On Thu, Jun 10, 2010 at 3:58 PM, Tim Renouf <tpr.vger@botech.co.uk> wrote:
> Hi Bluetooth people
>
> I am investigating a bug where dbus DiscoverServices incorrectly returns
> an empty array in some circumstances (see below).
>
> Here is my suggested patch, against BlueZ 4.47 (I don't think there are
> any more recent changes in this area):
>
> ====
> diff -ur ../eclair.old/external/bluetooth/bluez/src/device.c external/bluetooth/bluez/src/device.c
> --- ../eclair.old/external/bluetooth/bluez/src/device.c 2009-12-15 13:15:44.000000000 +0000
> +++ external/bluetooth/bluez/src/device.c       2010-06-10 11:31:04.000000000 +0100
> @@ -1380,6 +1380,7 @@
>  {
>        struct browse_req *req = user_data;
>        struct btd_device *device = req->device;
> +       sdp_list_t      *records = 0;
>        DBusMessage *reply;
>
>        if (err < 0) {
> @@ -1389,6 +1390,7 @@
>        }
>
>        update_services(req, recs);
> +       records = req->records;
>
>        if (device->tmp_records && req->records) {
>                sdp_list_free(device->tmp_records,
> @@ -1422,7 +1424,7 @@
>
>        if (dbus_message_is_method_call(req->msg, DEVICE_INTERFACE,
>                                        "DiscoverServices")) {
> -               discover_services_reply(req, err, req->records);
> +               discover_services_reply(req, err, records);
>                goto cleanup;
>        }
>
> ====
>
> The problem seems to arise in this bit of search_cb() at device.c:1395:
>
>    if (device->tmp_records && req->records) {
>        sdp_list_free(device->tmp_records,
>                    (sdp_free_func_t) sdp_record_free);
>        device->tmp_records = req->records;
>        req->records = NULL;
>    }
>
> In the case that device->tmp_records was already set, this zeroes
> req->records and so causes the empty array to be returned via dbus a bit
> lower down in the function.

Good catch, I've seems this sometimes but I was never really able to
reproduce it consistently but this seems definably the source of the
problem.

> I'm not really sure what tmp_records does, and whether it should be
> non-zero at this point. So it could be either
>
> 1. tmp_records could be non-zero, so search_cb should return the results
> even if the above code kicks in and zeroes req->records (that's what my
> patch assumes); or
>
> 2. tmp_records is supposed to be zero there, so there is a bug
> elsewhere. In particular, I have only seen the bug on Android phones,
> not on my PC, and a bit of investigation showed that it is some Android
> specific code (the new dbus method GetServiceAttributeValue; see the
> device.c here:
> http://android.git.kernel.org/?p=platform/external/bluez.git;a=blob;f=src/device.c;h=67a77318ad136c12cad96f0e537f8ceac8ae62f0;hb=refs/heads/eclair-bluez
> line 789) that sets tmp_records and does not clear it again.
>
> Also, the bug does not appear when the device I am trying to discover
> services on is my PC rather than a phone. I suspect the Android
> Bluetooth startup sequence only uses this GetServiceAttributeValue on a
> remote device with some phone-specific service, so the
> device->tmp_records for my PC remains at 0.
>
> I would be grateful for any hints on what tmp_records does, and whether
> my patch is correct or whether I should be looking elsewhere.

I would just rework it a bit to make the tmp_records to always store
the last search, something like the following:

-       if (device->tmp_records && req->records) {
+       if (device->tmp_records)
                sdp_list_free(device->tmp_records,
                                        (sdp_free_func_t) sdp_record_free);
-               device->tmp_records = req->records;
-               req->records = NULL;
-       }
+
+       device->tmp_records = req->records;
+       req->records = NULL;

        if (!req->profiles_added && !req->profiles_removed) {
                DBG("%s: No service update", device->path);
@@ -1522,7 +1522,7 @@ send_reply:

        if (dbus_message_is_method_call(req->msg, DEVICE_INTERFACE,
                                        "DiscoverServices"))
-               discover_services_reply(req, err, req->records);
+               discover_services_reply(req, err, device->tmp_records);
        else if (dbus_message_is_method_call(req->msg, ADAPTER_INTERFACE,
                                                "CreatePairedDevice"))
                create_device_reply(device, req);

What do you think?
The point of tmp_records is to avoid having to access the storage when
the records are still in memory (we just discovered them).

Regards,

-- 
Luiz Augusto von Dentz
Computer Engineer

Re: bug and possible patch for dbus DiscoverServices

[Tim Renouf]

On Thu, Jun 10, 2010 at 04:48:58PM +0300, Luiz Augusto von Dentz wrote:
> I would just rework it a bit to make the tmp_records to always store
> the last search, something like the following:
> 
> -       if (device->tmp_records && req->records) {
> +       if (device->tmp_records)
>                 sdp_list_free(device->tmp_records,
>                                         (sdp_free_func_t) sdp_record_free);
> -               device->tmp_records = req->records;
> -               req->records = NULL;
> -       }
> +
> +       device->tmp_records = req->records;
> +       req->records = NULL;
> 
>         if (!req->profiles_added && !req->profiles_removed) {
>                 DBG("%s: No service update", device->path);
> @@ -1522,7 +1522,7 @@ send_reply:
> 
>         if (dbus_message_is_method_call(req->msg, DEVICE_INTERFACE,
>                                         "DiscoverServices"))
> -               discover_services_reply(req, err, req->records);
> +               discover_services_reply(req, err, device->tmp_records);
>         else if (dbus_message_is_method_call(req->msg, ADAPTER_INTERFACE,
>                                                 "CreatePairedDevice"))
>                 create_device_reply(device, req);
> 
> What do you think?

Thanks, that looks good, I'll use that.

What is the procedure to get it included in future versions of BlueZ ?
Does someone sweep this list for patches to review and possibly
include ?

Thanks.

-tpr

Re: bug and possible patch for dbus DiscoverServices

[Luiz Augusto von Dentz]

Hi,

On Thu, Jun 10, 2010 at 11:20 PM, Tim Renouf <tpr.vger@botech.co.uk> wrote:
> On Thu, Jun 10, 2010 at 04:48:58PM +0300, Luiz Augusto von Dentz wrote:
>> I would just rework it a bit to make the tmp_records to always store
>> the last search, something like the following:
>>
>> -       if (device->tmp_records && req->records) {
>> +       if (device->tmp_records)
>>                 sdp_list_free(device->tmp_records,
>>                                         (sdp_free_func_t) sdp_record_free);
>> -               device->tmp_records = req->records;
>> -               req->records = NULL;
>> -       }
>> +
>> +       device->tmp_records = req->records;
>> +       req->records = NULL;
>>
>>         if (!req->profiles_added && !req->profiles_removed) {
>>                 DBG("%s: No service update", device->path);
>> @@ -1522,7 +1522,7 @@ send_reply:
>>
>>         if (dbus_message_is_method_call(req->msg, DEVICE_INTERFACE,
>>                                         "DiscoverServices"))
>> -               discover_services_reply(req, err, req->records);
>> +               discover_services_reply(req, err, device->tmp_records);
>>         else if (dbus_message_is_method_call(req->msg, ADAPTER_INTERFACE,
>>                                                 "CreatePairedDevice"))
>>                 create_device_reply(device, req);
>>
>> What do you think?
>
> Thanks, that looks good, I'll use that.
>
> What is the procedure to get it included in future versions of BlueZ ?
> Does someone sweep this list for patches to review and possibly
> include ?

Similar to kernel. git format-patch or git pull request, be sure that
it applies and compiles cleanly against git master.

-- 
Luiz Augusto von Dentz
Computer Engineer

Re: bug and possible patch for dbus DiscoverServices

[Luiz Augusto von Dentz]

[-- Attachment #1: Type: text/plain, Size: 2289 bytes --]

Hi,

On Fri, Jun 11, 2010 at 1:19 AM, Luiz Augusto von Dentz
<luiz.dentz@gmail.com> wrote:
> Hi,
>
> On Thu, Jun 10, 2010 at 11:20 PM, Tim Renouf <tpr.vger@botech.co.uk> wrote:
>> On Thu, Jun 10, 2010 at 04:48:58PM +0300, Luiz Augusto von Dentz wrote:
>>> I would just rework it a bit to make the tmp_records to always store
>>> the last search, something like the following:
>>>
>>> -       if (device->tmp_records && req->records) {
>>> +       if (device->tmp_records)
>>>                 sdp_list_free(device->tmp_records,
>>>                                         (sdp_free_func_t) sdp_record_free);
>>> -               device->tmp_records = req->records;
>>> -               req->records = NULL;
>>> -       }
>>> +
>>> +       device->tmp_records = req->records;
>>> +       req->records = NULL;
>>>
>>>         if (!req->profiles_added && !req->profiles_removed) {
>>>                 DBG("%s: No service update", device->path);
>>> @@ -1522,7 +1522,7 @@ send_reply:
>>>
>>>         if (dbus_message_is_method_call(req->msg, DEVICE_INTERFACE,
>>>                                         "DiscoverServices"))
>>> -               discover_services_reply(req, err, req->records);
>>> +               discover_services_reply(req, err, device->tmp_records);
>>>         else if (dbus_message_is_method_call(req->msg, ADAPTER_INTERFACE,
>>>                                                 "CreatePairedDevice"))
>>>                 create_device_reply(device, req);
>>>
>>> What do you think?
>>
>> Thanks, that looks good, I'll use that.
>>
>> What is the procedure to get it included in future versions of BlueZ ?
>> Does someone sweep this list for patches to review and possibly
>> include ?
>
> Similar to kernel. git format-patch or git pull request, be sure that
> it applies and compiles cleanly against git master.
>
> --
> Luiz Augusto von Dentz
> Computer Engineer
>

There were some problems with the changes I suggested previously,
basically  device_probe_drivers was freeing there records before we
return. The following patches should fix this issue and another one
with btd_device_get_record not looking into records storage when it is
missing on temporary cache.

-- 
Luiz Augusto von Dentz
Computer Engineer

[-- Attachment #2: 0001-Fix-DiscoverServices-not-retrieving-any-records.patch --]
[-- Type: text/x-patch, Size: 2007 bytes --]

From 25982ed3099f68de120ddf8b23086e3ac289ebd6 Mon Sep 17 00:00:00 2001
From: Luiz Augusto von Dentz <luiz.dentz-von@nokia.com>
Date: Fri, 11 Jun 2010 12:24:06 +0300
Subject: [PATCH 01/10] Fix DiscoverServices not retrieving any records

In the case that device->tmp_records was already set, req->records was
being set to NULL and so causes the empty array to be returned.

To fix that tmp_records now always has the latest discovered records and
it is used when repling to DiscoverServices.

Thanks to Tim Renouf <tpr.vger@botech.co.uk> for figuring out where was
the problem.
---
 src/device.c |   16 +++++-----------
 1 files changed, 5 insertions(+), 11 deletions(-)

diff --git a/src/device.c b/src/device.c
index 5584de9..0863a79 100644
--- a/src/device.c
+++ b/src/device.c
@@ -1267,12 +1267,6 @@ add_uuids:
 						g_strdup(list->data),
 						(GCompareFunc) strcasecmp);
 	}
-
-	if (device->tmp_records) {
-		sdp_list_free(device->tmp_records,
-				(sdp_free_func_t) sdp_record_free);
-		device->tmp_records = NULL;
-	}
 }
 
 static void device_remove_drivers(struct btd_device *device, GSList *uuids)
@@ -1493,12 +1487,12 @@ static void search_cb(sdp_list_t *recs, int err, gpointer user_data)
 
 	update_services(req, recs);
 
-	if (device->tmp_records && req->records) {
+	if (device->tmp_records)
 		sdp_list_free(device->tmp_records,
 					(sdp_free_func_t) sdp_record_free);
-		device->tmp_records = req->records;
-		req->records = NULL;
-	}
+
+	device->tmp_records = req->records;
+	req->records = NULL;
 
 	if (!req->profiles_added && !req->profiles_removed) {
 		DBG("%s: No service update", device->path);
@@ -1522,7 +1516,7 @@ send_reply:
 
 	if (dbus_message_is_method_call(req->msg, DEVICE_INTERFACE,
 					"DiscoverServices"))
-		discover_services_reply(req, err, req->records);
+		discover_services_reply(req, err, device->tmp_records);
 	else if (dbus_message_is_method_call(req->msg, ADAPTER_INTERFACE,
 						"CreatePairedDevice"))
 		create_device_reply(device, req);
-- 
1.7.0.4


[-- Attachment #3: 0002-Fix-not-looking-into-storage-when-a-record-is-not-fo.patch --]
[-- Type: text/x-patch, Size: 879 bytes --]

From 40afc7d29c1a56be67e7a117c22d6defb83f9e5e Mon Sep 17 00:00:00 2001
From: Luiz Augusto von Dentz <luiz.dentz-von@nokia.com>
Date: Fri, 11 Jun 2010 12:12:12 +0300
Subject: [PATCH 02/10] Fix not looking into storage when a record is not found in memory

---
 src/device.c |    9 +++++++--
 1 files changed, 7 insertions(+), 2 deletions(-)

diff --git a/src/device.c b/src/device.c
index 0863a79..6c085a3 100644
--- a/src/device.c
+++ b/src/device.c
@@ -2415,8 +2415,13 @@ const sdp_record_t *btd_device_get_record(struct btd_device *device,
 {
 	bdaddr_t src;
 
-	if (device->tmp_records)
-		return find_record_in_list(device->tmp_records, uuid);
+	if (device->tmp_records) {
+		const sdp_record_t *record;
+
+		record = find_record_in_list(device->tmp_records, uuid);
+		if (record != NULL)
+			return record;
+	}
 
 	adapter_get_address(device->adapter, &src);
 
-- 
1.7.0.4

Re: bug and possible patch for dbus DiscoverServices

[Johan Hedberg]

Hi Luiz,

On Fri, Jun 11, 2010, Luiz Augusto von Dentz wrote:
> There were some problems with the changes I suggested previously,
> basically  device_probe_drivers was freeing there records before we
> return. The following patches should fix this issue and another one
> with btd_device_get_record not looking into records storage when it is
> missing on temporary cache.

Both patches seem fine me (I hope you tested them too) and have now been
pushed upstream. Thanks.

Johan