New issue
Advanced search Search tips
Note: Color blocks (like █ or █) mean that a user may not be available. Tooltip shows the reason.

Issue 843943 link

Starred by 3 users
Status: Duplicate
Owner:
josephsih@chromium.org
Closed: May 2018
Cc:
█ jlklein@chromium.org
snanda@chromium.org
█ sonnysasaka@chromium.org
█ mcchou@chromium.org
khorimoto@chromium.org
█ jhawkins@chromium.org
hansberry@chromium.org
█ dwmclary@chromium.org
█ rjahagir@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug


Show other hotlists

Hotlists containing this issue:
Hotlist-1


Sign in to add a comment

Minnie: Unrecoverable error starting recovery due to "stop discovery in progress"

Project Member Reported by josephsih@chromium.org, May 17 2018 
Long-running tether scan test run by rjahagir (Ruchi) on Minnie v10655.0.0.

At first, everything works as expected. Eventually, we hit the following error in ui.LATEST:
[1358:1358:0515/170158.853709:ERROR:device_event_log_impl.cc(159)] [17:01:58.853] Bluetooth: bluetooth_adapter_bluez.cc:1589 /org/bluez/hci0: Failed to start discovery: org.bluez.Error.InProgress: Operation already in progress
[1358:1358:0515/170158.855344:ERROR:ble_scanner_impl.cc(265)] Error starting discovery session. Initialization failed.
(failure continued...)

At this point, nothing else succeeds.

Please refer to Ruchi's log: https://drive.google.com/open?id=1DKj4jSye4nQJgjI4FqC6gXyYlKyi1uEF


Also refer to a related issue 842332: Minnie: Unrecoverable error stopping recovery

Comment 1 by josephsih@chromium.org, May 21 2018 

$ grep "Failed to start" ui.LATEST
[1358:1358:0515/170158.853709:ERROR:device_event_log_impl.cc(159)[17:01:58.853] Bluetooth: bluetooth_adapter_bluez.cc:1589 /org/bluez/hci0: Failed to start discovery: org.bluez.Error.InProgress: Operation already in progress
[1358:1358:0515/170205.719146:ERROR:device_event_log_impl.cc(159)[17:02:05.719] Bluetooth: bluetooth_adapter_bluez.cc:1589 /org/bluez/hci0: Failed to start discovery: org.bluez.Error.InProgress: Operation already in progress
[1358:1358:0515/170212.534553:ERROR:device_event_log_impl.cc(159)[17:02:12.534] Bluetooth: bluetooth_adapter_bluez.cc:1589 /org/bluez/hci0: Failed to start discovery: org.bluez.Error.InProgress: Operation already in progress
... and more such error logs continuously ...

Looking at the messages log for the timestamp of the first such error:
2018-05-15T17:01:58.852162-07:00 DEBUG bluetoothd[2356]: src/adapter.c:try_sync_method() Try 5 of method StartDiscovery
2018-05-15T17:01:58.852187-07:00 DEBUG bluetoothd[2356]: src/adapter.c:start_discovery() sender :1.9
2018-05-15T17:01:58.852202-07:00 DEBUG bluetoothd[2356]:src/adapter.c:start_discovery() error: stop discovery in progress

Looking up the previous stop discovery method:
2018-05-15T17:01:23.784614-07:00 DEBUG bluetoothd[2356]: src/adapter.c:try_sync_method() Try 0 of method StopDiscovery
2018-05-15T17:01:23.784641-07:00 DEBUG bluetoothd[2356]: src/adapter.c:stop_discovery() sender :1.9

## Observation: 
It did not call mgmt.c:stop_discovery(). The stop_discovery() in bluetoothd was never completed which prevented start discovery accordingly.


Another weird thing:
$ grep "in progress" messages
2018-05-15T17:33:08.303718-07:00 DEBUG bluetoothd[2356]: src/adapter.c:start_discovery() error: stop discovery in progress
2018-05-15T17:33:08.965892-07:00 DEBUG bluetoothd[2356]: src/adapter.c:start_discovery() error: stop discovery in progress
2018-05-15T17:33:09.166508-07:00 DEBUG bluetoothd[2356]: src/adapter.c:start_discovery() error: stop discovery in progress
... and more such errors continuously ...

Comment 2 by snanda@chromium.org, May 21 2018

Labels: -Pri-1 Pri-2
I'm dropping this to P2. Lets continue testing & investigating but if you have other P1s on your plate, please prioritize accordingly.

Comment 3 by josephsih@chromium.org, May 22 2018 

Thanks, Sameer, for dropping it to Pri-2.

Comment 4 Deleted

Comment 5 by josephsih@chromium.org, May 24 2018

Summary: Minnie: Unrecoverable error starting recovery due to "stop discovery in progress" (was: Minnie: Unrecoverable error starting recovery)

Comment 6 by josephsih@chromium.org, May 24 2018

Mergedinto: 777543
Status: Duplicate (was: Assigned)
Although the error shown in ui.LATEST was "Failed to start discovery", the actual error lied in the kernel as 

2018-05-15T17:01:52.644753-07:00 DEBUG bluetoothd[2356]: src/adapter.c:start_discovery() error: stop discovery in progress

It is also a "stop discovery" error, and is a duplicate of issue 777543.
►

Sign in to add a comment