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
|