Skip to content

Fix failure to stop scans #507

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 3 commits into from
May 13, 2017
Merged

Fix failure to stop scans #507

merged 3 commits into from
May 13, 2017

Conversation

davidgyoung
Copy link
Member

This fixes a failure to stop BLE scanning in two scenarios caused by #491:

  1. When there is a nonzero between scan period.
  2. When the unbind() is called on the BeaconManager to stop the BeaconService.

This was reported here: http://stackoverflow.com/questions/43835705/how-to-properly-stop-scanning-beacon-using-android-beacon-library-altbeacon/43836157#43836157

Testing on Nexus 5X, showing logs after a call to
BeaconReferenceApplication.this.unbindService(connection);

Without change (note beacon packets are detected after service stops):

05-10 10:55:42.262 31353-31353/org.altbeacon.beaconreference E/BeaconService: onDestroy()
05-10 10:55:42.263 31353-31353/org.altbeacon.beaconreference D/BluetoothCrashResolver: stopped listening for BluetoothAdapter events
05-10 10:55:42.264 31353-31353/org.altbeacon.beaconreference D/BluetoothCrashResolver: Wrote 0 Bluetooth addresses
05-10 10:55:42.264 31353-31353/org.altbeacon.beaconreference I/BeaconService: onDestroy called.  stopping scanning
05-10 10:55:42.264 31353-31353/org.altbeacon.beaconreference D/CycledLeScanner: stop called
05-10 10:55:42.265 31353-31353/org.altbeacon.beaconreference D/CycledLeScanner: disabling scan
05-10 10:55:43.087 31353-31353/org.altbeacon.beaconreference D/CycledLeScannerForLollipop: got record
05-10 10:55:43.089 31353-32074/org.altbeacon.beaconreference D/BeaconParser: Ignoring pdu type 01
05-10 10:55:43.090 31353-32074/org.altbeacon.beaconreference D/BeaconParser: Processing pdu type FF: 02011a07ff4c0010020b00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 with startIndex: 5, endIndex: 10
05-10 10:55:43.090 31353-32074/org.altbeacon.beaconreference D/BeaconParser: This is not a matching Beacon advertisement. (Was expecting 02 15.  The bytes I see are: 02011a07ff4c0010020b00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

With change (note no beacon packets are detected after service stops):

05-10 10:52:43.784 26067-26067/org.altbeacon.beaconreference E/BeaconService: onDestroy()
05-10 10:52:43.785 26067-26067/org.altbeacon.beaconreference D/BluetoothCrashResolver: stopped listening for BluetoothAdapter events
05-10 10:52:43.786 26067-26067/org.altbeacon.beaconreference D/BluetoothCrashResolver: Wrote 0 Bluetooth addresses
05-10 10:52:43.787 26067-26067/org.altbeacon.beaconreference I/BeaconService: onDestroy called.  stopping scanning
05-10 10:52:43.787 26067-26067/org.altbeacon.beaconreference D/CycledLeScanner: stop called
05-10 10:52:43.787 26067-26067/org.altbeacon.beaconreference D/CycledLeScanner: disabling scan
05-10 10:52:43.789 26067-26067/org.altbeacon.beaconreference D/CycledLeScanner: forcing scanning to stop even for devices capable of multiple detections per cycle
05-10 10:52:43.791 26067-26122/org.altbeacon.beaconreference D/BluetoothAdapter: STATE_ON
05-10 10:52:44.756 26067-26067/org.altbeacon.beaconreference D/CycledLeScanner: Waiting to stop scan cycle for another 98 milliseconds
05-10 10:52:44.855 26067-26067/org.altbeacon.beaconreference D/CycledLeScanner: Done with scan cycle
05-10 10:52:44.856 26067-26067/org.altbeacon.beaconreference D/CycledLeScanner: Scanning disabled.  No ranging or monitoring regions are active.
05-10 10:52:44.856 26067-26067/org.altbeacon.beaconreference D/CycledLeScanner: cancel wakeup alarm: PendingIntent{4e22e7d: android.os.BinderProxy@261172}
05-10 10:52:44.862 26067-26067/org.altbeacon.beaconreference D/CycledLeScanner: Set a wakeup alarm to go off in 9223372036722221393 ms: PendingIntent{4e22e7d: android.os.BinderProxy@261172}

@@ -157,6 +157,8 @@ public void stop() {
mScanningEnabled = false;
if (mScanCyclerStarted) {
scanLeDevice(false);
LogManager.d(TAG, "forcing scanning to stop even for devices capable of multiple detections per cycle");
stopScan();
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why is stopScan() required here?

The call to scanLeDevice(false) will call it.

@cupakromer
Copy link
Contributor

cupakromer commented May 10, 2017

I think the issue is potentially in the deferScanIfNeeded logic and possibly in the leScanCallback instance logic. In some of the testing after unbinding I saw the CycledLeScannerForLollipop: Waiting to start full Bluetooth scan for another 10950 milliseconds message continue to appear before a final scan callback was made.

Toggling bind/unbind a few times seemed to also put it into a continuous scan state but there is too much noise here to get a cleaner debug log output at the moment.

@davidgyoung
Copy link
Member Author

davidgyoung commented May 10, 2017

So the original fix in this PR worked only by altering a race condition. The issue is that starting/stopping scanning is done on a dedicated Thread using a Handler, and when the CycledLeScanner is shut down, that thread may be terminated before it can stop the scan. Whether or not this succeeds is a race condition.

The revised solution is to allow the latest Runnable posted to the Handler to complete before shutting down the Thread.

Logs after update (Note that "Quitting scan thread" appears only after "Stopping LE scan on scan handler". This is now deterministic.):

05-10 15:50:00.538 26752-26752/org.altbeacon.beaconreference E/BeaconService: onDestroy()
05-10 15:50:00.539 26752-26752/org.altbeacon.beaconreference D/BluetoothCrashResolver: stopped listening for BluetoothAdapter events
05-10 15:50:00.543 26752-26752/org.altbeacon.beaconreference D/BluetoothCrashResolver: Wrote 0 Bluetooth addresses
05-10 15:50:00.544 26752-26752/org.altbeacon.beaconreference I/BeaconService: onDestroy called.  stopping scanning
05-10 15:50:00.544 26752-26752/org.altbeacon.beaconreference D/CycledLeScanner: stop called
05-10 15:50:00.544 26752-26752/org.altbeacon.beaconreference D/CycledLeScanner: disabling scan
05-10 15:50:00.545 26752-26752/org.altbeacon.beaconreference D/CycledLeScanner: Destroying
05-10 15:50:00.545 26752-26792/org.altbeacon.beaconreference D/CycledLeScannerForLollipop: Stopping LE scan on scan handler
05-10 15:50:00.547 26752-26792/org.altbeacon.beaconreference D/BluetoothAdapter: STATE_ON
05-10 15:50:00.550 26752-26752/org.altbeacon.beaconreference D/CycledLeScanner: Quitting scan thread

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants