Skip to content
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

org.altbeacon.beacon.service.MonitoringStatus org.altbeacon.beacon.service.ScanState.getMonitoringStatus() #887

Closed
AiPacinoDebug opened this issue May 30, 2019 · 30 comments · Fixed by #890

Comments

@AiPacinoDebug
Copy link

"androidversion":"8.0.0","brand":"HUAWEI HONOR DUK-AL20",

Android 2.16.2

error

error

E/JobServiceEngine: Application unable to handle onStopJob.
java.lang.NullPointerException: Attempt to invoke virtual method 'org.altbeacon.beacon.service.MonitoringStatus org.altbeacon.beacon.service.ScanState.getMonitoringStatus()' on a null object reference
at org.altbeacon.beacon.service.ScanJob.startPassiveScanIfNeeded(ScanJob.java:139)
at org.altbeacon.beacon.service.ScanJob.onStopJob(ScanJob.java:171)
at android.app.job.JobService$1.onStopJob(JobService.java:76)
at android.app.job.JobServiceEngine$JobHandler.handleMessage(JobServiceEngine.java:117)
at android.os.Handler.dispatchMessage(Handler.java:108)
at android.os.Looper.loop(Looper.java:166)
at android.app.ActivityThread.main(ActivityThread.java:7425)
at java.lang.reflect.Method.invoke(Native Method)
at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:245)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:921)

@davidgyoung
Copy link
Member

Thanks for this report. I stumbled across this today, too.

I suspect this crash was introduced by a change in 2.15.2 that puts the call to ScanState.restore() onto a new thread. If that call gets blocked due to the disk being busy, and something happens later that stops the ScanJob, the restore will never have happened and the crash shown could occur. I would think that this is not really a new crash introduced in 2.15.2 but a change in a crash for the same condition as reported in #814 and attempted to be fixed in #878

The fix for this crash would be to treat mScanState as nullable and properly protect against a NPE on each access.

@pawelmarchewka
Copy link

pawelmarchewka commented Jun 3, 2019

The same problem on Nexus 5X with Android 8.1.0 and library version 2.16.2

java.lang.NullPointerException: Attempt to invoke virtual method 'org.altbeacon.beacon.service.MonitoringStatus org.altbeacon.beacon.service.ScanState.getMonitoringStatus()' on a null object reference
        at org.altbeacon.beacon.service.ScanJob.startPassiveScanIfNeeded(ScanJob.java:139)
        at org.altbeacon.beacon.service.ScanJob.onStopJob(ScanJob.java:171)
        at android.app.job.JobService$1.onStopJob(JobService.java:76)
        at android.app.job.JobServiceEngine$JobHandler.handleMessage(JobServiceEngine.java:117)
        at android.os.Handler.dispatchMessage(Handler.java:106)
        at android.os.Looper.loop(Looper.java:164)
        at android.app.ActivityThread.main(ActivityThread.java:6494)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:438)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:807)

@jmvines
Copy link

jmvines commented Jun 4, 2019

Same issue here

@davidgyoung
Copy link
Member

Attempted fix in #890

@davidgyoung
Copy link
Member

@mzTeamMeatMan, @jmvines and @pawelmarchewka, can you please try this beta release with the fix and let me know if you see the crash go away?

https://github.com/AltBeacon/android-beacon-library/releases/tag/2.16.3-beta1

@AiPacinoDebug
Copy link
Author

@davidgyoung ,
Currently normal
Android 8 Is there a way to break through the 15 minute scan?
What we need is to scan every second.

@pawelmarchewka
Copy link

pawelmarchewka commented Jun 6, 2019

@davidgyoung I have tested 2.16.3-beta1 and haven't noticed any crash.

Unfortunately, I noticed a different problem (maybe related to fixing that crash) - I cannot stop ranging beacons in region. After calling stopRangingBeaconsInRegion I see the following exception in logcat, and BeaconManger is calling my RangeNotifier endlessly:

W/MessageQueue: Handler (android.os.Handler) {5e8d787} sending message to a Handler on a dead thread
    java.lang.IllegalStateException: Handler (android.os.Handler) {5e8d787} sending message to a Handler on a dead thread
        at android.os.MessageQueue.enqueueMessage(MessageQueue.java:545)
        at android.os.Handler.enqueueMessage(Handler.java:662)
        at android.os.Handler.sendMessageAtTime(Handler.java:631)
        at android.os.Handler.sendMessageDelayed(Handler.java:601)
        at android.os.Handler.post(Handler.java:357)
        at org.altbeacon.beacon.service.scanner.CycledLeScannerForLollipop.postStopLeScan(CycledLeScannerForLollipop.java:263)
        at org.altbeacon.beacon.service.scanner.CycledLeScannerForLollipop.stopScan(CycledLeScannerForLollipop.java:49)
        at org.altbeacon.beacon.service.scanner.CycledLeScannerForLollipop.finishScan(CycledLeScannerForLollipop.java:221)
        at org.altbeacon.beacon.service.scanner.CycledLeScanner.finishScanCycle(CycledLeScanner.java:424)
        at org.altbeacon.beacon.service.scanner.CycledLeScanner.scheduleScanCycleStop(CycledLeScanner.java:382)
        at org.altbeacon.beacon.service.scanner.CycledLeScanner$2.run(CycledLeScanner.java:378)
        at android.os.Handler.handleCallback(Handler.java:790)
        at android.os.Handler.dispatchMessage(Handler.java:99)
        at android.os.Looper.loop(Looper.java:164)
        at android.app.ActivityThread.main(ActivityThread.java:6494)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:438)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:807)

@davidgyoung
Copy link
Member

@pawelmarchewka, do you have specific steps to reproduce this? I can't figure out what might cause that exception just by looking at code. I really need to reproduce myself to figure out what causes it. (It might also be helpful if you can set beaconManager.setDebug(true) and capture a LogCat excerpt for a few seconds before that stacktrace appears.)

@pawelmarchewka
Copy link

pawelmarchewka commented Jun 12, 2019

@davidgyoung, I need to find the nearest beacon with specific UUID, so I scan for nearby beacons for few seconds:

  1. I call beaconManager.bind(beaconConsumer)
  2. In beaconConsumer.onBeaconServiceConnect() I call beaconManager.startRangingBeaconsInRegion
  3. I gather all detected beacons and sort them by RSSI to get the nearest one
  4. After 6 seconds I stop scanning by calling beaconManager.stopRangingBeaconsInRegion and then beaconManager.unbind(beaconConsumer)

A logcat file with beaconManager.setDebug(true) from Nexus 5X with Android 8.1: logcat-2019-06-12.txt

@davidgyoung
Copy link
Member

@pawelmarchewka, I am not able to reproduce this with the reference app on a Pixel 3a with 9.0.

Below is my test setup. Is anything significantly different than what you have? How are you scheduling the stop after 6 seconds? Which thread does that happen on?


    beaconManager.bind(this);

    ...

    @Override
    public void onBeaconServiceConnect() {
        final BeaconManager beaconManager = org.altbeacon.beacon.BeaconManager.getInstanceForApplication(this);
        final Region region = new Region("backgroundRegion",
                null, null, null);

        Log.i(TAG, "Starting ranging.");
        try {
            beaconManager.startRangingBeaconsInRegion(region);
        } catch (RemoteException e) {
            e.printStackTrace();
        }
        new Handler().postDelayed(new Runnable() {
            @Override
            public void run() {
                try {
                    Log.i(TAG, "Stopping ranging.");
                    beaconManager.stopRangingBeaconsInRegion(region);
                } catch (RemoteException e) {
                    e.printStackTrace();
                }

            }
        }, 6000);

    }
2019-06-17 11:37:28.362 2959-2959/org.altbeacon.beaconreference W/beaconreferenc: JIT profile information will not be recorded: profile file does not exits.
2019-06-17 11:37:28.385 2959-2959/org.altbeacon.beaconreference I/InstantRun: starting instant run server: is main process
2019-06-17 11:37:28.398 2959-2959/org.altbeacon.beaconreference I/BeaconManager: BeaconManager started up on pid 2959 named 'org.altbeacon.beaconreference' for application package 'org.altbeacon.beaconreference'.  isMainProcess=true
2019-06-17 11:37:28.407 2959-2959/org.altbeacon.beaconreference I/BeaconReferenceApp: Starting ranging.
2019-06-17 11:37:28.471 2959-2959/org.altbeacon.beaconreference I/ScanJob: Using immediateScanJobId from manifest: 208352939
2019-06-17 11:37:28.475 2959-2959/org.altbeacon.beaconreference I/ScanJob: Using periodicScanJobId from manifest: 208352940
2019-06-17 11:37:28.475 2959-2959/org.altbeacon.beaconreference W/JobInfo: Requested interval +5m0s0ms for job 208352940 is too small; raising to +15m0s0ms
2019-06-17 11:37:28.475 2959-2959/org.altbeacon.beaconreference W/JobInfo: Requested flex 0 for job 208352940 is too small; raising to +5m0s0ms
2019-06-17 11:37:28.480 2959-2959/org.altbeacon.beaconreference W/org.altbeacon.beaconreference: type=1400 audit(0.0:67620): avc: denied { read } for comm=45474C20496E6974 name="u:object_r:vendor_default_prop:s0" dev="tmpfs" ino=20027 scontext=u:r:untrusted_app:s0:c238,c256,c512,c768 tcontext=u:object_r:vendor_default_prop:s0 tclass=file permissive=0
2019-06-17 11:37:28.486 2959-2979/org.altbeacon.beaconreference E/libc: Access denied finding property "vendor.debug.egl.profiler"
2019-06-17 11:37:28.675 2959-2983/org.altbeacon.beaconreference I/Adreno: QUALCOMM build                   : 97eb455, I987d6683f9
    Build Date                       : 11/29/18
    OpenGL ES Shader Compiler Version: EV031.25.03.02
    Local Branch                     : 
    Remote Branch                    : 
    Remote Branch                    : 
    Reconstruct Branch               : 
2019-06-17 11:37:28.675 2959-2983/org.altbeacon.beaconreference I/Adreno: Build Config                     : S P 4.0.10 AArch64
2019-06-17 11:37:28.674 2959-2959/org.altbeacon.beaconreference W/RenderThread: type=1400 audit(0.0:67621): avc: denied { read } for name="u:object_r:vendor_default_prop:s0" dev="tmpfs" ino=20027 scontext=u:r:untrusted_app:s0:c238,c256,c512,c768 tcontext=u:object_r:vendor_default_prop:s0 tclass=file permissive=0
2019-06-17 11:37:28.680 2959-2983/org.altbeacon.beaconreference E/libc: Access denied finding property "ro.vendor.graphics.memory"
2019-06-17 11:37:28.681 2959-2983/org.altbeacon.beaconreference I/Adreno: PFP: 0x016ee176, ME: 0x00000000
2019-06-17 11:37:28.684 2959-2983/org.altbeacon.beaconreference I/ConfigStore: android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasWideColorDisplay retrieved: 1
2019-06-17 11:37:28.684 2959-2983/org.altbeacon.beaconreference I/ConfigStore: android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasHDRDisplay retrieved: 1
2019-06-17 11:37:28.685 2959-2983/org.altbeacon.beaconreference I/OpenGLRenderer: Initialized EGL, version 1.4
2019-06-17 11:37:28.725 2959-2986/org.altbeacon.beaconreference I/CycledLeScanner: Using Android O scanner
2019-06-17 11:37:28.727 2959-2983/org.altbeacon.beaconreference E/libc: Access denied finding property "vendor.gralloc.disable_ahardware_buffer"
2019-06-17 11:37:28.720 2959-2959/org.altbeacon.beaconreference W/RenderThread: type=1400 audit(0.0:67622): avc: denied { read } for name="u:object_r:vendor_default_prop:s0" dev="tmpfs" ino=20027 scontext=u:r:untrusted_app:s0:c238,c256,c512,c768 tcontext=u:object_r:vendor_default_prop:s0 tclass=file permissive=0
2019-06-17 11:37:28.730 2959-2986/org.altbeacon.beaconreference I/ScanJob: Using immediateScanJobId from manifest: 208352939
2019-06-17 11:37:28.730 2959-2986/org.altbeacon.beaconreference I/ScanJob: Running immediate scan job: instance is org.altbeacon.beacon.service.ScanJob$1@b8cf1c9
2019-06-17 11:37:28.731 2959-2986/org.altbeacon.beaconreference I/ScanJob: scanJob version 2.16.3-beta1-SNAPSHOT is starting up on the main process
2019-06-17 11:37:28.738 2959-2986/org.altbeacon.beaconreference W/ModelSpecificDistanceCalculator: Cannot find match for this device.  Using default
2019-06-17 11:37:28.739 2959-2986/org.altbeacon.beaconreference W/ModelSpecificDistanceCalculator: Cannot find match for this device.  Using default
2019-06-17 11:37:28.765 2959-2986/org.altbeacon.beaconreference I/ScanJob: Scan job running for 300000 millis
2019-06-17 11:37:32.220 2959-2959/org.altbeacon.beaconreference I/chatty: uid=10238(org.altbeacon.beaconreference) identical 1 line
2019-06-17 11:37:34.476 2959-2959/org.altbeacon.beaconreference I/BeaconReferenceApp: Stopping ranging.
2019-06-17 11:37:34.524 2959-2959/org.altbeacon.beaconreference I/ScanJob: Using immediateScanJobId from manifest: 208352939
2019-06-17 11:37:34.527 2959-2959/org.altbeacon.beaconreference I/ScanJob: Using periodicScanJobId from manifest: 208352940
2019-06-17 11:37:34.527 2959-2959/org.altbeacon.beaconreference W/JobInfo: Requested interval +5m0s0ms for job 208352940 is too small; raising to +15m0s0ms
2019-06-17 11:37:34.527 2959-2959/org.altbeacon.beaconreference W/JobInfo: Requested flex 0 for job 208352940 is too small; raising to +5m0s0ms
2019-06-17 11:37:34.530 2959-2959/org.altbeacon.beaconreference I/chatty: uid=10238(org.altbeacon.beaconreference) identical 8 lines
2019-06-17 11:37:34.531 2959-2959/org.altbeacon.beaconreference I/ScanJob: Using periodicScanJobId from manifest: 208352940
2019-06-17 11:37:34.531 2959-2959/org.altbeacon.beaconreference I/ScanJob: onStopJob called for immediate scan org.altbeacon.beacon.service.ScanJob@7e9c134
2019-06-17 11:37:34.602 2959-3035/org.altbeacon.beaconreference I/CycledLeScanner: Using Android O scanner
2019-06-17 11:37:34.605 2959-3035/org.altbeacon.beaconreference I/ScanJob: Using immediateScanJobId from manifest: 208352939
2019-06-17 11:37:34.605 2959-3035/org.altbeacon.beaconreference I/ScanJob: Running immediate scan job: instance is org.altbeacon.beacon.service.ScanJob$1@9a0dfc4
2019-06-17 11:37:34.605 2959-3035/org.altbeacon.beaconreference I/ScanJob: scanJob version 2.16.3-beta1-SNAPSHOT is starting up on the main process
2019-06-17 11:37:34.610 2959-3035/org.altbeacon.beaconreference W/ModelSpecificDistanceCalculator: Cannot find match for this device.  Using default
2019-06-17 11:37:34.610 2959-3035/org.altbeacon.beaconreference W/ModelSpecificDistanceCalculator: Cannot find match for this device.  Using default
2019-06-17 11:37:34.621 2959-3035/org.altbeacon.beaconreference I/ScanJob: Scan job running for 300000 millis

@davidgyoung davidgyoung reopened this Jun 17, 2019
@pawelmarchewka
Copy link

@davidgyoung, I prepared a small example application based on our code but:

  1. I can reproduce the problem only on my Nexus 5X with Android 8.1 (I can't reproduce it on Pixel 2 with Android 9, and I don't have more phones with Android 8.X)
  2. It is not reproducible in 100%
  3. In the provided logcat file you can see that stopRangingBeaconsInRegions is called at 17:56:16.066 but scanning not only hasn't stopped, but it restarts itself constantly
  4. Sometimes when this happens, I can even see such errors in logcat: E/BtGatt.GattService: App 'com.techcentrix.altbeaconissue887example' is scanning too frequently

AltBeaconIssue887Example.zip

logcat - 2019-06-19.txt

@davidgyoung
Copy link
Member

@pawelmarchewka, looking at the sample code I notice that the scanning start/stop is handled on a thread managed by a coroutine Dispatchers.Default. Nothing wrong with that, but that different thread might somehow make the difference here. I wonder if the thread trying to stop scanning is somehow blocked.

Unfortunately, I don't have any devices with Android 8.1 -- all are on Android 9 at this point.

I believe I the App 'com.techcentrix.altbeaconissue887example' is scanning too frequently message is unrelated. It is a warning from the OS that the way the library stops/starts scanning periodically is being ignored. The warning is triggered under some configurations and is generally benign.

I will do some testing with logging the thread id during the stop scanning process to see if that sheds any light on what is going on.

@pawelmarchewka
Copy link

@davidgyoung, I don't think that a thread trying to stop scanning is blocked:

  1. stopScanning() method is called because you can see stopRangingBeaconsInRegions in logcat
  2. changing dispatcher to Dispatchers.IO (which, according to documentation, can create up to 64 threads) doesn't help at all

I have tested my example app on two additional phones with Android 8.0 (LG G6 and Samsung Galaxy S7), and I can confirm the issue on both of them.

Finally, I changed the dispatcher to Dispatchers.Main so both startScanning() and stopScanning() methods are called on the main thread and it definitely resolves the issue. I haven't noticed any problem with stopping the scanning on any of three phones (Nexus 5X, LG G6, and Galaxy S7).

Maybe all methods like BeaconManager.bind()/unbind() and BeaconManager.startRangingBeaconsInRegion()/stopRangingBeaconsInRegion() should always be dispatched via the main thread by the library?

@davidgyoung
Copy link
Member

Using the UI thread probably resolves the problem just because it subtly changes the timing of the way things happen.

Investigating your logs further, I believe this problem is simply a race condition caused by anotherside effect of #878

Here's the sequence:

  1. An immediate ScanJob Build failed - missing com.android.support:support-v4:19.1.+. #1 is executing to scan for beacons.
  2. The code loops through two ranged regions, stopping one at a time.
  3. For the first region ranging stop, changes are synchronized to the server, which causes the ScanJob Build failed - missing com.android.support:support-v4:19.1.+. #1 to be killed (with two regions) and a new one ScanJob Not seeing any beacons #2 to be started (with just one region)
  4. For the second region ranging stop, changes are synchronized to the server, which causes the newly started ScanJob Not seeing any beacons #2 immediate scan job to be killed (with one regions). But this scan job is just starting up -- it is still loading state from storage when it is stopped and threads are killed. But then it starts up scanning on the killed threads anyway.

Here is that sequence:

2019-06-19 17:56:10.032 9972-9972/com.techcentrix.altbeaconissue887example D/CycledLeScanner: stop called
2019-06-19 17:56:10.032 9972-9972/com.techcentrix.altbeaconissue887example D/CycledLeScanner: scanning already stopped
2019-06-19 17:56:10.032 9972-9972/com.techcentrix.altbeaconissue887example D/CycledLeScanner: Destroying
2019-06-19 17:56:10.033 9972-10012/com.techcentrix.altbeaconissue887example D/BeaconManager: consumer count is now: 1
2019-06-19 17:56:10.033 9972-9972/com.techcentrix.altbeaconissue887example D/ScanJob: Scanning stopped
2019-06-19 17:56:10.033 9972-9972/com.techcentrix.altbeaconissue887example D/ScanJob: Checking to see if we need to start a passive scan
2019-06-19 17:56:10.033 9972-10018/com.techcentrix.altbeaconissue887example D/CycledLeScanner: Quitting scan thread
2019-06-19 17:56:10.036 9972-10017/com.techcentrix.altbeaconissue887example D/CycledLeScanner: Set a wakeup alarm to go off in 9223372036854486898 ms: PendingIntent{2e98091: android.os.BinderProxy@3be1bf6}
2019-06-19 17:56:10.036 9972-10017/com.techcentrix.altbeaconissue887example D/CycledLeScanner: start called

the last line with D/CycledLeScanner: start called is what causes all the trouble -- the threads have already been quit, and this will cause the exception later on.

Before #878, this was not possible to happen because the main thread was blocked while the ScanJob was starting up. Now that this start up happens on a new thread, the race condition can happen.

I believe a the solution to this is to simply check if the ScanJob was stopped before calling start() on CycledLeScanner. I also suspect the problem could be reproduced on any device by repeatedly calling startRangingBeaconsInRegion/stopRangingBeaconsInRegion many times in a loop.

@davidgyoung
Copy link
Member

Wow. I just cannot reproduce this with the reference app, or with the app you shared, @pawelmarchewka.

I have tried with the reference app and:

  • Pixel 3a Android 9.0
  • Huawei P9 Android 7.0 (With beaconManager.setEnableScheduledScanJobs(true))
  • Nexus 5X Android 8.0 Emulator (With a BeaconSimulator registered so ScanJob will execute on the Emulator)

I still cannot reproduce on any of these devices even if I start and stop ranging 100 regions in a row:

    @Override
    public void onBeaconServiceConnect() {
        final BeaconManager beaconManager = org.altbeacon.beacon.BeaconManager.getInstanceForApplication(this);

        Log.i(TAG, "Starting ranging.");
        try {
            for (int i = 0; i < 100d; i++) {
                Region region = new Region("backgroundRegion"+i,
                        null, null, null);
                beaconManager.startRangingBeaconsInRegion(region);
            }
        } catch (RemoteException e) {
            e.printStackTrace();
        }
        new Handler().postDelayed(new Runnable() {
            @Override
            public void run() {
                try {
                    Log.i(TAG, "Stopping ranging.");
                    for (int i = 0; i < 100; i++) {
                        Region region = new Region("backgroundRegion"+i,
                                null, null, null);
                        beaconManager.stopRangingBeaconsInRegion(region);
                    }
                } catch (RemoteException e) {
                    e.printStackTrace();
                }
            }
        }, 6000);

    }

@pawelmarchewka, I also tried with your app running on the Nexus 5X Android 8.0 emulator with one modification to the init of ClipDetector.kt to enable a BeaconSimulator so ScanJobs will run on the emulator:

        // Make it so you see no beacons each scan cycle, but the cycles still run.
        BeaconManager.setBeaconSimulator(BeaconSimulator { listOf() })

I do not doubt you see this crash, but I just can't reproduce the problem to verify my proposed fix in #896. @pawelmarchewka, I can roll a build to have you test it again, unless you have a better idea.

@pawelmarchewka
Copy link

pawelmarchewka commented Jun 25, 2019

@davidgyoung, as I mentioned, I was able to reproduce this problem only on devices with Android 8.X (I tried on other versions of Android), and I never tested it on an emulator.

If you can prepare another beta, it would be great - with my example app and three devices with Android 8.X I can test your fix quite easily 🙂

@davidgyoung
Copy link
Member

@pawelmarchewka , the release is here: https://github.com/AltBeacon/android-beacon-library/releases/tag/2.16.3-beta2

Yes, I realize you could only reproduce on Android 8.x, which is why I tried on the emulator. Strange that I could not reproduce there.

Please try the release with your app that reproduces the problem and let me know what you see.

@pawelmarchewka
Copy link

@davidgyoung, thank you for preparing beta2. I tested it many, many times on my example app using both dispatchers (Default and IO):

  1. I wasn't able to reproduce the issue on Nexus 5X and Samsung Galaxy S7 🙂
  2. Unfortunately, it happened 3 or 4 times on LG G6 although it was much harder to reproduce 🙁

Logcat - LG G6 with beta2 - 2019-06-27.txt

@davidgyoung
Copy link
Member

@pawelmarchewka, it seems it is impossible to use logic to guarantee preventing the race condition that starts a scan after a job is stopped. So I resorted to using synchornized blocks in this release:

https://github.com/AltBeacon/android-beacon-library/releases/tag/2.16.3-beta3

I did note when preparing this change that the stack trace shown is the result of a warning-level log from the library, not an actual crash. So while this adds log noise, and I'd like to eliminate it, I don't think is nearly as serious as the crash that caused this issue to be opened. That clarification aside, please do try the beta3 release if you have time and let me know if that makes it go away on the LG G6.

@pawelmarchewka
Copy link

@davidgyoung, the crash/warning was never my main concern, but if scanning has been stopped (or not) after calling stopRangingBeaconsInRegion 🙂

I have tested beta3 on LG G6, but it didn't help - scanning is still running in the background after calling stopRangingBeaconsInRegion.

Logcat - LG G6 with beta3 - 2019-07-08.txt

@davidgyoung
Copy link
Member

Sorry, @pawelmarchewka the beta3 build that intended to add synchronization did nothing because I synchronized on the wrong object during ScanJob startup -- I used synchronized(this) instead of the proper synchronized(ScanJob.this) as required due to the enclosing anonymous Runnable object that I did not notice. The beta4 build corrects that. https://github.com/AltBeacon/android-beacon-library/releases/tag/2.16.3-beta4

One clarification -- I do not think the scans are actually left on despite the warning say it cannot stop the scan. The scans are previously stopped successfully during job shutdown. The scan stop that causes the warning and stack trace are the regular cycled scanning of the library (which should be shut down cleanly but are clearly not due to this race condition). So when the warning appears, the CycledLeScanner is trying to do the regular periodic scan stop (despite the fact that the scan is alrady stopped) because it does not realize that it is supposed to be shut down. That said, the warning does create noise I'd like to eliminate.

@pawelmarchewka
Copy link

@davidgyoung, I have tested beta4 on LG G6 (and Nexus 5X), and it looks that synchronization resolved the issue 🙂

Logcat - LG G6 with beta4 - 2019-07-09.txt

@davidgyoung
Copy link
Member

Great, thank you for sticking with this, @pawelmarchewka

@sarikas26
Copy link

Great, thank you for sticking with this, @pawelmarchewka

Hi @davidgyoung

I am also facing the issues mentioned in this thread.

  • On android 8.0, sometimes i get the following crash:
    Logs - Application unable to handle onStopJob.
    java.lang.NullPointerException: Attempt to invoke virtual method 'org.altbeacon.beacon.service.MonitoringStatus org.altbeacon.beacon.service.ScanState.getMonitoringStatus()' on a null object reference
    at org.altbeacon.beacon.service.ScanJob.startPassiveScanIfNeeded(ScanJob.java:139)
    at org.altbeacon.beacon.service.ScanJob.onStopJob(ScanJob.java:171)
    at android.app.job.JobService$1.onStopJob(JobService.java:76)
    at android.app.job.JobServiceEngine$JobHandler.handleMessage(JobServiceEngine.java:117)
    at android.os.Handler.dispatchMessage(Handler.java:106)
    at android.os.Looper.loop(Looper.java:176)
    at android.app.ActivityThread.main(ActivityThread.java:6651)
    at java.lang.reflect.Method.invoke(Native Method)
    at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:547)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:824)

This happens randomly sometimes.

  • In Nexus 5X with android 6.0 i am getting error saying "W/MessageQueue: Handler (android.os.Handler) {5e8d787} sending message to a Handler on a dead thread".

I am using implementation 'org.altbeacon:android-beacon-library:2+' in my dependencies.

Can you please guide me as what is causing this issue and how can i resolve it.

@mikhailmelnik
Copy link

@davidgyoung we've had 2.16.1 since February in production and haven't had major issues with it. Recently we've pushed an update to the app which included various dependency and configuration updates (like ABI filter change required by Google Play) as well as upgrade to AltBeacon 2.16.2.

Since then we've started getting series of strange crashes from both background and foreground on different devices:

OnePlus5 Android 9:

Fatal Exception: java.util.ConcurrentModificationException
       at java.util.ArrayList$Itr.next + 860(ArrayList.java:860)
       at org.altbeacon.beacon.service.ScanJob$1.run + 76(ScanJob.java:76)
       at java.lang.Thread.run + 764(Thread.java:764)

OnePlus5 Android 9:

Fatal Exception: java.lang.NullPointerException: Attempt to invoke virtual method 'java.util.Set [REMOVED]' on a null object reference
       at org.altbeacon.beacon.service.ScanJob.restartScanning + 231(ScanJob.java:231)
       at org.altbeacon.beacon.service.ScanJob.startScanning + 259(ScanJob.java:259)
       at org.altbeacon.beacon.service.ScanJob.access$500 + 40(ScanJob.java:40)
       at org.altbeacon.beacon.service.ScanJob$1.run + 90(ScanJob.java:90)
       at java.lang.Thread.run + 764(Thread.java:764)

OnePlus5, Android 9:

Caused by java.lang.NullPointerException: Attempt to invoke virtual method 'void [REMOVED]' on a null object reference
       at org.altbeacon.beacon.service.ScanJob.stopScanning + 180(ScanJob.java:180)
       at org.altbeacon.beacon.service.ScanJob.onStopJob + 170(ScanJob.java:170)
       at android.app.job.JobService$1.onStopJob + 67(JobService.java:67)
       at android.app.job.JobServiceEngine$JobHandler.handleMessage + 117(JobServiceEngine.java:117)
       at android.os.Handler.dispatchMessage + 106(Handler.java:106)
       at android.os.Looper.loop + 193(Looper.java:193)
       at android.app.ActivityThread.main + 6898(ActivityThread.java:6898)
       at java.lang.reflect.Method.invoke(Method.java)
       at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run + 537(RuntimeInit.java:537)
       at com.android.internal.os.ZygoteInit.main + 858(ZygoteInit.java:858)

OnePlus5 Android 9, Galaxy S7 Android 8, HUAWEI Y5 2018 Android 8.1:

Caused by java.lang.NullPointerException: Attempt to invoke virtual method '[REMOVED] on a null object reference
       at org.altbeacon.beacon.service.ScanJob.startPassiveScanIfNeeded + 139(ScanJob.java:139)
       at org.altbeacon.beacon.service.ScanJob.onStopJob + 171(ScanJob.java:171)
       at android.app.job.JobService$1.onStopJob + 76(JobService.java:76)
       at android.app.job.JobServiceEngine$JobHandler.handleMessage + 117(JobServiceEngine.java:117)
       at android.os.Handler.dispatchMessage + 106(Handler.java:106)
       at android.os.Looper.loop + 166(Looper.java:166)
       at android.app.ActivityThread.main + 6861(ActivityThread.java:6861)
       at java.lang.reflect.Method.invoke(Method.java)
       at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run + 450(RuntimeInit.java:450)
       at com.android.internal.os.ZygoteInit.main + 936(ZygoteInit.java:936)

Most of the listed crashes happened one after another on our test device, so we've considered it as a glitch or some sort of reaction on large amount of beacons in the office, but the last one happened in production on two devices which I'm pretty sure had no beacons in vicinity at the time of the crash.

Since it happens pretty often (but still without steps to reproduce) on OnePlus5 which is in the office I can collect extra information if necessary.

@davidgyoung
Copy link
Member

Please use the 2.16.3-beta4 release to solve the original crash on this thread, then provide feedback that that release solved it for you and did not cause new problems. Once I have sufficient confirmation I will roll a non-beta release.

Please do not add new crashes to this issue. This is a closed issue.

@sarikas26
Copy link

Hi @davidgyoung i integrated 2.16.3-beta4 release and is not getting the crash. Thanks for providing the solution.

@atotalnoob
Copy link

I am experiencing this issue as well for 2 devices over the weekend.

Both android 7.0, both in library version 2.16.2.

I've added the beta 4. Will report with my testing results.

Including the stack traces, just in case.

Fatal Exception: java.lang.RuntimeException: java.lang.NullPointerException: Attempt to invoke virtual method 'org.altbeacon.beacon.service.MonitoringStatus org.altbeacon.beacon.service.ScanState.getMonitoringStatus()' on a null object reference
       at android.app.job.JobService$JobHandler.handleMessage + 156(JobService.java:156)
       at android.os.Handler.dispatchMessage + 102(Handler.java:102)
       at android.os.Looper.loop + 154(Looper.java:154)
       at android.app.ActivityThread.main + 6776(ActivityThread.java:6776)
       at java.lang.reflect.Method.invoke(Method.java)
       at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run + 1496(ZygoteInit.java:1496)
       at com.android.internal.os.ZygoteInit.main + 1386(ZygoteInit.java:1386)

and

Caused by java.lang.NullPointerException: Attempt to invoke virtual method 'org.altbeacon.beacon.service.MonitoringStatus org.altbeacon.beacon.service.ScanState.getMonitoringStatus()' on a null object reference
       at org.altbeacon.beacon.service.ScanJob.startPassiveScanIfNeeded + 139(ScanJob.java:139)
       at org.altbeacon.beacon.service.ScanJob.onStopJob + 171(ScanJob.java:171)
       at android.app.job.JobService$JobHandler.handleMessage + 152(JobService.java:152)
       at android.os.Handler.dispatchMessage + 102(Handler.java:102)
       at android.os.Looper.loop + 154(Looper.java:154)
       at android.app.ActivityThread.main + 6776(ActivityThread.java:6776)
       at java.lang.reflect.Method.invoke(Method.java)
       at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run + 1496(ZygoteInit.java:1496)
       at com.android.internal.os.ZygoteInit.main + 1386(ZygoteInit.java:1386)

@atotalnoob
Copy link

@davidgyoung Haven't observed any crashes once our devices upgraded to the beta4.

Tested on samsung/nexus 9, android versions 7.0, 7.1, 8.0, 8.1 across 50 devices

@davidgyoung
Copy link
Member

Thank you all for the feedback. This is now in release 2.16.4

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 a pull request may close this issue.

7 participants