expo: expo-location crash on Android when using in the background

Started to receive this app crash on Android after upgrading from Expo v46 to v48. From the crash data reported in Sentry so far the trigger seems to be a call to Location.getCurrentPositionAsync() on component mount after a prolonged time (for example overnight). Suspect doze mode. Been unable to find reliable steps to reproduce despite many hours of trying via various adb commands to force doze and/or app standby.

Stacktrace:

java.lang.RuntimeException: callback 2 arg cannot be called more than once
    at expo.modules.kotlin.jni.JavaCallback.invoke(JavaCallback.kt)
    at expo.modules.kotlin.jni.JavaCallback.invoke(JavaCallback.kt:25)
    at expo.modules.kotlin.PromiseKt$toBridgePromise$resolveMethod$1.invoke(Promise.kt:22)
    at expo.modules.kotlin.PromiseKt$toBridgePromise$resolveMethod$1.invoke(Promise.kt:22)
    at expo.modules.kotlin.PromiseKt$toBridgePromise$1.resolve(Promise.kt:29)
    at expo.modules.adapters.react.PromiseWrapper.resolve(PromiseWrapper.java:27)
    at expo.modules.location.LocationHelpers$1.onLocationChanged(LocationHelpers.java:157)
    at expo.modules.location.LocationModule$1.onLocationResult(LocationModule.java:557)
    at com.google.android.gms.internal.location.zzau.notifyListener
    at com.google.android.gms.common.api.internal.ListenerHolder.notifyListenerInternal
    at com.google.android.gms.common.api.internal.ListenerHolder$zaa.handleMessage
    at android.os.Handler.dispatchMessage(Handler.java:106)
    at android.os.Looper.loopOnce(Looper.java:226)
    at android.os.Looper.loop(Looper.java:313)
    at android.os.HandlerThread.run(HandlerThread.java:67)

This issue happens when waking the app after it has entered DREAMING state, from what our logs say. But unsure if it only happens when a currentlocation request is running when the app is minimized.

Activity log (most recent event first):

- RuntimeException: callback 2 arg cannot be called more than once
- console Foreground! (JS event callback)
- app.lifecycle state: foreground
- app.lifecycle state: start
- device.event action: SCREEN_ON, 
- 14:27:35 device.event action: DREAMING_STOPPED
- 14:06:12 device.event action action: DREAMING_STARTED

It is a major issue for us, and are getting several percent of our users crashing every day. It is making us look for other Geolocation frameworks as this issue does not seem to be on the radar of the Expo team.

FWIW I am experiencing this, and I do not have notifee installed. I doubt it is an essential part of reproducing the issue.

@brentvatne I have made a reproduceable demo.

https://github.com/hanselsen/expo-location-stopping

It contains the essence of what we are supposed to accomplish. If you run yarn android it will start the app and it will log certain lines to a Telegram group chat. Both our app and this demo quit this night.

It supposed to log this set of lines over and over:

ExpoLocationBot, [18-Jan-23 01:12] Heartbeat!
ExpoLocationBot, [18-Jan-23 01:12] Releasing wake lock
ExpoLocationBot, [18-Jan-23 01:12] Acquiring wake lock
ExpoLocationBot, [18-Jan-23 01:12] heartbeat:emitting
ExpoLocationBot, [18-Jan-23 01:12] Getting location
ExpoLocationBot, [18-Jan-23 01:12] Got location: {"timestamp":1674000728989,"mocked":false,"coords":{"altitude":73.5999984741211,"heading":0,"altitudeAccuracy":2.2362146377563477,"latitude":51.4421011,"speed":0,"longitude":5.4085551,"accuracy":11.649999618530273}}

Instead, in the end, it stopped sending log lines and the last lines were:

ExpoLocationBot, [18-Jan-23 01:12] OnCreate called
ExpoLocationBot, [18-Jan-23 01:12] notification is not null
ExpoLocationBot, [18-Jan-23 01:12] onStartCommand called: no intent

What also is interesting is that my original application has implemented some more log lines:

MyBot, [18-Jan-23 01:11] Heartbeat!
MyBot, [18-Jan-23 01:11] Releasing wake lock 
MyBot, [18-Jan-23 01:11] heartbeat:emitting
MyBot, [18-Jan-23 01:12] MainApplication:onCreate (1069949074)
MyBot, [18-Jan-23 01:12] OnCreate called
MyBot, [18-Jan-23 01:12] onStartCommand called: no intent
MyBot, [18-Jan-23 01:26] MainApplication:onTrimMemory: 5
MyBot, [18-Jan-23 01:26] MainApplication:onTrimMemory: 5

In the Android bug report I see the same lines for both the apps:

01-18 01:12:21.494 10383 17191 17258 E AndroidRuntime: FATAL EXCEPTION: expo.modules.AsyncFunctionQueue
01-18 01:12:21.494 10383 17191 17258 E AndroidRuntime: Process: com.mobile, PID: 17191
01-18 01:12:21.494 10383 17191 17258 E AndroidRuntime: java.lang.RuntimeException: callback 2 arg cannot be called more than once
...
01-18 01:12:21.497 10377 18649 18689 E AndroidRuntime: FATAL EXCEPTION: expo.modules.AsyncFunctionQueue
01-18 01:12:21.497 10377 18649 18689 E AndroidRuntime: Process: com.myapp, PID: 18649
01-18 01:12:21.497 10377 18649 18689 E AndroidRuntime: java.lang.RuntimeException: callback 2 arg cannot be called more than once

I hope this demo can provide enough to go with.

Our app has been running in production with Expo v49 and expo-location v16.1.0 for a few days (about 50% of users). So far the native crash has not yet surfaced for that new app version but continues on the older ones as expected. Perhaps a bit early to celebrate but the data so far looks very promising that this is indeed solved. Thanks a lot Alan!

Update: app has been running in production for about 2 months for vast majority of users and the issue has not surfaced yet. Would call this issue solved.

Any updates? I am facing the same issue. Could you fix it, @jonrh ?

@alanjhughes I’m using 48.0.0.

Anyway, the latest expo-location 15.3.0 works with both build and update, no idea why the patch-package method didn’t work 🤔

I’ll be pushing the update to my users in about 2 weeks, I’ll let you know if it resolves the issue I’m seeing on Sentry. Hopefully I’ll have good news 🙏

@nixolas1 - no problem, I wasn’t able to reproduce so if you could report back if it fixes the issue that would be great 👍

@michaek - yes, I don’t see notifee having anything to do with the issue. The issue with the repro provided is the module creates its own threads and calls the event emitter from them, which then calls expo location. I would like to see a reproduction with fairly typical usage.

No solution yet sadly. Tried out a the community location package, but that has its own issues. So currently hoping this one gets resolved, or we have to do some more research with other packages.

On May 22, 2023, GitHub notification @.***> wrote:

@nixolas1 https://github.com/nixolas1 we’re also seeing this issue on our app, would you mind sharing what you ended up opting for to solve this problem?

— Reply to this email directly, view it on GitHub https://github.com/expo/expo/issues/20663#issuecomment-1557271046, or unsubscribe <https://github.com/notifications/unsubscribe- auth/AA27KBWJ6QTLN4JF6IJ7O5LXHNWJJANCNFSM6AAAAAATNRMDN4>. You are receiving this because you were mentioned.Message ID: @.***>