Doze mode locks scan? - Githubissues

Expected behavior

Scanner works when device is locked or how we can to check is scanner locked by OS?

Actual behavior

Periodically scanner stops

Steps to reproduce this behavior

Run scanner with foreground service and lock device. Sometimes didRangeBeaconsInRegion not called.

Mobile device model and OS version

Samsung Galaxy S6 edge+ (Android 7.0)

Android Beacon Library version

2.15.2

I'm not sure that this question should be a issue. Briefly:

When method addRangeNotifier invoked, i iterate by beacon collections (in method didRangeBeaconsInRegion argument) and add it into List<> if not exsits, or update last visible time parameter (modifiedAt = System.currentTimeMillis()) if beacon was already in list.

Every 10 seconds my background thread iterates through this collection (List<>) and checks modifiedAt field. If we saw beacon more than 1 minute ago i remove it from collection. So i guess that we left the zone.

But. If device in idle state, periodically we do not receive events.

It's mean (Situation1) :

User enters in zone (new beacon, not exists in our cache, in our List<>)
User locks screen and does not leave the zone.
For a while we get an events, all is good, great.
After a while didRangeBeaconsInRegion stop calling.
Sooner or later didRangeBeaconsInRegion invokes again

I guess it's doze mode, but im not sure because see something strange (method for adding beacon or update it modifiedAt field):

fun addBeacon(beacon: AppBeacon) {
        if (isInDozeMode(TheApplication.getInstance())) {
            Crashlytics.logException(InconsistencyStateException("addBeacon invoke but doze mode active"))
       }
      //next logic

fun isInDozeMode(context: Context) : Boolean {
    val powerManager = context.getSystemService(Context.POWER_SERVICE) as PowerManager
    return Build.VERSION.SDK_INT >= Build.VERSION_CODES.M && powerManager.isDeviceIdleMode
}

And in reports i see this exception. I mean we obtain callback from library but isInDozeMode returns true.

For avoiding [Situation1] i added condition inside looper thread (thread that clean up expired objects).

if (isInDozeMode()) {
   //Ignore check modifiedAt parameter.
} else {
  //Check modifiedAt. If >1minute remove it
}

Unfortunately this condition does not work perfectly.

So, my question. Can we check is scanner not available now (blocked by OS)? Thanks.

Attachment: scanner setup in Application instance class

private const val REGION_UID = "my.packagename.here"
        private val region : Region
        get() {
            return Region(REGION_UID, null, null, null)
        }
const val FOREGROUND_BETWEEN_SCAN_DELAY: Long = 1000L
const val BACKGROUND_BETWEEN_SCAN_DELAY: Long = 1000L

const val FOREGROUND_SCAN_PERIOD: Long = 2000
const val BACKGROUND_SCAN_PERIOD: Long = 5100

 private fun setupBeaconScanner() {
        LogManager.setLogger(BeaconLogger())

        beaconManager = BeaconManager.getInstanceForApplication(this)
        beaconManager!!.beaconParsers.clear()
        beaconManager!!.beaconParsers.add(AltBeaconParser())
        beaconManager!!.beaconParsers.add(BeaconParser().setBeaconLayout(BeaconParser.URI_BEACON_LAYOUT))
        beaconManager!!.beaconParsers.add(BeaconParser().setBeaconLayout(BeaconParser.EDDYSTONE_TLM_LAYOUT))
        beaconManager!!.beaconParsers.add(BeaconParser().setBeaconLayout(BeaconParser.EDDYSTONE_UID_LAYOUT))
        beaconManager!!.beaconParsers.add(BeaconParser().setBeaconLayout(BeaconParser.EDDYSTONE_URL_LAYOUT))
        beaconManager!!.beaconParsers.add(BeaconParser().setBeaconLayout("m:2-3=0215,i:4-19,i:20-21,i:22-23,p:24-24,d:25-25"))

        val notificationBuilder = NotificationCompat.Builder(this)
        notificationBuilder.setSmallIcon(R.drawable.ic_details_action)
        notificationBuilder.setLargeIcon(BitmapFactory.decodeResource(resources, R.drawable.ic_details_action))
        notificationBuilder.setContentTitle("Scanning for beacons")
        val intent = Intent(this, MainActivity::class.java)
        val pendingIntent = PendingIntent.getActivity(this, MainActivity.BEACON_REQUEST_CODE, intent, PendingIntent.FLAG_UPDATE_CURRENT)
        notificationBuilder.setContentIntent(pendingIntent)

        if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.O) {
            val channelId = createNotificationChannel(SCANNER_CHANEL_ID, SCANNER_CHANEL_NAME, SCANNER_IMPORTANCE)
            notificationBuilder.setChannelId(channelId)
            notificationBuilder.setBadgeIconType(BADGE_ICON_SMALL)
        }

        val notification = notificationBuilder.build()
        beaconManager!!.enableForegroundServiceScanning(notification, 456)

        beaconManager!!.addRangeNotifier { p0, p1 ->
            p0?.run {
                forEach {
                    val beacon = AppBeacon.fromLibraryBeacon(it)
                    if (beacon != null) {
                        AppBeaconManager.addBeacon(beacon 
                    }
                }
            }
        }
        beaconManager!!.addMonitorNotifier(this)
        beaconManager!!.setEnableScheduledScanJobs(false)
        beaconManager!!.backgroundBetweenScanPeriod = BACKGROUND_BETWEEN_SCAN_DELAY
        beaconManager!!.foregroundBetweenScanPeriod = FOREGROUND_BETWEEN_SCAN_DELAY
        beaconManager!!.backgroundScanPeriod = BACKGROUND_SCAN_PERIOD
        beaconManager!!.foregroundScanPeriod = FOREGROUND_SCAN_PERIOD

        regionBootstrap = RegionBootstrap(this, region)
// Power saver temporary excluded but it did not fix the situation.
//        backgroundPowerSaver = BackgroundPowerSaver(this)

    }

When using a foreground service, the library uses an android Handler to schedule periodic scans (cycled based on the scanPeriod and betweenScanPeriod), and the didRangeBeaconsInRegion method is called at the end of each of these scan cycles. If you are seeing this stop, then this suggests that something is stopping the Handler event from firing.

You might check to see if this is happening in your test setup by enabling debug logging in the library: beaconManager.setDebug(true); then looking in LogCat when your app enters Doze mode to see how the log lines change. Under normal conditions, you should see the following repeatedly as each scan cycle starts and stops:

D/CycledLeScanner﹕Scan started
D/CycledLeScanner:  Done with scan cycle

Thanks for the reply. Unfortunately it's client feedback. On my OnePlus6 (9.0) OS kills my app after a while. It's oneplus feature

Did library has any callback or method for check is scan is active? Or last scan time? F.e., If i will see that last scanner running time was > (BACKGROUND_BETWEEN_SCAN_DELAY + BACKGROUND_SCAN_PERIOD), I can understand that the scan is blocked. Its would be helpful for me.

Thanks

If you are ranging, then a call to didRangeBeaconsInRegion indicates the time the last scan cycle completed. If you see these stop, then the scan cycles have stopped for some reason.

I suspect you can test on your OnePlus despite custom behavior that kills the app in the background. You can either whitelist your app to in the OnePlus settings so it can run forever, or you can simply use an ADB command to force entering doze mode immediately: $ adb shell dumpsys deviceidle force-idle

Thanks. But if we don't see any beacons (out of range) is didRangeBeaconsInRegion will be called?

Yes, so long as ranging is active, didRangeBeconsInRegion is called with a zero length collection of beacons when none are in range.

Yes, so long as ranging is active, didRangeBeconsInRegion is called with a zero length collection of beacons when none are in range.

Great! Thanks

Unfortunately, this method doesn't work. Because scanner works regular. Sometimes as i guess we not see beacons. Logs:

019-01-31 20:03:16.263 18029-18029 D/CycledLeScanner: Waiting to stop scan cycle for another 4088 milliseconds
2019-01-31 20:03:16.270 18029-18029 D/CycledLeScanner: Set a wakeup alarm to go off in 300000 ms: PendingIntent{de0a6ac: android.os.BinderProxy@778f75}
2019-01-31 20:03:17.271 18029-18029 D/CycledLeScanner: Waiting to stop scan cycle for another 3080 milliseconds
2019-01-31 20:03:17.278 18029-18029 D/CycledLeScanner: Set a wakeup alarm to go off in 300000 ms: PendingIntent{de0a6ac: android.os.BinderProxy@778f75}
2019-01-31 20:03:18.280 18029-18029 D/CycledLeScanner: Waiting to stop scan cycle for another 2071 milliseconds
2019-01-31 20:03:18.287 18029-18029 D/CycledLeScanner: Set a wakeup alarm to go off in 300000 ms: PendingIntent{de0a6ac: android.os.BinderProxy@778f75}
2019-01-31 20:03:18.439 18029-18041 D/ScanRecord: parseFromBytes
2019-01-31 20:03:18.439 18029-18041 D/ScanRecord: first manudata for manu ID
2019-01-31 20:03:18.440 18029-18029 D/CycledLeScannerForLollipop: got record
2019-01-31 20:03:18.442 18029-18430 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:18.443 18029-18430 D/BeaconParser: Processing pdu type FF: 0201061aff4c000215f7826da64fa24e988024bc5b71e0893e00019567c50d0961626561636f6e5f36373935000000000000000000000000000000000000 with startIndex: 5, endIndex: 29
2019-01-31 20:03:18.445 18029-18430 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting aa fe at offset 5 and 00 at offset 7.  The bytes I see are: 0201061aff4c000215f7826da64fa24e988024bc5b71e0893e00019567c50d0961626561636f6e5f36373935000000000000000000000000000000000000
2019-01-31 20:03:18.445 18029-18430 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:18.446 18029-18430 D/BeaconParser: Processing pdu type FF: 0201061aff4c000215f7826da64fa24e988024bc5b71e0893e00019567c50d0961626561636f6e5f36373935000000000000000000000000000000000000 with startIndex: 5, endIndex: 29
2019-01-31 20:03:18.447 18029-18430 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting aa fe at offset 5 and 20 at offset 7.  The bytes I see are: 0201061aff4c000215f7826da64fa24e988024bc5b71e0893e00019567c50d0961626561636f6e5f36373935000000000000000000000000000000000000
2019-01-31 20:03:18.447 18029-18430 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:18.448 18029-18430 D/BeaconParser: Processing pdu type FF: 0201061aff4c000215f7826da64fa24e988024bc5b71e0893e00019567c50d0961626561636f6e5f36373935000000000000000000000000000000000000 with startIndex: 5, endIndex: 29
2019-01-31 20:03:18.449 18029-18430 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting d8 fe at offset 5 and 00 at offset 7.  The bytes I see are: 0201061aff4c000215f7826da64fa24e988024bc5b71e0893e00019567c50d0961626561636f6e5f36373935000000000000000000000000000000000000
2019-01-31 20:03:18.449 18029-18430 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:18.450 18029-18430 D/BeaconParser: Processing pdu type FF: 0201061aff4c000215f7826da64fa24e988024bc5b71e0893e00019567c50d0961626561636f6e5f36373935000000000000000000000000000000000000 with startIndex: 5, endIndex: 29
2019-01-31 20:03:18.453 18029-18430 D/BeaconParser: This is a recognized beacon advertisement -- 02 15 seen
2019-01-31 20:03:18.453 18029-18430 D/BeaconParser: Bytes are: 0201061aff4c000215f7826da64fa24e988024bc5b71e0893e00019567c50d0961626561636f6e5f36373935000000000000000000000000000000000000
2019-01-31 20:03:18.458 18029-18430 D/ScanHelper: Beacon packet detected for: id1: f7826da6-4fa2-4e98-8024-bc5b71e0893e id2: 1 id3: 38247 with rssi -40
2019-01-31 20:03:18.458 18029-18430 D/ScanHelper: beacon detected : id1: f7826da6-4fa2-4e98-8024-bc5b71e0893e id2: 1 id3: 38247
2019-01-31 20:03:18.459 18029-18430 D/ScanHelper: looking for ranging region matches for this beacon
2019-01-31 20:03:18.459 18029-18430 D/ScanHelper: matches ranging region: id1: null id2: null id3: null
2019-01-31 20:03:18.460 18029-18430 D/RangeState: adding id1: f7826da6-4fa2-4e98-8024-bc5b71e0893e id2: 1 id3: 38247 to existing range for: org.altbeacon.beacon.service.RangedBeacon@a768f0e
2019-01-31 20:03:19.289 18029-18029 D/CycledLeScanner: Waiting to stop scan cycle for another 1062 milliseconds
2019-01-31 20:03:19.296 18029-18029 D/CycledLeScanner: Set a wakeup alarm to go off in 300000 ms: PendingIntent{de0a6ac: android.os.BinderProxy@778f75}
2019-01-31 20:03:19.448 18029-18042 D/ScanRecord: parseFromBytes
2019-01-31 20:03:19.449 18029-18042 D/ScanRecord: first manudata for manu ID
2019-01-31 20:03:19.450 18029-18029 D/CycledLeScannerForLollipop: got record
2019-01-31 20:03:19.450 18029-18029 D/CycledLeScannerForLollipop: with service uuid: 0000fef5-0000-1000-8000-00805f9b34fb
2019-01-31 20:03:19.452 18029-18431 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:19.453 18029-18431 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:19.453 18029-18431 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:19.454 18029-18431 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting aa fe at offset 9 and 00 at offset 11.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:19.455 18029-18431 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:19.455 18029-18431 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:19.455 18029-18431 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:19.456 18029-18431 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting aa fe at offset 9 and 20 at offset 11.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:19.456 18029-18431 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:19.460 18029-18431 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:19.461 18029-18431 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:19.462 18029-18431 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting d8 fe at offset 9 and 00 at offset 11.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:19.462 18029-18431 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:19.463 18029-18431 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:19.463 18029-18431 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:19.464 18029-18431 D/BeaconParser: This is not a matching Beacon advertisement. (Was expecting 02 15.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:19.464 18029-18431 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:19.465 18029-18431 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:19.465 18029-18431 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:19.466 18029-18431 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting aa fe at offset 9 and 10 at offset 11.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:19.467 18029-18431 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:19.468 18029-18431 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:19.468 18029-18431 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:19.469 18029-18431 D/BeaconParser: This is not a matching Beacon advertisement. (Was expecting be ac.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:20.297 18029-18029 D/CycledLeScanner: Waiting to stop scan cycle for another 54 milliseconds
2019-01-31 20:03:20.304 18029-18029 D/CycledLeScanner: Set a wakeup alarm to go off in 300000 ms: PendingIntent{de0a6ac: android.os.BinderProxy@778f75}
2019-01-31 20:03:20.358 18029-18029 D/CycledLeScanner: Done with scan cycle
2019-01-31 20:03:20.359 18029-18029 D/ScanHelper: Beacon simulator not enabled
2019-01-31 20:03:20.359 18029-18029 D/ScanHelper: Calling ranging callback
2019-01-31 20:03:20.360 18029-18029 D/RunningAverageRssiFilter: Running average mRssi based on 2 measurements: -40.0
2019-01-31 20:03:20.361 18029-18029 D/RangedBeacon: calculated new runningAverageRssi: -40.0
2019-01-31 20:03:20.361 18029-18029 D/Callback: attempting callback via local broadcast intent: org.altbeacon.beacon.range_notification
2019-01-31 20:03:20.363 18029-18029 D/CycledLeScanner: stopping bluetooth le scan
2019-01-31 20:03:20.363 18029-18029 D/CycledLeScannerForLollipop: Stopping scan
2019-01-31 20:03:20.364 18029-18085 D/CycledLeScannerForLollipop: Stopping LE scan on scan handler
2019-01-31 20:03:20.365 18029-18085 D/BluetoothAdapter: STATE_ON
2019-01-31 20:03:20.366 18029-18085 D/BluetoothAdapter: STATE_ON
2019-01-31 20:03:20.366 18029-18085 D/BluetoothLeScanner: Stop Scan
2019-01-31 20:03:20.371 18029-18029 D/CycledLeScanner: Normalizing between scan period from 1000 to 960
2019-01-31 20:03:20.372 18029-18029 D/CycledLeScannerForLollipop: This is Android L, but we last saw a beacon only 1913 ago, so we will not keep scanning in background.
2019-01-31 20:03:20.372 18029-18029 D/CycledLeScannerForLollipop: Waiting to start full Bluetooth scan for another 960 milliseconds
2019-01-31 20:03:20.381 18029-18029 D/CycledLeScanner: Set a wakeup alarm to go off in 300000 ms: PendingIntent{de0a6ac: android.os.BinderProxy@778f75}
2019-01-31 20:03:20.382 18029-18029 D/IntentHandler: got ranging data
2019-01-31 20:03:21.343 18029-18029 D/CycledLeScanner: starting a new scan cycle
2019-01-31 20:03:21.344 18029-18029 D/CycledLeScanner: starting a new bluetooth le scan
2019-01-31 20:03:21.345 18029-18029 D/CycledLeScannerForLollipop: starting non-filtered scan in SCAN_MODE_LOW_LATENCY
2019-01-31 20:03:21.346 18029-18029 D/CycledLeScanner: Waiting to stop scan cycle for another 5100 milliseconds
2019-01-31 20:03:21.346 18029-18085 D/BluetoothLeScanner: Start Scan
2019-01-31 20:03:21.350 18029-18085 D/BluetoothAdapter: STATE_ON
2019-01-31 20:03:21.351 18029-18085 D/BluetoothAdapter: STATE_ON
2019-01-31 20:03:21.352 18029-18085 D/BluetoothAdapter: STATE_ON
2019-01-31 20:03:21.353 18029-18085 D/BluetoothAdapter: STATE_ON
2019-01-31 20:03:21.356 18029-18029 D/CycledLeScanner: Set a wakeup alarm to go off in 300000 ms: PendingIntent{de0a6ac: android.os.BinderProxy@778f75}
2019-01-31 20:03:21.357 18029-18029 D/CycledLeScanner: Scan started
2019-01-31 20:03:21.459 18029-18041 D/BluetoothLeScanner: onClientRegistered() - status=0 clientIf=7 mClientIf=0
2019-01-31 20:03:21.502 18029-18042 D/ScanRecord: parseFromBytes
2019-01-31 20:03:21.503 18029-18042 D/ScanRecord: first manudata for manu ID
2019-01-31 20:03:21.503 18029-18029 D/CycledLeScannerForLollipop: got record
2019-01-31 20:03:21.503 18029-18029 D/CycledLeScannerForLollipop: with service uuid: 0000fef5-0000-1000-8000-00805f9b34fb
2019-01-31 20:03:21.505 18029-18432 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:21.506 18029-18432 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:21.507 18029-18432 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:21.508 18029-18432 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting aa fe at offset 9 and 00 at offset 11.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:21.509 18029-18432 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:21.509 18029-18432 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:21.510 18029-18432 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:21.512 18029-18432 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting aa fe at offset 9 and 20 at offset 11.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:21.512 18029-18432 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:21.513 18029-18432 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:21.513 18029-18432 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:21.515 18029-18432 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting d8 fe at offset 9 and 00 at offset 11.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:21.515 18029-18432 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:21.516 18029-18432 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:21.516 18029-18432 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:21.517 18029-18432 D/BeaconParser: This is not a matching Beacon advertisement. (Was expecting 02 15.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:21.517 18029-18432 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:21.517 18029-18432 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:21.518 18029-18432 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:21.519 18029-18432 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting aa fe at offset 9 and 10 at offset 11.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:21.519 18029-18432 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:21.519 18029-18432 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:21.520 18029-18432 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:21.522 18029-18432 D/BeaconParser: This is not a matching Beacon advertisement. (Was expecting be ac.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:22.358 18029-18029 D/CycledLeScanner: Waiting to stop scan cycle for another 4088 milliseconds
2019-01-31 20:03:22.365 18029-18029 D/CycledLeScanner: Set a wakeup alarm to go off in 300000 ms: PendingIntent{de0a6ac: android.os.BinderProxy@778f75}
2019-01-31 20:03:23.367 18029-18029 D/CycledLeScanner: Waiting to stop scan cycle for another 3079 milliseconds
2019-01-31 20:03:23.374 18029-18029 D/CycledLeScanner: Set a wakeup alarm to go off in 300000 ms: PendingIntent{de0a6ac: android.os.BinderProxy@778f75}
2019-01-31 20:03:23.519 18029-18041 D/ScanRecord: parseFromBytes
2019-01-31 20:03:23.520 18029-18041 D/ScanRecord: first manudata for manu ID
2019-01-31 20:03:23.521 18029-18029 D/CycledLeScannerForLollipop: got record
2019-01-31 20:03:23.521 18029-18029 D/CycledLeScannerForLollipop: with service uuid: 0000fef5-0000-1000-8000-00805f9b34fb
2019-01-31 20:03:23.524 18029-18434 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:23.524 18029-18434 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:23.525 18029-18434 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:23.526 18029-18434 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting aa fe at offset 9 and 00 at offset 11.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:23.526 18029-18434 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:23.526 18029-18434 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:23.527 18029-18434 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:23.527 18029-18434 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting aa fe at offset 9 and 20 at offset 11.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:23.528 18029-18434 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:23.528 18029-18434 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:23.528 18029-18434 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:23.529 18029-18434 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting d8 fe at offset 9 and 00 at offset 11.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:23.529 18029-18434 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:23.530 18029-18434 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:23.532 18029-18434 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:23.533 18029-18434 D/BeaconParser: This is not a matching Beacon advertisement. (Was expecting 02 15.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:23.534 18029-18434 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:23.534 18029-18434 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:23.534 18029-18434 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:23.536 18029-18434 D/BeaconParser: This is not a matching Beacon advertisement. Was expecting aa fe at offset 9 and 10 at offset 11.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:23.536 18029-18434 D/BeaconParser: Ignoring pdu type 01
2019-01-31 20:03:23.536 18029-18434 D/BeaconParser: Ignoring pdu type 03
2019-01-31 20:03:23.537 18029-18434 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27
2019-01-31 20:03:23.538 18029-18434 D/BeaconParser: This is not a matching Beacon advertisement. (Was expecting be ac.  The bytes I see are: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000
2019-01-31 20:03:24.374 18029-18029 D/CycledLeScanner: Waiting to stop scan cycle for another 2071 milliseconds
2019-01-31 20:03:24.383 18029-18029 D/CycledLeScanner: Set a wakeup alarm to go off in 300000 ms: PendingIntent{de0a6ac: android.os.BinderProxy@778f75}
2019-01-31 20:03:25.385 18029-18029 D/CycledLeScanner: Waiting to stop scan cycle for another 1061 milliseconds
2019-01-31 20:03:25.393 18029-18029 D/CycledLeScanner: Set a wakeup alarm to go off in 300000 ms: PendingIntent{de0a6ac: android.os.BinderProxy@778f75}

OK, to clarify what those logs show:

You are saying you put the device into Doze mode over adb, and you still see scan cycles completing as expected and beacons being detected as expected. So this means that you simply cannot reproduce the problem on your OnePlus test device, correct?

OK, to clarify what those logs show:

You are saying you put the device into Doze mode over adb, and you still see scan cycles completing as expected and beacons being detected as expected. So this means that you simply cannot reproduce the problem on your OnePlus test device, correct?

My fault. I forgot to say. I found Samsung Galaxy Tab A (SM-T550), Android version 7.1.1. I ran app and press "Home", without device lock.

Sorry, I still don't understand what you are trying to communicate by showing that log excerpt. I see 9 seconds of logs, with multiple BLE detections (though none of them are beacons) and what looks like normal scan cycling. Is there something wrong with what you see in that test?

Sorry. I just saying that after a while didRangeBeaconsInRegion many time invoked with empty collection in argument. After ~20 minutes (every time different time) i see beacons again (collection in method not empty).

Can you reproduce this problem (an empty collection for a long period of time,) locally? If so a log excerpt covering that time would be helpful in finding the cause.

Can you reproduce this problem (an empty collection for a long period of time,) locally? If so a log excerpt covering that time would be helpful in finding the cause.

Good day. I tried to collect logs on unlocked device but...all is good (>15 minutes). Looks like periodically issue. After that i locked device. My max lifetime for beacons in cache - 1 minute. But this parameter is ignored if last scan was > 30 seconds ago. In logs i see next: 18:00:02.220 19278-19314 D/ScanMonitor: Current scan between scan interval 736 ms But lifetime more than 1 minute.

It's mean that didRangeBeaconsInRegion invoked, but no beacons detected. Attached logs. Thank you.

Logcat2.txt

The logs show that BLE advertisements continue to detected by the library, but none of the recent advertisements matched the beacon layout. you can see the most recent detection in this log line:

2019-02-01 18:00:00.568 19278-19326 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd2000104853323e9e6ed67f875ed7e7311ee1d0d0961626561636f6e5f363832310000000000000000000000000000000000000000

This suggests the phone's Bluetooth stack is working to detect advertisements and the library is parsing them to find ones that are beacon advertisements but it just isn't finding any that are beacons during this period of time.

Is it possible that this could be right? Could there really not be any beacon advertisements during this period? What is your transmitter, and how often is it set to advertise?

Perhaps you can use a second device as a detector (perhaps iOS or Windows or Mac to get a second opinion) over the same time to see if there really are dropouts in advertisements.

Perhaps unrelated, but I do see this exception right before packets matching the beacon layout stop being detected. Any idea what this is?

2019-02-01 17:59:30.404 18340-18340 W/System.err: io.reactivex.exceptions.OnErrorNotImplementedException: The exception was not handled due to missing onError handler in the subscribe() method call. Further reading: https://github.com/ReactiveX/RxJava/wiki/Error-Handling | null
2019-02-01 17:59:30.404 18340-18340 W/System.err:     at io.reactivex.internal.functions.Functions$OnErrorMissingConsumer.accept(Functions.java:704)

Perhaps unrelated, but I do see this exception right before packets matching the beacon layout stop being detected. Any idea what this is?

2019-02-01 17:59:30.404 18340-18340 W/System.err: io.reactivex.exceptions.OnErrorNotImplementedException: The exception was not handled due to missing onError handler in the subscribe() method call. Further reading: https://github.com/ReactiveX/RxJava/wiki/Error-Handling | null
2019-02-01 17:59:30.404 18340-18340 W/System.err:     at io.reactivex.internal.functions.Functions$OnErrorMissingConsumer.accept(Functions.java:704)

It's manually exception throwing when beacon in cache is out of time. I will try to run on OnePlus 6 (9.0) and Galaxy Tab (7.1) in the same time.

My beacons nearby my devices :) Strange that exception (beacons lost) i see when device in idle mode.

@davidgyoung Unfortunately, same behavior on 9.0

Device

OnePlus 6.0 (OS 9)

Step to reproduce

Open application for start scanning
Lock device
Go away from beacon zone (optional)
Get back to zone (optional)

Step 3 and 4 are optional because if we just lock device inside zone after a while we obtain empty collection in method region.

didRangeBeaconsInRegion invoked with empty collection in argument

Logs attached. Thank you beacon_logs_1.txt

P.S. Maybe my beacon logger setup is wrong? I don't invoke .bind method

Again, that log shows bluetooth LE advertisements being detected throughout the period the log is captured, but not necessarily the beacons you are looking for. This does not appear to be a radio or OS problem in doing bluetooth scanning. I would perhaps set up two devices simultaneously (with the clocks set to be the same), one in the foreground and one in the background, and capture logs from both. The one in the foreground can be used as a reference to see what is really transmitting. When the backgrounded device stops detecting, does the foregrounded device still detect the beacon? If so, can you show two logs of this over the same time period, with the foreground device showing the detection at the same time as the background device does not.

Hi. Thanks for the answer. I tried to run on Samsung Tab (7.1) and OnePlus 6 (9 OS) in the same time. Run, press home and kill app from stack. After that i go away from beacon zone ~15-20minutes and go back.

Samsung see beacons, oneplus - no.

Maybe something wrong in beacon scanner setup? (https://github.com/AltBeacon/android-beacon-library/issues/815#issue-405274345)

In my manifest

 <uses-permission android:name="android.permission.INTERNET" />
    <uses-permission android:name="android.permission.BLUETOOTH" />
    <uses-permission android:name="android.permission.BLUETOOTH_ADMIN" />
    <uses-permission android:name="android.permission.ACCESS_COARSE_LOCATION" />
    <uses-permission android:name="android.permission.ACCESS_FINE_LOCATION" />
    <uses-permission android:name="android.permission.FOREGROUND_SERVICE"/>
    <uses-feature
        android:name="android.hardware.bluetooth_le"
        android:required="true" />

    <uses-feature android:name="android.hardware.location.network"/>

//Inside application tag
 <service android:name="org.altbeacon.beacon.service.BeaconService"
            tools:node="replace">
            <meta-data android:name="longScanForcingEnabled" android:value="true"/>
        </service>

Should i call .bind method for foreground mode?

@YuraAAA, going by the logs you have shared with me, this is NOT an issue of the scan set up or failing to detect Bluetooth LE advertisements. I know this because I see lines in the logs indicating that bluetooth LE packets continue to be detected by the operating system and the Android Beacon Library inside your app. You know it is seeing these advertising packets whenever the logs show a line like this:

2019-01-31 20:03:21.510 18029-18432 D/BeaconParser: Processing pdu type FF: 0201060303f5fe14ffd20001bd00087350f246d64e61875aa0621a810d0961626561636f6e5f363739350000000000000000000000000000000000000000 with startIndex: 9, endIndex: 27

But the reason you don't see any callbacks to your didRangeBeaconsInRegion method is because none of the packets detected match the three different BeaconParsers you have registered with the library. (I see one is for iBeacon, another is for Eddystone and a third is for a d8 fe byte pattern that I am not familiar with.) If a detected advertisement matches one of your BeaconParsers you will see a line like this:

2019-01-31 20:03:18.453 18029-18430 D/BeaconParser: This is a recognized beacon advertisement -- 02 15 seen

I do not understand why the packets you are expecting stop being detected when other packets are still being detected. I suspect maybe they really are not being transmitted. That is why I suggested you use a second device to look for them in the foreground to verify they really are advertising at the same time as you do not see them on the first device. If you could do this test and attach a log from device 1 and device 2 showing that the same timestamps on each (with one detecting and one not) it might give us some clues.

Hi, thanks for the answer. I installed on Samsung Tab (7.1) and on OnePlus (9.0) in the same time. Application run and i press home button on both devices.

On Samsung - all looks fine! I see beacons On OnePlus - nothing :(

I disable BackgroundPowerSaver

May be logs from this devices may be helpful.

OnePlus.txt Samsung.txt

Thanks

Sorry, my fault. I don't know why on OnePlus location service was turned off.

I added next lines into application

BluetoothMedic.getInstance().enablePowerCycleOnFailures(this)
beaconManager!!.bind(this)

because i see too many errors on huawei Scan failed: a BLE scan with the same settings is already started by the app

and moved beaconManager!!.addRangeNotifier

into onBeaconServiceConnect method

AltBeacon / android-beacon-library

Doze mode locks scan? #815