AltBeacon / android-beacon-library

Allows Android apps to interact with BLE beacons
Apache License 2.0
2.84k stars 837 forks source link

Problem Detecting Existing Beacons After App Restart #708

Closed gchallen closed 5 years ago

gchallen commented 6 years ago

Expected behavior

After the reference app is restarted it should report on nearby beacons, either via didEnterRegion or didDetermineStateForRegion.

Actual behavior

After restart no initial didDetermineStateForRegion event is delivered. After a long pause on the order of minutes the reference app delivers pairs of "I no longer see a beacon"/"I see a beacon again" repeatedly, accompanied by the "I have just switched..." message.

However, the library does seem to know it's inside a region, since you receive this log message:

06-21 17:16:58.495 2740-2740/org.altbeacon.beaconreference I/ScanJob: We are inside a beacon region.  We will not scan between cycles.

One thing I did notice from time to time is that onCreate is called again in the app around the same time it's restarted. So you restart and you can see the UI redraw quickly before the second onCreate event causes the UI to restart. But this doesn't seem consistent.

Steps to reproduce this behavior

I'm using a BlueCharm beacon set to iBeacon mode and set to broadcast at 2Hz. I saw another post about setting it to broadcast at at least 10Hz (which seems quite high), so I tried that as well, but it made no difference. If you have suggestions about iBeacon hardware known to work better I'm all ears 😄.

Mobile device model and OS version

Google Pixel with Android 8.1.0.

Android Beacon Library version

2.14.

Thanks for all the hard work on this library!

davidgyoung commented 6 years ago

@gchallen, can you set beaconManager.setDebug(true); and attach a log excerpt? This will help me track down what is happening.

gchallen commented 6 years ago

Done. Scenario was:

  1. App was installed and started within range of a beacon
  2. And didn't see the beacon for a while
  3. And then displayed one pair of exited/entered messages

I was planning on getting a second pair but my phone went to sleep and that seemed to break the logcat connection. (Or it might have been due to Apple's stupid USB-C insanity, which leads to flaky connections since they go through an adapter.) But hopefully this is enough. Let me know if you need more info.

davidgyoung commented 6 years ago

The log file covers about 90 seconds, and I see a beacon is detected by the library within 4 seconds of the start of the log:

06-22 10:37:44.490 18003-18142/org.altbeacon.beaconreference D/ScanHelper: Beacon packet detected for: id1: 9304fd9d-4276-4442-980f-ff8739a9efd4 id2: 10004 id3: 54480 with rssi -52

But this won't necessarily give you a callback to didEnterRegion if you were already in the region when the beacon was detected. And because the library persists region state across app restarts, this applies even when restarting your app (at least if the app had been last running within a reasonable amount of time ~15 min -- this is done to prevent duplicate entry events across app restarts caused by the operating system.) You might wish to disable this behavior with beaconManager.setRegionStatePersistenceEnabled(false) which will always give you a callback on first detection after app restart.

I believe the didDetermineStateForRegion() callback WILL get called in all cases on app restart. But because neither the library nor the reference app logs anything when this callback is made, I can't tell for sure from the logs if this happens. You might try adding a log line to the reference app for this and see if you see it upon restart.

gchallen commented 6 years ago

Thanks for the help.

After a bit more debugging I have a better sense of what is happening. First, the didDetermineStateForRegion is being called as you stated. However, what's confusing is that no message is shown in the display the first time the app is launched. I think that there must be a race here in that the didDetermineStateForRegion callback is being fired just before the monitoring activity is rendered—at least when the app is shut down and restarted. So nothing on the console indicates that that event was received. To the degree that this app is intended to help debug the library, that might be worth fixing, since it's confusing otherwise.

As promised, with the setRegionState... enabled both an enter and a state changed event are received. IIRC I think that one makes it to the display.

However, the problem of repeat exit/enter pairs remains. The previous log that I sent along should contain one pair of those as well.

davidgyoung commented 6 years ago

Regarding the race condition -- I agree that is probably the issue. That didDetermineStateForRegion callback is made very quickly, probably before the MonitoringActivity has been constructed. I'm not sure what a good way to fix this is that keeps the reference app simple and easy to understand. Any ideas welcome.

@Override
public void didDetermineStateForRegion(int state, Region region) {
    if (monitoringActivity != null) {
        monitoringActivity.logToDisplay("I have just switched from seeing/not seeing beacons: " + state);
    }
}

The repeat exit/enter pairs is a different issue, and quite a common one. This is caused by the receiver not detecting any beacon packets for a long time -- 10 seconds by default. This number can be customized in BeaconManager.setRegionExitPeriod(10000/*milliseconds*/);

Understand that not 100% of beacon packets are detected even in the best conditions. 80-90% is typical. There are lots of factors that can contribute to intermittently not detecting beacons and causing spurious region exits.

  1. Beacons not advertising frequently enough
  2. Scan period configured to be too short to reliably capture a packet in the previous 10 second window.
  3. Beacon is too far from receiver to reliably detect
  4. Poor transmitter of receiver antenna quality
  5. Radio noise

To prevent spurious exits, I would recommend adjusting items 1 and 2 above, and only change BeaconManager.setRegionExitPeriod(10000/*milliseconds*/); if you have no other choice.

gchallen commented 6 years ago

Thanks again for the reply.

I don't really understand the iBeacon protocol, but I'm confused as to why the factors above would cause spurious exit/enter pairs. I could understand how the would cause spurious exits, but in this case the reentrance happens almost immediately each time. So the device is unable to detect a beacon for 10s but then almost immediately redetects it once the 10s is up? But again—maybe there is a handshake taking place or some other part of the protocol that I'm not familiar with (as in, any of it).

WRT the factors affecting spurious region exits:

  1. The beacon is set up to advertise at a period of 500ms
  2. I'm not sure how the scan period is configured...?
  3. Beacon is right next to the smartphone
  4. Possibly, but most enter and exit events are detected quite rapidly
  5. Again, possible, but doesn't explain the snappiness of most enter and exit detections

To me this just doesn't seem like the behavior you'd expect from 10% transmission rates (for example). I'd expect slow and variable beacon detection, and same for when I power it off to simulate an exit event. After the 10s window is up I'd expect varying amounts of time before the beacon is redetected, but it always seems to happen almost immediately. What am I missing here?

davidgyoung commented 6 years ago

There is no handshake at all -- it is a simple one way transmission by the beacon and receipt by the phone.

It is pretty common for the didEnterRegion to quickly follow the didExitRegion for spurious exits. This happens because you just barely missed seeing the packet that would have kept it in region.

You set the scan period with calls like this:

beaconManager.setForegroundScanPreriod(1100); // this is the default
beaconManager.setForegroundBetweenScanPreriod(0); // this is the default
beaconManager.setBackgroundScanPreriod(10000); // this is the default
beaconManager.setBackgroundBetweenScanPreriod(300000); // this is the default

If you are using these defaults, then it does seem improbable that you are missing all detections for a full 10 second period. You can analyze what is going on before a spurious exit with a log file with setDebug(true) and looking for lines like this:

06-22 10:38:31.260 18003-18144/org.altbeacon.beaconreference D/ScanHelper: Beacon packet detected for: id1: 9304fd9d-4276-4442-980f-ff8739a9efd4 id2: 10004 id3: 54480 with rssi -61

For an exit to happen, it should have been 10 seconds since the last detection. If you suspect that it is wrong that there was no detection, check over that period to see if any other BLE packets were detected at all with log lines like this:

06-22 10:38:31.208 18003-18143/org.altbeacon.beaconreference D/BeaconParser: This is not a matching Beacon advertisement. (Was expecting 4c 00 02 15.  The bytes I see are: 02011a0bff4c0009060305c011714c0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000

If you don't see ANY lines like the above for 10 seconds then you are in a very quiet bluetooth location, or something might be wrong with the scanning on your device. Look for other look messages to suggest what this might be.

davidgyoung commented 5 years ago

closing due to inactivity