Return-Path: MIME-Version: 1.0 In-Reply-To: References: Date: Tue, 24 Jun 2014 17:44:41 -0700 Message-ID: Subject: Re: BlueZ 5.19: BLE HoG device reconnect issues From: Petri Gynther To: Luiz Augusto von Dentz Cc: linux-bluetooth Content-Type: text/plain; charset=UTF-8 Sender: linux-bluetooth-owner@vger.kernel.org List-ID: Hi Luiz, On Tue, Jun 24, 2014 at 4:48 AM, Luiz Augusto von Dentz wrote: > Hi Petri, > > On Tue, Jun 24, 2014 at 3:37 AM, Petri Gynther wrote: >> With BlueZ 5.19 stack and BLE HoG remote controls, I'm seeing 3 >> different issues when trying to reconnect a previously paired BLE HoG >> remote control: >> >> Full log: >> [72241.012] bluez: bluetoothd[29263]: >> src/adapter.c:discovering_callback() hci0 type 6 discovering 1 >> [72251.269] bluez: bluetoothd[29263]: >> src/adapter.c:device_found_callback() hci0 addr 88:33:14:E6:XX:XX, >> rssi -81 flags 0x0000 eir_len 16 >> [72251.270] bluez: bluetoothd[29263]: src/device.c:device_set_legacy() legacy 0 >> [72251.270] bluez: bluetoothd[29263]: src/adapter.c:stop_passive_scanning() >> [72251.270] bluez: bluetoothd[29263]: >> src/adapter.c:discovering_callback() hci0 type 6 discovering 0 >> [72251.270] bluez: bluetoothd[29263]: >> src/adapter.c:trigger_passive_scanning() >> [72251.270] bluez: bluetoothd[29263]: >> src/adapter.c:stop_passive_scanning_complete() status 0x0b (Rejected) >> [72251.270] bluez: bluetoothd[29263]: Stopping passive scanning failed: Rejected >> [72255.015] bluez: bluetoothd[29263]: >> src/adapter.c:passive_scanning_complete() status 0x00 >> [72255.015] bluez: bluetoothd[29263]: >> src/adapter.c:discovering_callback() hci0 type 6 discovering 1 >> [72258.550] bluez: bluetoothd[29263]: >> src/adapter.c:device_found_callback() hci0 addr 88:33:14:E6:XX:XX, >> rssi -76 flags 0x0000 eir_len 16 >> [72258.551] bluez: bluetoothd[29263]: src/device.c:device_set_legacy() legacy 0 >> [72258.551] bluez: bluetoothd[29263]: src/adapter.c:stop_passive_scanning() >> [72258.551] bluez: bluetoothd[29263]: >> src/adapter.c:device_found_callback() hci0 addr CB:36:E5:F5:XX:XX, >> rssi -82 flags 0x0000 eir_len 36 >> [72258.558] bluez: bluetoothd[29263]: >> src/adapter.c:stop_passive_scanning_complete() status 0x00 (Success) >> [72258.558] bluez: bluetoothd[29263]: src/device.c:device_connect_le() >> Connection attempt to: 88:33:14:E6:XX:XX >> [72258.558] bluez: bluetoothd[29263]: >> src/adapter.c:discovering_callback() hci0 type 6 discovering 0 >> [72278.629] bluez: bluetoothd[29263]: >> src/adapter.c:connect_failed_callback() hci0 88:33:14:E6:XX:XX status >> 2 >> [72278.629] bluez: bluetoothd[29263]: plugins/policy.c:conn_fail_cb() status 2 >> [72278.629] bluez: bluetoothd[29263]: >> src/adapter.c:bonding_attempt_complete() hci0 bdaddr 88:33:14:E6:XX:XX >> type 1 status 0x2 >> [72278.629] bluez: bluetoothd[29263]: >> src/device.c:device_bonding_complete() bonding (nil) status 0x02 >> [72278.629] bluez: bluetoothd[29263]: >> src/device.c:device_bonding_failed() status 2 >> [72278.629] bluez: bluetoothd[29263]: src/adapter.c:resume_discovery() >> [72278.629] bluez: bluetoothd[29263]: src/device.c:att_connect_cb() >> connect error: Transport endpoint is not connected (134) >> [72278.629] bluez: bluetoothd[29263]: src/device.c:att_error_cb() >> Enabling automatic connections >> [72278.630] bluez: bluetoothd[29263]: >> src/adapter.c:adapter_connect_list_add() ignoring already added device >> /org/bluez/hci0/dev_88_33_14_E6_XX_XX >> >> Issues 1 and 2: >> [72251.270] bluez: bluetoothd[29263]: src/adapter.c:stop_passive_scanning() >> [72251.270] bluez: bluetoothd[29263]: >> src/adapter.c:discovering_callback() hci0 type 6 discovering 0 >> [72251.270] bluez: bluetoothd[29263]: >> src/adapter.c:trigger_passive_scanning() >> [72251.270] bluez: bluetoothd[29263]: >> src/adapter.c:stop_passive_scanning_complete() status 0x0b (Rejected) >> [72251.270] bluez: bluetoothd[29263]: Stopping passive scanning failed: Rejected >> >> 1) device_found_callback() -> update_found_devices() -> >> stop_passive_scanning() needs to stop passive scanning because BlueZ >> is about to connect to previously paired BLE device. But, >> discovering_callback() doesn't take the pending BLE connection into >> account and still calls trigger_passive_scanning() when it shouldn't. >> >> 2) stop_passive_scanning() can actually fail because passive scanning >> was already stopped in kernel due to passive scan timer expiring. But, >> stop_passive_scanning_complete() handles the Reject case as an error >> and never attempts the pending BLE connection in that case. >> >> Issue 3: >> [72278.629] bluez: bluetoothd[29263]: src/device.c:att_connect_cb() >> connect error: Transport endpoint is not connected (134) >> [72278.629] bluez: bluetoothd[29263]: src/device.c:att_error_cb() >> Enabling automatic connections >> [72278.630] bluez: bluetoothd[29263]: >> src/adapter.c:adapter_connect_list_add() ignoring already added device >> /org/bluez/hci0/dev_88_33_14_E6_XX_XX >> >> If there is an error connecting to BLE device, att_error_cb() adds the >> failed device back to adapter connect list, but if it is already >> there, no code actually calls trigger_passive_scanning(). So, from >> this point on, no BLE device is ever going to reconnect back to BlueZ, >> because the passive scanning is disabled and nothing will re-enable >> it. >> >> >> Here is my proposed diff for fixing these issues: >> @@ -1228,7 +1228,7 @@ static void >> stop_passive_scanning_complete(uint8_t status, uint16_t length, >> dev = adapter->connect_le; >> adapter->connect_le = NULL; >> >> - if (status != MGMT_STATUS_SUCCESS) { >> + if (status != MGMT_STATUS_SUCCESS && status != MGMT_STATUS_REJECTED) { >> error("Stopping passive scanning failed: %s", >> mgmt_errstr(status)); >> return; >> >> @@ -1500,6 +1500,10 @@ static void discovering_callback(uint16_t >> index, uint16_t length, >> * passive scanning attempt. >> */ >> if (!adapter->discovery_list) { >> + if (adapter->connect_le) { >> + DBG("LE connect pending, skip >> trigger_passive_scanning"); >> + return; >> + } >> trigger_passive_scanning(adapter); >> return; >> } >> >> @@ -3675,6 +3676,7 @@ static void att_error_cb(const GError *gerr, >> gpointer user_data) >> if (device_get_auto_connect(device)) { >> DBG("Enabling automatic connections"); >> adapter_connect_list_add(device->adapter, device); >> + trigger_passive_scanning(device->adapter); >> } >> } >> >> >> Let me know if this looks good. I'll then e-mail proper patch for review. > > Haven't tested it yet but has this code been changed recently? I > wonder how does 5.20 behave in this regard since I did change some > parts of uHID implementation but not the scanning logic. Anyway in > future we will be changing the scanning logic and let the kernel do > the scanning (real passive scanning and perhaps whitelist) for us but > in the meantime it is good to have this fixed if still reproducible > with 5.20. I just tested with BlueZ 5.20, and I'm seeing the same 3 issues. I'll e-mail patches shortly. I'll fix issue #3 inside adapter_connect_list_add(), instead of modifying att_error_cb(). -- Petri > > > -- > Luiz Augusto von Dentz