flutter_background_geolocation icon indicating copy to clipboard operation
flutter_background_geolocation copied to clipboard

Seeing NSInternalInconsistencyException Sending a message before the FlutterEngine has been run.

Open billysmt opened this issue 3 years ago • 15 comments

Your Environment

  • Plugin version: 4.3.2

  • Platform: iOS

  • OS version: 13+

  • Device manufacturer / model: Many,

  • Flutter info (flutter doctor):

  • [✓] Flutter (Channel stable, 2.8.1, on Pop!_OS 21.10 5.15.15-76051515-generic, locale en_US.UTF-8) [✓] Android toolchain - develop for Android devices (Android SDK version 32.0.0) [✓] Chrome - develop for the web [✓] Android Studio (version 2021.1) [✓] VS Code (version 1.60.1) [✓] Connected device (1 available)

  • Plugin config:

bg.Config config = bg.Config(
      locationAuthorizationRequest: 'Always',
      backgroundPermissionRationale: bg.PermissionRationale(
          title: "Allow access to this device's location in the background?",
          message:
              "This app utilizes location tracking in the background in order to allow Geofencing and Breadcrumbing while the app is closed or minimized.  The tracking is enabled while a job is active and disabled upon job completion.  Please enable 'Allow all the time' permission in order to allow gathering of data in the background.",
          positiveAction: "Change to Allow all the time",
          negativeAction: "Cancel"),
      desiredAccuracy: bg.Config.DESIRED_ACCURACY_HIGH,
      scheduleUseAlarmManager: true,
      stopTimeout: 60,
      enableHeadless: false,
      stopOnTerminate: true,
      startOnBoot: false,
      logLevel: bg.Config.LOG_LEVEL_ERROR,
      url: url,
      autoSync: true,
      autoSyncThreshold: 50,
      maxDaysToPersist: 7,
      batchSync: true,
      enableTimestampMeta: true,
      geofenceInitialTriggerEntry: true,
      maxBatchSize: 100,
      headers: headers,
      locationsOrderDirection: "DESC",
      locationTemplate:
          '{"latitude":<%= latitude %>,"longitude":<%= longitude %>,"event":"<%= event %>","isMoving":<%= is_moving %>, "crumbDate":"<%= timestamp %>", "speed": <%= speed %>, "accuracy": <%= accuracy %>, "heading": <%= heading %>, "altitude": <%= altitude %>, "uuid": "<%= uuid %>"}',
      geofenceTemplate:
          '{"latitude":<%= latitude %>,"longitude":<%= longitude %>,"event":"<%= event %>","isMoving":<%= is_moving %>, "crumbDate":"<%= timestamp %>", "speed": <%= speed %>, "accuracy": <%= accuracy %>, "heading": <%= heading %>, "altitude": <%= altitude %>, "uuid": "<%= uuid %>", "locationId": <%= geofence.identifier %>, "action": "<%= geofence.action %>"}',
      httpRootProperty: "breadcrumbs",
      extras: params,
      params: params,

      //
      distanceFilter: 1500.0,
      elasticityMultiplier: 0.0,

      /// Debug Parameters for testing.
      // debug: true,                    // Causes Audio tone to play on event.
      // isMoving: true,                 // Default GeoTracking into Active State
      // distanceFilter: 0,              // Must be 0 or locationUpdateInterval is ignored!
      // locationUpdateInterval: 10000,  // Get a location every 10 seconds
    );

Expected Behavior

Shouldn't see this error.

Actual Behavior

Sees this error in our prod logs but doesn't seem to appear in our testing. Assuming it's a lifecycle issue but haven't tracked it down yet.

Runner +0x592d5c __62-[EnabledChangeStreamHandler onListenWithArguments:eventSink:]_block_invoke (programs/flutter_2_8_1/.pub-cache/hosted/pub.dartlang.org/flutter_background_geolocation-4.3.2/ios/Classes/streams/EnabledChangeStreamHandler.m:14) Runner +0x4eeadc __25-[TSLocationManager init]_block_invoke_2 Runner +0x524cf0 -[TSQueue runOnMainQueueWithoutDeadlocking:] Runner +0x4ee9b0 __25-[TSLocationManager init]_block_invoke Runner +0x4de938 -[TSConfig fireOnChange:value:] Runner +0x4df264 -[TSConfig observeValueForKeyPath:ofObject:change:context:] Called from: Foundation +0x10be18 NSKeyValueNotifyObserver Runner +0x4f1afc -[TSLocationManager stop] Runner +0x500694 -[TSLocationManager onAppTerminate] Called from: CoreFoundation +0x084d6c CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER Runner +0x007160 main (AppDelegate.swift:7) Called from: libdyld +0x001cf4 start

Steps to Reproduce

  1. Haven't been able to reproduce

Context

We upgraded the dependency version in our pubspec in our last update from 4.3.0 and started seeing the error after release

Debug logs

Haven't replicated locally but we use Sentry for our prod Error Reporting and this is the Error Summary.

Logs
Runner
+0x592d5c
__62-[EnabledChangeStreamHandler onListenWithArguments:eventSink:]_block_invoke
(programs/flutter_2_8_1/.pub-cache/hosted/pub.dartlang.org/flutter_background_geolocation-4.3.2/ios/Classes/streams/EnabledChangeStreamHandler.m:14)
Runner
+0x4eeadc
__25-[TSLocationManager init]_block_invoke_2
Runner
+0x524cf0
-[TSQueue runOnMainQueueWithoutDeadlocking:]
Runner
+0x4ee9b0
__25-[TSLocationManager init]_block_invoke
Runner
+0x4de938
-[TSConfig fireOnChange:value:]
Runner
+0x4df264
-[TSConfig observeValueForKeyPath:ofObject:change:context:]
Called from:
Foundation
+0x10be18
NSKeyValueNotifyObserver
Runner
+0x4f1afc
-[TSLocationManager stop]
Runner
+0x500694
-[TSLocationManager onAppTerminate]
Called from:
CoreFoundation
+0x084d6c
__CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER__
Runner
+0x007160
main
(AppDelegate.swift:7)
Called from:
libdyld
+0x001cf4
start

billysmt avatar Feb 01 '22 09:02 billysmt

"locationId": <%= geofence.identifier %>

geofence.identifier is a String. You are not wrapping it with double-quotes. ””.

you should be able to reproduce this in the simulator by causing a geofence event to fire.

christocracy avatar Feb 01 '22 14:02 christocracy

I see few similar points. We've been receiving identical crash as well. It happens on different iOS versions. And we recently upgraded flutter to 2.8.1 and flutter_background_geolocation library to 4.3.3. During the test phase we got over 10 crashes like this on crashlytics. Each of them involved killing the app and reopening it, according to our testers. I personally got that a few days ago, for few times in a row, and it was caused just by tapping twice home button, then swiping the app up. Maybe it's worth mentioning that there were already two or more locations in close proximity to my gps location (we listen to locations and setup geofences around the user).

But the latest release we're working on, included flutter upgrade from 2.5.3 to 2.8.1. We've also updated flutter_background_geolocation from 4.0.2 to 4.3.3 as jcenter deprecation prevented us from building android. I can't reproduce the crash reliably, but judging by somewhat related threads on flutter github, it might be a flutter issue. https://github.com/flutter/flutter/issues/96901

They also pointed out that library developers should use new callback for freeing the resources when the flutter engine gets disposed. https://github.com/flutter/flutter/issues/44256#issuecomment-583507578

I didn't dive deep into that yet, but I'm leaving this comment as a hint to anyone receiving similar crash logs. I'm currently considering to temporarily downgrade flutter for the next release of our app, as the 2.8.1 version is broken in few other places.

igorczapski avatar Feb 07 '22 14:02 igorczapski

Thanks @igorczapski, I will investigate.

christocracy avatar Feb 07 '22 14:02 christocracy

In the case of the OP's stack-trace, I think I see what's going on, given that your app is configured to stopOnTerminate: true.

- EnabledChangeStreamHandler.m:14
-[TSConfig fireOnChange:value:]
-[TSConfig observeValueForKeyPath:ofObject:change:context:]
- NSKeyValueNotifyObserver
- [see #2] [TSLocationManager stop]
- [see #1] [TSLocationManager onAppTerminate]

The plugin's native library TSLocationManager has an app-terminate handler:


// #1
-(void) onAppTerminate
{
    NSUserDefaults *userDefaults = [NSUserDefaults standardUserDefaults];
    TSLog *log = [TSLog sharedInstance];
    TSConfig *config = [TSConfig sharedInstance];
    DDLogNotice(@"stopOnTerminate? %d", config.stopOnTerminate);
    
    [self stopHeartbeat];
    if (config.stopOnTerminate) {        
        [self stop];  // <------------------------ #2 here.
    }
    .
    .
    .

Calling stop will modify the plugin's Config.enabled. The plugin's Configuration is stored in a class which persists its values in iOS NSUserDefaults (The same place where Flutter's shared_preferences stores its values, but this is not important). The plugin's Config has a value observer upon it NSKeyValueNotifyObserver which allows the plugin to subscribe to Configuration changes anywhere throughout the code and modify its behaviour accordingly and possibly fire an event.

When the value Config.enabled is changed (as a results of having [self stop] called upon it, the onEnabledChange event is fired. However, as @igorczapski points out, due to recent changes in the Flutter engine, this may be causing the plugin to attempt to fire your dart onEnabledChange` listener where the engine no longer exists.

I think it might make sense for the plugin to simply remove all its event-subscribers in the onAppTerminate handler. This will prevent any events from TSLocationManager being emitted to the Flutter code when an app is on its way to being terminated.

-(void) onAppTerminate
{
    [self removeListeners];  <-- will add this
    .
    .
    .
}

christocracy avatar Feb 07 '22 16:02 christocracy

In short, this crash is occurring in an app which has been instructed to be terminated. In its dying breaths, the plugin attempts to fire the onEnabledChanged event to your dart code but the Flutter engine seems to no longer exist to deliver that event, logging a final exception in an app that was in the final stages of of being terminated anyway.

christocracy avatar Feb 07 '22 16:02 christocracy

My app is also configured to stopOnTerminate: true, so I am seeing this a lot. Happens when force quitting the app. Looking forward to the update.

ozzy1873 avatar Feb 12 '22 12:02 ozzy1873

Version 4.3.4 is released with this new code added:

-(void) onAppTerminate
{
    [self removeListeners];  <-- will add this
    .
    .
    .
}

christocracy avatar Feb 21 '22 15:02 christocracy

This update fixed the crash for my app on iOS. Thanks!

ozzy1873 avatar Feb 21 '22 15:02 ozzy1873

@billysmt and @igorczapski ?

christocracy avatar Feb 21 '22 15:02 christocracy

Sorry for the delay. I'm not seeing it on my end. We're going into more in depth testing so I'll keep an eye on our logs but so far sounds promising.

billysmt avatar Feb 25 '22 04:02 billysmt

Sorry for late response. I conducted several tests and there were no crashes anymore. But the new app version went live with downgraded flutter, and it avoids the problem as well. Soon we will update flutter again, and your library as well. If this problem still occurs, I'll let you know. For now it looks like your fix can work.

igorczapski avatar Mar 01 '22 10:03 igorczapski

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions. You may also mark this issue as a "discussion" and I will leave this open.

stale[bot] avatar Apr 30 '22 17:04 stale[bot]

Sorry for late response. I conducted several tests and there were no crashes anymore. But the new app version went live with downgraded flutter, and it avoids the problem as well. Soon we will update flutter again, and your library as well. If this problem still occurs, I'll let you know. For now it looks like your fix can work.

Any update since then?

rtokun avatar Oct 30 '22 12:10 rtokun

Nobody else has reported this.

have you updated to latest version? See the CHANGELOG.

christocracy avatar Oct 30 '22 14:10 christocracy

Same issue, using the latest version of plugin.

Same Log as #285

sikandernoori avatar Nov 02 '22 11:11 sikandernoori