NullPointerException in logger (possibly just on very old Android APIs)

[mikehardy]

Your Environment

• Plugin version: ^3.0.0-beta.4
• Platform: Android
• OS version: 4.2.1 (I know, it is ancient)
• Device manufacturer / model: HiSense M470BSA (one of those $30 newegg tablets from years ago)
• React Native version (react-native -v): 0.58.6
• Plugin config: ironically, it's in the stack trace I'll paste

Expected Behavior

Boot the app with the plugin, run BackGroundGeolocation.getLog(), get the log contents Note that at the time the app had booted on this device for the first time ever, and had no locations saved.

Actual Behavior

Native crash

Steps to Reproduce

This is the function called as a button handler:

  _onGetLog = async () => {
    try {
      const logString = await BackgroundGeolocation.getLog(); // Crash here
      this.setState({ logContents: logString });
      BackgroundGeolocation.destroyLog();
    } catch (e) {
      console.log('unable to get logs?', e);
    }
  };

Here is the chunk of render() that calls it:

        <RX.Button style={Styles.loginIngresarButton} onPress={this._onGetLog}>
          <RX.Text style={Styles.loginIngresarButton}>Muestra Log</RX.Text>
        </RX.Button>

Context

I'm still in the process of integrating the plugin and I'm at the point where I'm testing it on a wide API skew, and with devices that don't have a great sensor mix. This is a screen where you hit a button and it shows the log in a scrollview on the device

This is not the most urgent thing. However, I'm pretty skilled at Java and Android so I might be able to help pinpoint it. Also, I just started the license process, so this is the public android plugin in demo mode. I'll switch shortly and update if there is a behavior difference.

Debug logs

03-07 08:08:03.172 22405-22423/com.kullki.kscore W/dalvikvm: threadid=12: thread exiting with uncaught exception (group=0x41465930)
03-07 08:08:03.312 22405-22423/com.kullki.kscore E/TSLocationManager: [c.t.l.a.BackgroundGeolocation$e uncaughtException] 
      ‼️  Uncaught Exception: An error occured while executing doInBackground()
    {"headers":{},"deferTime":0,"httpTimeout":60000,"fastestLocationUpdateInterval":10000,"notificationPriority":0,"notificationSmallIcon":"","desiredOdometerAccuracy":100,"speedJumpFilter":300,"persist":true,"logMaxDays":3,"desiredAccuracy":-1,"notificationLargeIcon":"","geofenceProximityRadius":1000,"geofenceInitialTriggerEntry":true,"stationaryRadius":25,"batchSync":true,"minimumActivityRecognitionConfidence":50,"stopOnStationary":false,"maxDaysToPersist":20,"logLevel":5,"elasticityMultiplier":1,"forceReloadOnLocationChange":false,"forceReloadOnHeartbeat":false,"forceReloadOnBoot":false,"enabled":true,"forceReloadOnGeofence":false,"locationTemplate":"","forceReloadOnSchedule":false,"autoSync":true,"odometer":0,"httpRootProperty":"location","triggerActivities":"in_vehicle, on_bicycle, on_foot, running, walking","url":"https:\/\/app.kullki.com:9001\/locations\/testrun","extras":{},"locationsOrderDirection":"ASC","geofenceTemplate":"","schedulerEnabled":false,"isFirstBoot":false,"locationTimeout":60,"activityRecognitionInterval":10000,"notificationTitle":"","disableElasticity":false,"persistMode":2,"debug":true,"trackingMode":1,"stopTimeout":5,"maxBatchSize":100,"heartbeatInterval":60,"locationUpdateInterval":1000,"disableStopDetection":false,"maxRecordsToPersist":-1,"startOnBoot":true,"forceReloadOnMotionChange":false,"enableTimestampMeta":true,"headlessJobService":"com.transistorsoft.rnbackgroundgeolocation.HeadlessTask","stopOnTerminate":false,"notificationText":"Mejorando score con sus movimientos...","autoSyncThreshold":30,"isMoving":false,"params":{"device":{"platform":"android","model":"M470BSA","uuid":"f6e1dbbb35ea797","manufacturer":"Hisense","version":"4.2.1"}},"notificationColor":"","schedule":[],"foregroundService":true,"stopAfterElapsedMinutes":0,"method":"POST","allowIdenticalLocations":true,"enableHeadless":false,"distanceFilter":20}
    java.lang.RuntimeException: An error occured while executing doInBackground()
        at android.os.AsyncTask$3.done(AsyncTask.java:299)
        at java.util.concurrent.FutureTask.finishCompletion(FutureTask.java:352)
        at java.util.concurrent.FutureTask.setException(FutureTask.java:219)
        at java.util.concurrent.FutureTask.run(FutureTask.java:239)
        at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:230)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1080)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
        at java.lang.Thread.run(Thread.java:856)
     Caused by: java.lang.NullPointerException: null
        at com.transistorsoft.locationmanager.logger.a.a(Unknown Source)
        at com.transistorsoft.locationmanager.logger.a.a(Unknown Source)
        at com.transistorsoft.locationmanager.logger.TSLog$c.a(Unknown Source)
        at com.transistorsoft.locationmanager.logger.TSLog$c.doInBackground(Unknown Source)
        at android.os.AsyncTask$2.call(AsyncTask.java:287)
        at java.util.concurrent.FutureTask.run(FutureTask.java:234)
        ... 4 common frames omitted

[christocracy]

Lowest android device I test upon is Nexus 4 @ 4.4.4.

However, I would not immediately execute #destroyLog right after #getLog. Use a Promise.

BackgroundGeolocation.getLog().then(BackgroundGeolocation.destroyLog))

[mikehardy]

Lowest android device I test upon is Nexus 4 @ 4.4.4.

I bisected and saw it fails on API15, 16 and 17 emulators and starts working >=18 so that explains it as your lower bound is 19. Testing on APIs lower than 18 is problematic but if you're interested (for support reason) I use this to support down to API15 on AnkiDroid - https://github.com/ankidroid/Anki-Android/blob/master/tools/quality-check/start_all_emulators.sh#L9

However, I would not immediately execute #destroyLog right after #getLog. Use a Promise.

BackgroundGeolocation.getLog().then(BackgroundGeolocation.destroyLog))

Sounds fair - this is the cheesiest sort of scaffolding but still better to do it right. At the same time, as I'm doing the async/await Promise consumption style, I was under the impression the getLog() would return before destroyLog() was called, so I wasn't at risk for anything racy? I suppose I could convert it to Promise style vs async/await but if I understand it the result would be the same. I certainly see expected log output on API18+

[mikehardy]

Also, while I like solutions and I've seen your super responsive support, I understand you are on vacation and this is not a blocker for me, just an item on a list for an unlaunched app for APIs that are cumulatively like 2% of global API penetration. No rush

[mikehardy]

Might be an easy one if vacation is over? I could fence any getLog() calls by API>16 but it would be nice to have the full React-Native API skew supported without NPEs. If there's anything you need from me, let me know and I'll have at it.

[christocracy]

I have added some guards in next beta (should be released today).

[mikehardy]

Thanks, I'll try it and close here if it's all good.

[mikehardy]

This now works on my API16 emulator so I will cavalierly assume it works on 17 and 18 emulators and my API17 device. It's a minor thing for a tiny population, but still nice to have a crash fix. Thanks

[christocracy]

There should be a log entry from the plugin.

It works or just doesn’t crash?

[mikehardy]

This is with the licensed plugin 3.0.0-rc.4 now, and this log was from an API16 emulator.

Just doesn't crash, works not quite, from the same code snippet above whether I comment out the destroyLog call or not:

03-30 15:00:14.398 2519-2673/com.kullki.kscore I/ReactNativeJS: 'unable to get logs?', 'Failed to fetch logs'
03-30 15:00:15.108 2519-2576/com.kullki.kscore E/TSLocationManager: [c.t.l.logger.TSLogReader getLog] 
      ‼️  Failed to open database

There is activity, the plugin seems to be working. Just not logs.

03-30 15:00:12.078 2519-2674/com.kullki.kscore D/TSLocationManager: [c.t.l.adapter.TSConfig c] ℹ️   Persist config
03-30 15:00:12.088 2519-2674/com.kullki.kscore E/TSLocationManager: [c.t.l.l.TSLocationManager getLastLocation] 
      ‼️  Failed to get last location: com.google.android.gms.tasks.zzu@b2402660
03-30 15:00:12.088 2519-2674/com.kullki.kscore D/TSLocationManager: [c.t.locationmanager.util.b a] 
      ℹ️  LocationAuthorization: Permission granted
03-30 15:00:12.088 2519-2550/com.kullki.kscore W/GooglePlayServicesUtil: Google Play services out of date.  Requires 11925000 but found 9256030
03-30 15:00:12.138 2519-2550/com.kullki.kscore W/GooglePlayServicesUtil: Google Play services out of date.  Requires 11925000 but found 9256030
03-30 15:00:12.158 2519-2681/com.kullki.kscore I/TSLocationManager: [c.t.l.http.HttpService flush] 
    ╔═════════════════════════════════════════════
    ║ HTTP Service (count: 0)
    ╠═════════════════════════════════════════════
03-30 15:00:12.168 2519-2550/com.kullki.kscore W/GooglePlayServicesUtil: Google Play services out of date.  Requires 11925000 but found 9256030
03-30 15:00:12.168 2519-2550/com.kullki.kscore W/GooglePlayServicesUtil: Google Play services out of date.  Requires 11925000 but found 9256030
03-30 15:00:12.328 2519-2673/com.kullki.kscore I/ReactNativeJS: '- BackgroundGeolocation is configured and ready: ', true
03-30 15:00:12.418 2519-2521/com.kullki.kscore D/dalvikvm: GC_CONCURRENT freed 1914K, 10% free 18091K/20039K, paused 20ms+28ms, total 72ms
03-30 15:00:12.418 2519-2519/com.kullki.kscore D/dalvikvm: WAIT_FOR_CONCURRENT_GC blocked 41ms
03-30 15:00:12.428 2519-2519/com.kullki.kscore D/dalvikvm: GC_FOR_ALLOC freed 222K, 11% free 18012K/20231K, paused 5ms, total 6ms
03-30 15:00:12.428 2519-2519/com.kullki.kscore I/dalvikvm-heap: Grow heap (frag case) to 17.758MB for 144156-byte allocation
03-30 15:00:12.438 2519-2519/com.kullki.kscore D/dalvikvm: GC_FOR_ALLOC freed 7K, 12% free 18145K/20423K, paused 5ms, total 5ms
03-30 15:00:12.448 2519-2519/com.kullki.kscore D/dalvikvm: GC_FOR_ALLOC freed <1K, 12% free 18147K/20423K, paused 5ms, total 5ms
03-30 15:00:12.448 2519-2519/com.kullki.kscore I/dalvikvm-heap: Grow heap (frag case) to 17.889MB for 144156-byte allocation
03-30 15:00:12.448 2519-2519/com.kullki.kscore D/dalvikvm: GC_FOR_ALLOC freed 0K, 12% free 18287K/20615K, paused 4ms, total 4ms
03-30 15:00:14.388 2519-2656/com.kullki.kscore E/TSLocationManager: [c.t.l.logger.TSLogReader getLog] 
      ‼️  Failed to open database
03-30 15:00:14.398 2519-2673/com.kullki.kscore I/ReactNativeJS: 'unable to get logs?', 'Failed to fetch logs'
03-30 15:00:15.108 2519-2576/com.kullki.kscore E/TSLocationManager: [c.t.l.logger.TSLogReader getLog] 
      ‼️  Failed to open database
03-30 15:00:15.108 2519-2673/com.kullki.kscore I/ReactNativeJS: 'unable to get logs?', 'Failed to fetch logs'
03-30 15:00:15.448 2519-2564/com.kullki.kscore E/TSLocationManager: [c.t.l.logger.TSLogReader getLog] 
      ‼️  Failed to open database
03-30 15:00:15.458 2519-2673/com.kullki.kscore I/ReactNativeJS: 'unable to get logs?', 'Failed to fetch logs'
03-30 15:00:23.348 2519-2519/com.kullki.kscore D/TSLocationManager: [c.t.l.service.HeartbeatService onStartCommand] ❤️