Open shriharsha-bhagwat opened 5 years ago
Thanks for this report. I have not seen this before.
I will attempt to reproduce with the reference app with a foreground service enabled on a Nokia 6.1 plus with Android 9.
I'd be curious to know if you see anything special in LogCat (from the OS or from app logs) when the scans stops. I understand this is difficult to capture this if it takes 12 hours for it to happen.
I captured the following after approx 28 minutes scanning in the background (and with the screen off) with the reference app and foreground service enabled:
01-04 17:18:46.383 2145 2145 D CycledLeScannerForLollipop: starting non-filtered scan in SCAN_MODE_LOW_LATENCY
01-04 17:18:46.384 2145 2145 D CycledLeScanner: Waiting to stop scan cycle for another 1100 milliseconds
01-04 17:18:46.384 2145 2145 D CycledLeScanner: Scan started
01-04 17:18:46.384 2145 2145 D IntentHandler: got ranging data
01-04 17:18:46.384 2145 2145 D BeaconReferenceApp: Ranged beacons with count: 1
01-04 17:18:46.384 2145 2145 D BeaconReferenceApp: Ranged beacons with count: 1
01-04 17:18:46.384 2145 2145 D RangingActivity: didRangeBeaconsInRegion called with beacon count: 1
01-04 17:18:46.384 2145 2145 D CurveFittedDistanceCalculator: calculating distance based on mRssi of -49.95789473684211 and txPower of -58
01-04 17:18:46.384 2145 2145 D CurveFittedDistanceCalculator: avg mRssi: -49.95789473684211 distance: 0.22478190645256937
01-04 17:18:46.387 2145 2188 D BluetoothAdapter: isLeEnabled(): ON
01-04 17:18:46.397 2145 2160 D BluetoothLeScanner: onScannerRegistered() - status=0 scannerId=7 mScannerId=0
01-04 17:18:46.474 2145 2160 W Binder : Binder call failed.
01-04 17:18:46.474 2145 2160 W Binder : java.lang.SecurityException: Need ACCESS_COARSE_LOCATION or ACCESS_FINE_LOCATION permission to get scan results
01-04 17:18:46.474 2145 2160 W Binder : at android.os.Parcel.createException(Parcel.java:1950)
01-04 17:18:46.474 2145 2160 W Binder : at android.os.Parcel.readException(Parcel.java:1918)
01-04 17:18:46.474 2145 2160 W Binder : at android.os.Parcel.readException(Parcel.java:1868)
01-04 17:18:46.474 2145 2160 W Binder : at android.bluetooth.IBluetoothGatt$Stub$Proxy.startScan(IBluetoothGatt.java:947)
01-04 17:18:46.474 2145 2160 W Binder : at android.bluetooth.le.BluetoothLeScanner$BleScanCallbackWrapper.onScannerRegistered(BluetoothLeScanner.java:460)
01-04 17:18:46.474 2145 2160 W Binder : at android.bluetooth.le.IScannerCallback$Stub.onTransact(IScannerCallback.java:57)
01-04 17:18:46.474 2145 2160 W Binder : at android.os.Binder.execTransact(Binder.java:731)
01-04 17:18:46.524 2145 2145 D IntentHandler: got ranging data
01-04 17:18:46.524 2145 2145 D BeaconReferenceApp: Ranged beacons with count: 1
01-04 17:18:46.525 2145 2145 D BeaconReferenceApp: Ranged beacons with count: 1
01-04 17:18:46.525 2145 2145 D RangingActivity: didRangeBeaconsInRegion called with beacon count: 1
01-04 17:18:46.531 2145 2159 I beaconreferenc: Background concurrent copying GC freed 19587(1211KB) AllocSpace objects, 12(7MB) LOS objects, 50% free, 7MB/15MB, paused 4.473ms total 115.825ms
01-04 17:18:47.386 2145 2145 D CycledLeScanner: Waiting to stop scan cycle for another 98 milliseconds
01-04 17:18:47.485 2145 2145 D CycledLeScanner: Done with scan cycle
01-04 17:18:47.485 2145 2145 D ScanHelper: Beacon simulator not enabled
01-04 17:18:47.486 2145 2145 D ScanHelper: Calling ranging callback
01-04 17:18:47.487 2145 2145 D Callback: attempting callback via local broadcast intent: org.altbeacon.beacon.range_notification
01-04 17:18:47.487 2145 2145 D ScanHelper: Calling ranging callback
01-04 17:18:47.488 2145 2145 D Callback: attempting callback via local broadcast intent: org.altbeacon.beacon.range_notification
01-04 17:18:47.491 2145 2145 D CycledLeScanner: Not stopping scanning. Device capable of multiple indistinct detections per scan.
01-04 17:18:47.491 2145 2145 D CycledLeScanner: starting a new scan cycle
01-04 17:18:47.491 2145 2145 D CycledLeScanner: We are already scanning and have been for 1116 millis
01-04 17:18:47.491 2145 2145 D CycledLeScanner: Waiting to stop scan cycle for another 1100 milliseconds
01-04 17:18:47.491 2145 2145 D CycledLeScanner: Scan started
01-04 17:18:47.491 2145 2145 D IntentHandler: got ranging data
01-04 17:18:47.492 2145 2145 D BeaconReferenceApp: Ranged beacons with count: 0
01-04 17:18:47.492 2145 2145 D BeaconReferenceApp: Ranged beacons with count: 0
After I saw the above, I illuminated the screen and it still detected zero beacons. I then brought the app to the foreground, but it still detected zero beacons.
Killing and restarting the app caused it to resume detecting beacons normally.
I'm not sure if this is a bug in Android 9.0 (or the Nokia ROM) or intended behavior. I am going to try to reproduce again and see if when the condition occurs, if settings indicates the app has been granted location permission or not.
Right before the above SecurityException happened, the library tried to stop and restart the scan per these log lines:
01-04 17:18:46.365 2145 2145 D CycledLeScanner: The next scan cycle would go over the Android N max duration.
01-04 17:18:46.365 2145 2145 D CycledLeScanner: Stopping scan to prevent Android N scan timeout.
This is a library feature that will stop a constant scan after 30 minutes if it is on Android N+ and then restart it. But it seems in this case the new scan is blocked with that SecuirtyException.
Reproduced the problem a second time -- it takes exactly 30 minutes to get this in the background.
Then when I go to Settings -> Apps -> BeaconReference -> App permissions
I can confirm that it says it has Location permission.
Another test to see if scans are always blocked from starting in the background for foreground service apps on this device:
adb shell monkey -p org.altbeacon.beaconreference -c android.intent.category.LAUNCHER 1
This proves that the exception does not always happen for starting scans in the background with foreground services.
Thanks for trying out to reproduce the issue. Yes it takes 30 minutes atleast to reproduce this issue. The code actually works good in Oreo (Tried in Pixel). But not sure why it does not behave the same in Pie (Tried in Nokia).
Is there any solution which can be tried out to solve this issue? Please let me know.
I would suggest testing a betweenScanPeriod of 100ms to see if this alters the behavior
I tried this and still the same. It did not work for me. Not sure how to proceed.
beaconManager.setBackgroundBetweenScanPeriod(100);
beaconManager.setForegroundBetweenScanPeriod(100);
Discoveries from a few further tests:
Periodically turning off scanning with a between scan period of 100ms (as @android-bash noted above) does not affect this issue. When the next scan is started more than 5 minutes after the app is in the background, it fails with the same SecurityException described above.
Even if the app does not scan at all for the first five minutes of being in the background, as soon as it does start scanning (after being in the background > 5 minutes) it will get this exception. I tested this by setting beaconManager.setForegroundBetweenScanPeriod(6 60 1000); then launching the app and putting it to the background. As soon as the next scan started (6 minutes later) it was blocked with the same SecurityException.
If I change to targetSdkVersion 27
instead of targetSdkVersion 28
in build.gradle, this SecurityException goes away. @android-bash, can you confirm this?
I also verified that if you do not use foreground service scanning with the library and instead use the default job scheduler running scans every ~15 minutes, the scans do succeed without a SecurityException. So the default behavior of the library without a foreground service works as expected with Android 9
So this appears to be that:
Apps targeting SDK 28 with a foreground service starting BLE scans after > 5 minutes of running in the background on Android 9 will get a SecurityException trying to start a BLE scan. (Only seen so far on Nokia Android Pie ROMs)
It is unclear if this is an intended behavior of Android 9 or if it is a bug in AOSP or the Nokia ROMs.
While Nokia Android Pie ROMs are part of AndroidOne, so supposedly stock AOSP, if anybody has a Pixel device with Android 9.0 test this with, I'd love to get a confirmation of whether the problem exists there.
I can verify in Google pixel today. And also if i run scans every 25 minutes using AlarmManager or Job Scheduler, what will be the behaviour? Will scans run continuously or will there be gaps in scan results as scheduler execution might be varied?
AlarmManager cannot run on Android 8+ in the background. JobScheduler can run for up to 10 minutes every ~15 minutes but there will be gaps for sure, as the 15 minute cycle can vary by +/-10 min. So neither of these will allow constant scanning.
Please let me know what you see with a foreground service with constant scanning on a Pixel with Android 9.
Sure thank you. I will let you know by EOD.
I tried the same with Google Pixel running Android 9 and it works completely fine in it.
How can i proceed to make this work in Nokia 6.1 Version 9 as well? Any suggestions?
I tried the same with a OnePlus 5T running Android 9.0 and it works fine too. targetSdkVersion is 28, using a foreground service, scanning is still running after 45+ minutes with app in background, and screen off
This appears to be a bug in Nokia Android 9.0 ROMs. The same behavior does not happen on a tested Google Pixel 9.0 ROM nor on a tested OnePlus 5T Android 9.0 ROM. Further, this is not a documented change in Android 9.0.
I have confirmed you can get around this by changing to targetSdkVersion 27
instead of targetSdkVersion 28
.
This was logged with Nokia here and in an email to support. Unfortunately, I am told by their support they do not have a public bug reporting system.
Yeah seems like bug in Nokia. Will try to get around it as you have said and will get back to you. @davidgyoung Thank you for all your inputs.
I tried with targetSdkVersion 27 in Nokia. I see scanning gaps when phone goes to background.
@android-bash, I received a reply from Nokia support, and they suggested doing the following:
I performed the steps above to humor them, not expecting them to help. To my surprise, however, after performing the above I can no longer reproduce the problem on my Nokia 6.1 Plus 9.0. This won't do anything to fix such problems with the wider user base (good luck getting all Nokia users to do this) but it suggests the problem has something to do with phone state.
Can you please try the above and see if you can confirm the same?
For what it's worth, after the problem went away, I re-enabled bluetooth scanning per the first step, rebooted, and confirmed I was still able to scan for more than 5 minutes with the screen off with a foreground service.
Wow something to try out. I will also try this and get back to you. Thanks @davidgyoung
@android-bash, please do try the steps above when you have a chance and let me know the result, I'd like to get confirmation if this helps from more than one affected device.
@davidgyoung Sorry i did not have access to Nokia device from past few days. Tomorrow i will try this out and get back to you.
Wow, I just read this, and really all I can say is wow.
Since it looks like a security issue, have you tried to query the Location (and potentially phone state) permissions again during the process in which you stop and restart the scanning? I wonder if that would have any affect? We all know that it probably shouldn't... but I'd still be tempted to see if it makes a difference. Maybe Nokia is putting some kind of timeout on the permission duration? I've known Nokia to have different interpretations of specs before, and would not put it past them.
Update: I set up my app to do periodic permissions checks to see it it would help, but I still got the same error about the binder call failing.
01-17 14:53:58.999 29921-29957/org.aph.avigenie.debug W/Binder: Binder call failed.
java.lang.SecurityException: Need ACCESS_COARSE_LOCATION or ACCESS_FINE_LOCATION permission to get scan results
at android.os.Parcel.createException(Parcel.java:1950)
at android.os.Parcel.readException(Parcel.java:1918)
at android.os.Parcel.readException(Parcel.java:1868)
at android.bluetooth.IBluetoothGatt$Stub$Proxy.startScan(IBluetoothGatt.java:947)
at android.bluetooth.le.BluetoothLeScanner$BleScanCallbackWrapper.onScannerRegistered(BluetoothLeScanner.java:460)
at android.bluetooth.le.IScannerCallback$Stub.onTransact(IScannerCallback.java:57)
at android.os.Binder.execTransact(Binder.java:731)
I have not tried editing the library, I think it still would have failed.
Question: If I use the steps above to "fix" the issue, is there a way to get the issue back again?
Question 2 Is there a way to do those steps programmatically in my app?
@joew46167, I did check permissions when the phone was in this state of blocking scans, and the OS reported then as being granted. Based on my comment from Nokia support, I did see that doing their Bluetooth reset procedure made the problem go away. I would like somebody else to repeat this to confirm, but if it is confirmed this suggests a bug triggered by stateful condition and not intended behavior.
And to answer your other questions, I have not been able to reproduce the problem since the reset procedure. I highly doubt there is a programmatic way to do the same.
Thanks for the information David.
My app is designed for blind people to use. That procedure would be difficult for them to follow. So if I can’t reproduce the issue after running the procedure, I’d rather not run it until I exhaust all other options. I’d like to continue testing. So for that reason I’m hesitant to run the procedure at this time. The rest of my team concurs.
Tomorrow I’ll have a Pixel 2 to test with. I hope that you’re correct and it works better.
Again, thanks for your help.
Joe
David
I don't have access to the Nokia phone today, so testing with that will have to until Monday.
I may not have access to the Pixel 2 ether. :(
I'm testing today with a Samsung Galaxy Note 9 with Oreo 8.1 API 27. As soon as the screen gets turned off the scanning stops immediately. When I turn the screen back on it starts right up. But many blind people leave the screen off - no need to have that battery draw. I checked the battery save settings, and it looks like battery save setting is not the issue.
Update: Galaxy Note 9 works well with 2.15.4
I'm also testing with a Samsung Galaxy Nexus with Marshmallow 6.0.1 API 23. So far that looks to run wonderfully.
@joew46167, let's keep this issue focussed on the Nokia Pie / Nokia Android 9 scanning problem. For info on Samsung 8.1 scanning, please see #769. The problem you described with that was fixed in 2.15.3.
@davidgyoung A couple of times in this thread it shows a log where the issue is that the app no longer has location permission. Does this bubble up to the app in any manner? I haven't really figured out how to see the error condition at the app level. (Sorry if I'm missing something obvious here.)
The error appears in LogCat, but there is no exception received at the app level. Scan results just stop. And again, even if you programmatically check to see if the COARSE_LOCATION permission has been granted, the OS tells you it has.
@davidgyoung have you done any testing on your Nokia phone since you showed that procedure? Does the solution still seem to be persistent - in that after performing it just the once everything still works ok?
@joew46167, yes, I have done testing since then, and the issue described in this thread is now gone. It disappeared right after performing the bluetooth reset steps suggested by Nokia and has not returned since. That's good and bad news -- bad because I can no longer use my device to investigate automated solutions to the problem.
@davidgyoung That's why I'm hesitant to do it. I'm stubborn and not yet ready to stop trying to find a better way.
An interesting thing - before I found your library, I created my own. It worked pretty well, but had some stability issues. I was hoping that moving to the beacon would help with those stability issues. so I started the migration.
I didn't have the Nokia phone yet when I started the process. ad I had been doing most of my testing with the "keep screen on while charging" option turned on. and I have the phone connected for logging, so it was always charging. So it took a while before I ever saw the issue.
Now I've gone back for a bit to using my old code, just to see what happens. I had also found by trial and error that I needed to stop and restart scanning periodically. The bad news in my old code is that after the screen is off, the scans stop, and I get the same COARSE_LOCATION error message. the good news in my old phone, though, is that when I turn the screen back on it appears to recover, although I admittedly need to do some longer duration testing yet. I wonder if maybe I inadvertently stumbled on a way around this? I'll let you know more tomorrow.
Lastly, if you were to do a factory reset, would you get the issue back so you could resume investigation? I'm guessing you've already tried that.
I did not try a factory reset. I suspect however that a factory reset would have also cleared the error condition in a way similar to resetting the Bluetooth settings.
I say this because the error condition happened right after the Android Pie upgrade. I suspect the upgrade process is at fault, basically retaining Bluetooth state data from Android 8 that does not work properly with Android Pie on Nokia phones.
Juat a theory.
@davidgyoung Hate to say it, because I hate disagreeing with smarter people, but I think your theory ay be wrong. And here's why.
I got my unlocked Nokia 7.1 in mid December. During the setup procedure it did an upgrade to Pie, So I've never done anything with this phone that wasn't done on Pie, and I'm still seeing the issue, I don't think there could have been any data on my phone to retain from Oreo. Granted I could be wrong. But my gut feeling is after a factory reset and getting to Pie again, even without running anything Bluetooth pre-Pie you'll see the issue.
Just my feeling.
@joew46167 what you suggest is certainly possible, although I think a migration problem could happen even with very limited Bluetooth state data. If I do a factory reset I will let you know what I see, but as I am using it as my primary device, it is not a quick test to do. Please let me know the results if you try the same.
@davidgyoung Is there any way to accelerate testing? That half an hour before the issue occurs is tough!
Hello @davidgyoung
I never did do the ugly "fix" procedure that you got from Nokia. However yesterday I did do a factory reset of the phone, and the issue is still present. IDK if that is useful information for you.
I have same issue. Using library in foreground service and it works like a charm some time and then it stops scan for a while and start again. I have same behaviour on 3 different devices (Moto Z Play 8.0, Samsung A7 8.0 and Nokia8 9.0). Only thing i get from log is:
01-28 14:01:38.099 5651-6767/nsoft.navi.claim.claimerwmp D/BluetoothLeScanner: onScannerRegistered() - status=0 scannerId=5 mScannerId=0 01-28 14:01:39.204 5651-7693/nsoft.navi.claim.claimerwmp D/BluetoothAdapter: isLeEnabled(): ON 01-28 14:01:42.217 5651-5651/nsoft.navi.claim.claimerwmp I/ScanJob: Scan job runtime expired: org.altbeacon.beacon.service.ScanJob@de707cf 01-28 14:01:42.224 5651-7693/nsoft.navi.claim.claimerwmp D/BluetoothAdapter: isLeEnabled(): ON 01-28 14:01:42.225 5651-7693/nsoft.navi.claim.claimerwmp D/BluetoothLeScanner: could not find callback wrapper 01-28 14:01:42.587 5651-5651/nsoft.navi.claim.claimerwmp I/ScanJob: Using immediateScanJobId from manifest: 208352939 01-28 14:01:42.596 5651-5651/nsoft.navi.claim.claimerwmp I/ScanJob: Using periodicScanJobId from manifest: 208352940 01-28 14:01:42.596 5651-5651/nsoft.navi.claim.claimerwmp W/JobInfo: Requested interval +5m0s0ms for job 208352940 is too small; raising to +15m0s0ms Requested flex 0 for job 208352940 is too small; raising to +5m0s0ms 01-28 14:01:42.831 5651-5651/nsoft.navi.claim.claimerwmp I/CycledLeScanner: Using Android O scanner 01-28 14:01:42.838 5651-5651/nsoft.navi.claim.claimerwmp I/ScanJob: Using immediateScanJobId from manifest: 208352939 Running immediate scan job: instance is org.altbeacon.beacon.service.ScanJob@2c0300 scanJob version 2.15 is starting up on the main process
Any suggestion on how i could fix this?
Thanks
@cobainmo
For the Nokia phone I'm still searching for a good way around this. I'm starting to lean toward detect and report.
I'm a little surprised by the Moto Z, but it is what I've had the least testing time with.
As for the Samsung, as David mentioned earlier, you can see #769 - which basically says to make sure you're using the latest version of the library.
Lastly, David has asked that we limit this issue to Nokia phones.
@joew46167 Thanks. i was using 2.15 instead of 2.15.2. Will try that.
Since Nokia was accused for having too aggressive background task manager (package: com.evenwell.powersaving.g3) that kills background activity of some apps after 20 minutes , maybe it can be one of the reasons for lib issue.
@cobainmo I even had trouble with 2.15.2. I went all the way to 2.15.4
@cobainmo, any issues with Samsung, please comment on #769. The core issue may be entirely different on each manufacturer phone. Feel free to open a new issue for the Moto Z, but please make sure any logs you post are for the specific device associated with the issue. It is also very helpful if you include system-level logs in your excerpts (not just log lines originating from your app process) because system level logs from the bluetooth stack often give clues to what is going on. An example is the Nokia system log line about permissions mentioned above.
Finally, please keep this issue focussed on Nokia so we don't confuse ourselves.
@davidgyoung
I just saw this Nokia Security update article.
Do you have any sight into what is happening at Nokia to know if this will address this issue?
Unfortunately, I see nothing in the descriptions of those security patches that looks like they would address this issue.
@davidgyoung H. I'm not sure what you'll be able to do with this, but I'm sharing it with you anyway.
On my Nokia 7.1 running Pie, I went though the procedure you put in a comment above, my plan being to do a factory rest later to see if this issue comes back. However, I still get the same results - after about 10 minutes with the screen off I start seeing
01-30 13:48:23.712 5075-5701/org.aph.nearbyonline.debug W/Binder: Binder call failed.
java.lang.SecurityException: Need ACCESS_COARSE_LOCATION or ACCESS_FINE_LOCATION permission to get scan results
at android.os.Parcel.createException(Parcel.java:1950)
at android.os.Parcel.readException(Parcel.java:1918)
at android.os.Parcel.readException(Parcel.java:1868)
at android.bluetooth.IBluetoothGatt$Stub$Proxy.startScan(IBluetoothGatt.java:947)
at android.bluetooth.le.BluetoothLeScanner$BleScanCallbackWrapper.onScannerRegistered(BluetoothLeScanner.java:460)
at android.bluetooth.le.IScannerCallback$Stub.onTransact(IScannerCallback.java:57)
at android.os.Binder.execTransact(Binder.java:731)
and after 30 minutes I no longer get any ranging information.
One thing that I didn't expect - after the soft reset the screen showed a sick Android with it's chest open and the words No Command on the screen. I'm not sure what that was about. I had to power off and on again. I thought maybe I missed something, so I went through the entire process a second time with the same results.
I haven't bothered with a factory reset.
@joew46167, this suggests that the procedure from Nokia is not 100% effective. Since you repeated it twice, this makes it unlikely that you accidentally skipped a step.
For the record, I did not see a "No Command" Android graphic like you describe when I went through the procedure.
Expected behavior
When Foreground scanning service is enabled it should scan always
Actual behavior
Scanning works for sometime(1-2 hours) and then scanning stops when the app is kept in background for a long time.
Steps to reproduce this behavior
Let the scan start and leave mobile idle for more than 2 hours. Scanning return empty list of beacons I have attached code.
Mobile device model and OS version
Nokia 6.1 Android PIe OS Version 9
Android Beacon Library version
2.15
My Code: How can i run the scanning for a long time (10-12 hours) continuously on Android 8 and Android 9?