BlueZ segfault on sdp resolving

DISCUSSION Manuel Naranjo 1 participant 1 message Jul 19, 2010 Bluetooth drivers

Share & tools

Manuel Naranjo

author

2010-07-19 15:22 UTC #0 lore raw

Hi guys,

I had been tracing a BlueZ segfault for a few months all ready, the other day I got an idea, I added some trace to the code just printed which line got called (then I discover |-finstrument-functions from gcc)

Anyway, I run the test two times, and both times it died the same way, here's the trace I got:

bluetoothd[3551]: ../bluez-4.66/src/device.c:device_free()
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_free() device_free(0x2cf17e8)
bluetoothd[3551]: ../bluez-4.66/src/security.c:check_pending_hci_req()
bluetoothd[3551]: ../bluez-4.66/src/security.c:io_security_event()
bluetoothd[3551]: ../bluez-4.66/src/security.c:inquiry_complete()
bluetoothd[3551]: ../bluez-4.66/src/manager.c:manager_find_adapter()
bluetoothd[3551]: ../bluez-4.66/src/manager.c:adapter_cmp()
bluetoothd[3551]: ../bluez-4.66/src/security.c:check_pending_hci_req()
bluetoothd[3551]: ../bluez-4.66/src/security.c:io_security_event()
bluetoothd[3551]: ../bluez-4.66/src/security.c:cmd_status()
bluetoothd[3551]: ../bluez-4.66/src/security.c:check_pending_hci_req()
bluetoothd[3551]: ../bluez-4.66/src/adapter.c:session_unref() session_unref(0x2c99a68): ref=0 bluetoothd[3551]: ../bluez-4.66/src/adapter.c:session_free() Discovery session 0x2c99a68 with :1.247 deactivated bluetoothd[3551]: ../bluez-4.66/src/adapter.c:session_remove() Stopping discovery
bluetoothd[3551]: Stopping discovery
bluetoothd[3551]: ../bluez-4.66/src/security.c:io_security_event()
bluetoothd[3551]: ../bluez-4.66/src/security.c:cmd_complete()
bluetoothd[3551]: ../bluez-4.66/src/security.c:inquiry_complete()
bluetoothd[3551]: ../bluez-4.66/src/manager.c:manager_find_adapter()
bluetoothd[3551]: ../bluez-4.66/src/manager.c:adapter_cmp()
bluetoothd[3551]: ../bluez-4.66/src/security.c:check_pending_hci_req()
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_address_cmp()
....
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_address_cmp()
bluetoothd[3551]: ../bluez-4.66/src/adapter.c:create_device() create_device(00:25:E7:98:AB:57) bluetoothd[3551]: ../bluez-4.66/src/adapter.c:adapter_create_device() adapter_create_device(00:25:E7:98:AB:57) bluetoothd[3551]: ../bluez-4.66/src/device.c:device_create()
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_create() Creating device /org/bluez/3551/hci0/dev_00_25_E7_98_AB_57 bluetoothd[3551]: ../bluez-4.66/src/device.c:btd_device_ref() btd_device_ref(0x2cf3938): ref=1 bluetoothd[3551]: ../bluez-4.66/src/device.c:device_get_path()
....
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_get_path()
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_browse()
bluetoothd[3551]: ../bluez-4.66/src/device.c:btd_device_ref() btd_device_ref(0x2cf3938): ref=2 bluetoothd[3551]: ../bluez-4.66/src/device.c:init_browse()
bluetoothd[3551]: ../bluez-4.66/src/glib-helper.c:bt_search_service()
bluetoothd[3551]: ../bluez-4.66/src/glib-helper.c:create_search_context()
bluetoothd[3551]: ../bluez-4.66/src/glib-helper.c:get_sdp_session() new (0x2ce2ce0)
bluetoothd[3551]: ../bluez-4.66/src/glib-helper.c:search_context_ref() (0x2cdd858) ref=1, src(0x2cdd858), dest(0x2cdd85e) bluetoothd[3551]: ../bluez-4.66/src/glib-helper.c:create_search_context() (0x2cdd858) bluetoothd[3551]: ../bluez-4.66/src/device.c:get_properties()
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_is_paired()
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_is_trusted()
bluetoothd[3551]: ../bluez-4.66/src/device.c:get_properties()
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_is_paired()
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_is_trusted()
bluetoothd[3551]: ../bluez-4.66/src/device.c:get_properties()
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_is_paired()
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_is_trusted()
bluetoothd[3551]: ../bluez-4.66/src/security.c:io_security_event()
bluetoothd[3551]: ../bluez-4.66/src/security.c:conn_complete()
bluetoothd[3551]: ../bluez-4.66/src/manager.c:manager_find_adapter()
bluetoothd[3551]: ../bluez-4.66/src/manager.c:adapter_cmp()
bluetoothd[3551]: ../bluez-4.66/src/adapter.c:adapter_get_device() adapter_get_device(00:25:E7:98:AB:57) bluetoothd[3551]: ../bluez-4.66/src/device.c:device_address_cmp()
....
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_address_cmp()
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_add_connection()
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_set_connected()
bluetoothd[3551]: ../bluez-4.66/src/security.c:update_lastused()
bluetoothd[3551]: ../bluez-4.66/src/security.c:hci_req_data_new()
bluetoothd[3551]: ../bluez-4.66/src/security.c:hci_req_queue_append()
bluetoothd[3551]: ../bluez-4.66/src/security.c:hci_req_find_by_devid()
bluetoothd[3551]: ../bluez-4.66/src/security.c:hci_req_queue_process()
bluetoothd[3551]: ../bluez-4.66/src/security.c:hci_req_find_by_devid()
bluetoothd[3551]: ../bluez-4.66/src/security.c:check_pending_hci_req()
bluetoothd[3551]: ../bluez-4.66/src/security.c:hci_req_find_by_devid()
bluetoothd[3551]: ../bluez-4.66/src/security.c:io_security_event()
bluetoothd[3551]: ../bluez-4.66/src/security.c:cmd_status()
bluetoothd[3551]: ../bluez-4.66/src/security.c:check_pending_hci_req()
bluetoothd[3551]: ../bluez-4.66/src/security.c:hci_req_find_by_devid()
bluetoothd[3551]: ../bluez-4.66/src/security.c:io_security_event()
bluetoothd[3551]: ../bluez-4.66/src/security.c:cmd_status()
bluetoothd[3551]: ../bluez-4.66/src/security.c:check_pending_hci_req()
bluetoothd[3551]: ../bluez-4.66/src/security.c:hci_req_find_by_devid()
bluetoothd[3551]: ../bluez-4.66/src/security.c:io_security_event()
bluetoothd[3551]: ../bluez-4.66/src/security.c:cmd_status()
bluetoothd[3551]: ../bluez-4.66/src/security.c:check_pending_hci_req()
bluetoothd[3551]: ../bluez-4.66/src/security.c:hci_req_find_by_devid()
bluetoothd[3551]: ../bluez-4.66/src/security.c:io_security_event()
bluetoothd[3551]: ../bluez-4.66/src/security.c:remote_features_information()
bluetoothd[3551]: ../bluez-4.66/src/security.c:get_bdaddr()
bluetoothd[3551]: ../bluez-4.66/src/security.c:check_pending_hci_req()
bluetoothd[3551]: ../bluez-4.66/src/security.c:hci_req_find_by_devid()
bluetoothd[3551]: Discovery session 0x2cd6958 with :1.247 activated
bluetoothd[3551]: ../bluez-4.66/src/adapter.c:session_ref() session_ref(0x2cd6958): ref=1 bluetoothd[3551]: ../bluez-4.66/src/security.c:io_security_event()
bluetoothd[3551]: ../bluez-4.66/src/security.c:remote_name_information()
bluetoothd[3551]: ../bluez-4.66/src/manager.c:manager_find_adapter()
bluetoothd[3551]: ../bluez-4.66/src/manager.c:adapter_cmp()
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_address_cmp()
....
bluetoothd[3551]: ../bluez-4.66/src/device.c:device_set_name()
bluetoothd[3551]: ../bluez-4.66/src/security.c:check_pending_hci_req()
bluetoothd[3551]: ../bluez-4.66/src/security.c:hci_req_find_by_devid()
bluetoothd[3551]: ../bluez-4.66/src/security.c:hci_req_queue_process()
bluetoothd[3551]: ../bluez-4.66/src/security.c:io_security_event()
bluetoothd[3551]: ../bluez-4.66/src/security.c:cmd_complete()
bluetoothd[3551]: ../bluez-4.66/src/security.c:start_inquiry()
bluetoothd[3551]: ../bluez-4.66/src/manager.c:manager_find_adapter()
bluetoothd[3551]: ../bluez-4.66/src/manager.c:adapter_cmp()
bluetoothd[3551]: ../bluez-4.66/src/security.c:check_pending_hci_req()
bluetoothd[3551]: ../bluez-4.66/src/glib-helper.c:connect_watch()
bluetoothd[3551]: ../bluez-4.66/src/device.c:browse_cb()
bluetoothd[3551]: ../bluez-4.66/src/device.c:search_cb()

Segmentation fault

If I read the code then I see device.c gets into search_cb directly from browse_cb in this piece /* If we have a valid response and req->search_uuid == 2, then L2CAP
* UUID & PNP searching was successful -- we are done */

 if (err < 0 || (req->search_uuid == 2 && req->records)) {
    if (err == -ECONNRESET && req->reconnect_attempt < 1) {
        req->search_uuid--;
        req->reconnect_attempt++;
    } else
        goto done;
    }

...
done:

        search_cb(recs, err, user_data);

Problem is that device has been released by when search_cb does:

if (err < 0) {
    error("%s: error updating services: %s (%d)",
          device->path, strerror(-err), -err);
    goto send_reply;
}

The solution we found a few months ago was to make a slight change in security.c, tell glib to do resources releasing with low priority:
chan = g_io_channel_unix_new(dev);
g_io_channel_set_close_on_unref(chan, TRUE);
io_data[hdev].watch_id = g_io_add_watch_full(chan, G_PRIORITY_LOW,

                        G_IO_IN | G_IO_NVAL | G_IO_HUP | G_IO_ERR,
                        io_security_event, di, (GDestroyNotify) g_free);

Still this is not enough. I think the problem is that the refcount is broken, we're forgeting to do btd_device_ref under some circustances?

I can mail the log if someone needs it.

Manuel
|