Nearly identical location records saved to SQLLite DB 10 minutes apart; What does event:null mean?

[trupsis]

Two issues/questions.

1) Why are we seeing nearly identical records inserted to the SQLLite db 10 minutes apart? In the attached log, see that UUID=24cbed22-c547-43b1-b9b9-ae0e0e7c7bca is inserted to the db at 04-11 07:24:07.830 (IST) and then UUID 4faa7d99-b8d2-4412-a415-84df5c4f9a6d is inserted to the db at 04-11 07:34:09.860 (IST). The records have identical timestamp and location data. The only differences are is_moving (true on the first, false on the second), age (90 on the first, 602120 on the second), and activity.type (walking on the first, still on the second). The device was set to GPS enabled but no network access during this timeframe.

2) Why is event: null in nearly every record? The documentation says it is a string and should have a value of motionchange, geofence, or heartbeat. Yet, throughout the entire period of this test, only a few records ever reflect one of those values.

Your Environment

System: OS: macOS 14.4.1 CPU: (8) arm64 Apple M2 Memory: 107.06 MB / 8.00 GB Shell: 5.9 - /bin/zsh Binaries: Node: 16.20.2 - ~/.nvm/versions/node/v16.20.2/bin/node Yarn: 1.22.21 - ~/Documents/GitHub/alt-tomrex-app/node_modules/.bin/yarn npm: 8.19.4 - ~/.nvm/versions/node/v16.20.2/bin/npm Watchman: 2024.01.22.00 - /opt/homebrew/bin/watchman Managers: CocoaPods: 1.15.0 - /opt/homebrew/bin/pod SDKs: iOS SDK: Platforms: DriverKit 23.2, iOS 17.2, macOS 14.2, tvOS 17.2, visionOS 1.0, watchOS 10.2 Android SDK: Not Found IDEs: Android Studio: 2023.1 AI-231.9392.1.2311.11330709 Xcode: 15.2/15C500b - /usr/bin/xcodebuild Languages: Java: 15.0.2 - /usr/bin/javac npmPackages: @react-native-community/cli: Not Found react: 16.13.1 => 16.13.1 react-native: ^0.64.0 => 0.64.4 react-native-macos: Not Found npmGlobalPackages: react-native: Not Found Plugin version: "react-native-background-geolocation": "^4.15.0" Platform: iOS or Android : Android OS version: 12 Device manufacturer / model: realme 7 pro React Native version (react-native -v): 0.64.0

{
  "activityRecognitionInterval": 10000,
  "allowIdenticalLocations": false,
  "authorization": {},
  "autoSync": true,
  "autoSyncThreshold": 5,
  "backgroundPermissionRationale": {
    "title": "Allow {applicationName} to access this device's location even when closed or not in use.",
    "message": "This app collects location data to enable recording your trips to work and calculate distance-travelled.",
    "positiveAction": "Change to \"{backgroundPermissionOptionLabel}\"",
    "negativeAction": "Cancel"
  },
  "batchSync": true,
  "configUrl": "",
  "debug": false,
  "deferTime": 0,
  "desiredAccuracy": -1,
  "desiredOdometerAccuracy": 100,
  "disableAutoSyncOnCellular": false,
  "disableElasticity": false,
  "disableLocationAuthorizationAlert": false,
  "disableMotionActivityUpdates": false,
  "disableProviderChangeRecord": true,
  "disableStopDetection": false,
  "distanceFilter": 1,
  "elasticityMultiplier": 1,
  "enableHeadless": true,
  "enableTimestampMeta": false,
  "extras": {},
  "fastestLocationUpdateInterval": -1,
  "foregroundService": true,
  "geofenceInitialTriggerEntry": true,
  "geofenceModeHighAccuracy": false,
  "geofenceProximityRadius": 1000,
  "geofenceTemplate": "",
  "headers": {
    "authorization": "Bearer Ai6mnkLi0sjgwKvrSJcf4G\/CHaVHc5dt5IeGiootxk8=",
    "source": "92.204.135.120"
  },
  "headlessJobService": "com.transistorsoft.rnbackgroundgeolocation.HeadlessTask",
  "heartbeatInterval": -1,
  "httpRootProperty": "location",
  "httpTimeout": 60000,
  "isMoving": false,
  "locationAuthorizationRequest": "Always",
  "locationTemplate": "",
  "locationTimeout": 60,
  "locationUpdateInterval": 1000,
  "locationsOrderDirection": "ASC",
  "logLevel": 5,
  "logMaxDays": 5,
  "maxBatchSize": 10,
  "maxDaysToPersist": 3,
  "maxMonitoredGeofences": 97,
  "maxRecordsToPersist": -1,
  "method": "POST",
  "minimumActivityRecognitionConfidence": 75,
  "motionTriggerDelay": 0,
  "notification": {
    "layout": "",
    "title": "",
    "text": "Location Service activated",
    "color": "",
    "channelName": "TSLocationManager",
    "channelId": "",
    "smallIcon": "",
    "largeIcon": "",
    "priority": -1,
    "sticky": false,
    "strings": {},
    "actions": []
  },
  "params": {
    "ClientId": 61
  },
  "persist": true,
  "persistMode": 2,
  "schedule": [],
  "scheduleUseAlarmManager": false,
  "speedJumpFilter": 300,
  "startOnBoot": true,
  "stationaryRadius": 25,
  "stopAfterElapsedMinutes": 0,
  "stopOnStationary": false,
  "stopOnTerminate": false,
  "stopTimeout": 5,
  "triggerActivities": "in_vehicle, on_bicycle, on_foot, running, walking",
  "url": "http:\/\/92.204.135.120:8099\/TomAPI\/SaveLocationInformation",
  "useSignificantChangesOnly": false,
  "enabled": true,
  "schedulerEnabled": false,
  "trackingMode": 1,
  "odometer": 30886.90625,
  "isFirstBoot": false,
  "didLaunchInBackground": false,
  "didDeviceReboot": false
}

Expected Behavior

A location record should only be inserted to the SQLLite database a single time. Each record should have one of the defined event values.

Actual Behavior

While offline (network access turned off), we see the same location inserted to the database multiple times. In some other tests, this has happened many more times than just twice. Event values on posted data nearly always has event:null.

Steps to Reproduce

Put device into offline mode while keeping GPS enabled. Walk, drive, or otherwise move around (to ensure different GPS locations are recorded as in our test data).

Context

We are trying to figure out how the library is producing so many redundant submissions to our API. In our production environment, we are seeing API posts that grew and grew and grew. We have since limited the maxBatchSize to 10, but the batching is not stopping the duplicate insertions. We can't figure out why the library is inserting nearly the same data 10 minutes apart. Somehow some part of the old data is being cached by the library and re-inserted after some other event?

Debug logs

Logs

[APILog of ClientID_ 61.xlsx](https://github.com/transistorsoft/react-native-background-geolocation/files/14949541/APILog.of.ClientID_.61.xlsx) [SuccessLogsRealme.log](https://github.com/transistorsoft/react-native-background-geolocation/files/14949542/SuccessLogsRealme.log) ``` PASTE_YOUR_LOGS_HERE ```

[trupsis]

FYI...the library log timestamps are in IST and the API log timestamps are in GMT.

[christocracy]

the library log timestamps are in IST and the API log timestamps are in GMT.

Yes, they are.

[trupsis]

Certainly didn't mean to imply that was the issue. Just trying to be helpful to figure out what's going on.

[trupsis]

Good morning, Chris. Just wanted to check to see if we can get any guidance on this issue? Thank you!

[christocracy]

It’s not unusual that a location with coords the same as the last could be inserted if the OS is only able to provide the last known location.

[trupsis]

Agreed, but the logs demonstrate pretty clearly that something else is happening here. There are something like 100 other locations inserted to the plugin db over that 10 minute gap. And we're getting large batches of repeated entries into the plugin db (with only the noted slight differences).

[christocracy]

"distanceFilter": 1,

You're using a very aggressive distanceFilter so you should expect a lot of data.

[trupsis]

Absolutely. But the question isn't "why are we getting a lot of data?" The question is "why are we getting the same big batches of data 10 minutes apart?"

[christocracy]

What timestamps from your logs is this phenomenon evidenced?

[trupsis]

In the attached log, see that UUID=24cbed22-c547-43b1-b9b9-ae0e0e7c7bca is inserted to the db at 04-11 07:24:07.830 (IST) and then UUID 4faa7d99-b8d2-4412-a415-84df5c4f9a6d is inserted to the db at 04-11 07:34:09.860 (IST).

The data associated with timestamps are also seen in the API log file. I believe the repeated batch is highlighted in red.

[christocracy]

And what is your HeadlessTask doing?

I'm not interested in your excel file. I'm only interested in my plugin's logs.

Which timestamp(s) in the log are you interested in me having a look at?

[trupsis]

I don't believe HeadlessTask is doing anything. We're using autoSync.

The reason we provided the API logs is that they show the data collected by the plugin where the plugin logs do not. That is how we know that nearly identical data is being inserted into the plugin db across relatively long time spans.

In the attached log, see that UUID=24cbed22-c547-43b1-b9b9-ae0e0e7c7bca is inserted to the db at 04-11 07:24:07.830 (IST) and then UUID 4faa7d99-b8d2-4412-a415-84df5c4f9a6d is inserted to the db at 04-11 07:34:09.860 (IST).

Those timestamps appear to be the initial insert of the data (age = 90) and the nearly identical second insert of the data (age = 602120).

[christocracy]

Each location has location.uuid attribute which you can use to match locations received at your server with those in the logs.

04-11 07:34:09.889 DEBUG [TrackingService c] 
╔═════════════════════════════════════════════
║ TrackingService: LocationResult
╠═════════════════════════════════════════════
╟─ 📍  Location[fused 30.69****,76.82**** hAcc=16.217 et=+53d21h19m47s108ms alt=298.8999938964844 vAcc=1.0378835 vel=1.0678389 sAcc=0.39258394 bear=358.5432 bAcc=45.0 {Bundle[{}]}]
╟─ Age: 597251ms, time: 1712800452637

04-11 07:34:09.890 INFO [TrackingService b] 
  ℹ️  Distance from stoppedAtLocation: -17.169628
04-11 07:34:09.890 DEBUG [AbstractService a] 
  ⚙️︎   FINISH [TrackingService startId: 9, eventCount: 0, sticky: true]
04-11 07:34:09.891 DEBUG [TSLocationManager onLocationResult] 
╔═════════════════════════════════════════════
║ Process LocationResult
╠═════════════════════════════════════════════

04-11 07:34:09.894 DEBUG [TSLocationManager a] Median accuracy: 7.571
04-11 07:34:09.897 INFO [SQLiteLocationDAO persist] 
  ✅  INSERT: 267ed2e0-529c-4532-828c-e97a33fa40b8   // <-------- UUID

[trupsis]

Exactly, we've done that which is how we know that this is not new original location data.

[christocracy]

Then tell me some particular location.uuid from your logs that you're interested in having a look at.

[trupsis]

Chris, I've listed this same UUID info several times...

In the attached log, see that UUID=24cbed22-c547-43b1-b9b9-ae0e0e7c7bca is inserted to the db at 04-11 07:24:07.830 (IST) and then UUID 4faa7d99-b8d2-4412-a415-84df5c4f9a6d is inserted to the db at 04-11 07:34:09.860 (IST).

[trupsis]

From the API log, UUID 24cbed22-c547-43b1-b9b9-ae0e0e7c7bca is in a batch of 10 on row 3 and has this data:

{"extras":{},"mock":false,"coords":{"ellipsoidal_altitude":0,"speed_accuracy":0,"longitude":76.8212026,"speed":0,"floor":null,"heading_accuracy":45,"latitude":30.6904803,"accuracy":0,"heading":0,"altitude":0,"altitude_accuracy":0},"is_moving":true,"event":null,"odometer":30886.9,"age":90,"uuid":"24cbed22-c547-43b1-b9b9-ae0e0e7c7bca","battery":{"level":0,"is_charging":false},"activity":{"type":"walking","confidence":100},"timestamp":"2024-04-11T01:54:07.725Z"}

From the API log, UUID 4faa7d99-b8d2-4412-a415-84df5c4f9a6d is in a batch of 10 on row 21 and has this data:

{"extras":{},"mock":false,"coords":{"ellipsoidal_altitude":0,"speed_accuracy":0,"longitude":76.8212026,"speed":0,"floor":null,"heading_accuracy":45,"latitude":30.6904803,"accuracy":0,"heading":0,"altitude":0,"altitude_accuracy":0},"is_moving":false,"event":null,"odometer":31103.1,"age":602120,"uuid":"4faa7d99-b8d2-4412-a415-84df5c4f9a6d","battery":{"level":0,"is_charging":false},"activity":{"type":"still","confidence":100},"timestamp":"2024-04-11T01:54:07.725Z"}

You can see that everything is identical except for age, is_moving, and activity.type.

[christocracy]

04-11 07:24:07.804 DEBUG [TrackingService c] 
╔═════════════════════════════════════════════
║ TrackingService: LocationResult
╠═════════════════════════════════════════════
╟─ 📍  Location[fused 30.69****,76.82**** hAcc=7.124 et=+53d21h19m42s195ms alt=298.8999938964844 vAcc=1.2393656 vel=0.40579644 sAcc=0.6762396 bear=58.323856 bAcc=45.0 {Bundle[{}]}]
╟─ Age: 76ms, time: 1712800447725

04-11 07:24:07.806 DEBUG [TSLocationManager onLocationResult] 
╔═════════════════════════════════════════════
║ Process LocationResult
╠═════════════════════════════════════════════

04-11 07:24:07.808 DEBUG [TSLocationManager a] Median accuracy: 7.124
04-11 07:24:07.811 INFO [TSScheduleManager cancelOneShot] 
  ⏰ Cancel OneShot: MOTION_ACTIVITY_CHECK
04-11 07:24:07.818 INFO [TSScheduleManager oneShot] 
  ⏰ Scheduled OneShot: MOTION_ACTIVITY_CHECK in 62010ms (jobID: -18513055)
04-11 07:24:07.824 DEBUG [AbstractService a] 
  ⚙️︎   FINISH [TrackingService startId: 4, eventCount: 0, sticky: true]
04-11 07:24:07.825 DEBUG [HeadlessTask onHeadlessEvent] 💀  event: location
04-11 07:24:07.828 DEBUG [HeadlessTask$2 onHeadlessJsTaskStart] taskId: 6
04-11 07:24:07.830 INFO [SQLiteLocationDAO persist] 
  ✅  INSERT: 24cbed22-c547-43b1-b9b9-ae0e0e7c7bca
04-11 07:24:07.830 DEBUG [HeadlessTask$2 onHeadlessJsTaskFinish] taskId: 6

04-11 07:34:09.853 DEBUG [TrackingService c] 
╔═════════════════════════════════════════════
║ TrackingService: LocationResult
╠═════════════════════════════════════════════
╟─ 📍  Location[fused 30.69****,76.82**** hAcc=11.967 et=+53d21h19m45s571ms alt=298.8999938964844 vAcc=1.027922 vel=0.70732665 sAcc=1.5 bear=9.93469 bAcc=45.0 {Bundle[{}]}]
╟─ Age: 598751ms, time: 1712800451100

04-11 07:34:09.854 INFO [TrackingService b] 
  ℹ️  Distance from stoppedAtLocation: -15.254843
04-11 07:34:09.854 DEBUG [AbstractService a] 
  ⚙️︎   FINISH [TrackingService startId: 6, eventCount: 0, sticky: true]
04-11 07:34:09.854 DEBUG [TSLocationManager onLocationResult] 
╔═════════════════════════════════════════════
║ Process LocationResult
╠═════════════════════════════════════════════

04-11 07:34:09.856 DEBUG [TSLocationManager a] Median accuracy: 7.124
04-11 07:34:09.860 INFO [SQLiteLocationDAO persist] 
  ✅  INSERT: 4faa7d99-b8d2-4412-a415-84df5c4f9a6d

These two locations were provided by the native location API stream while in the tracking state. They are separated by about 10 min, reflected by a high location.age of the second one. It seems the native location API had no fresh location to provide, so was left with only the "last known location".

[trupsis]

But, as you would have no doubt noticed as you scrolled through those logs, there were about 100 newer fresher location results received in that 10 minute gap.

[christocracy]

at ~ 07:34:08, your app was re-launched after being terminated (either by the user or the OS).

04-11 07:34:08.804 INFO [LoggerFacade$a a] 
╔═════════════════════════════════════════════
║ TSLocationManager version: 3.5.4 (433)
╠═════════════════════════════════════════════
╟─ realme RMX2170 @ 12 (react)
{

These locations you're receiving are being provided by the OS location stream. For some unknown reason, the native location API had no fresh location to provide. It was likely re-turning into GPS satellites.

[christocracy]

You're expected to filter your own data as-desired. The plugin will not perform any judgement upon the data.

[trupsis]

There was no fresh location data, so it re-played/re-inserted the last 100 received location records?

[christocracy]

There was no fresh location data, so it re-played/re-inserted the last 100 received location records?

on that particular device, yes. Realme devices tend to be some of the worst offenders for odd behaviour.

[trupsis]

Is there any situation where a large age number is not likely to be a redundant entry? It would be nice if we could filter based on age, event or some other attribute to know which data to trust as new.

The event value seems to nearly always be null even though the documentation says it should be something else. Is that another case of "the device is screwy"?

[christocracy]

Is there any situation where a large age number is not likely to be a redundant entry?

Yes, particularly on latest Android 14, where there are more strict limitations on when Foreground Services may be launched from the background (eg: calling .getCurrentPosition from the background where the plugin will at least return the last-known location if the OS doesn't allow location-services to be turned on).

The event value seems to nearly always be null even though the documentation

This isn't related to your issue.

[trupsis]

But is it possible to address the question anyway? It was one of the two original concerns we raised when logging this issue.

-- Tom Rupsis Granite Peak Systems Phone: 406-672-8292 Email: @.***

On Mon, Apr 15, 2024, 9:08 AM Chris Scott @.***> wrote:

Is there any situation where a large age number is not likely to be a redundant entry?

Yes, particularly on latest Android 14, where there are more strict limitations on when Foreground Services may be launched from the background (eg: calling .getCurrentPosition from the background where the plugin will at least return the last-known location if the OS doesn't allow location-services to be turned on).

The event value seems to nearly always be null even though the documentation

This isn't related to your issue.

— Reply to this email directly, view it on GitHub https://github.com/transistorsoft/react-native-background-geolocation/issues/1993#issuecomment-2057091244, or unsubscribe https://github.com/notifications/unsubscribe-auth/AF52MZ26VBBGPSRF5GX7KZTY5PUPDAVCNFSM6AAAAABGCXUXEKVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDANJXGA4TCMRUGQ . You are receiving this because you authored the thread.Message ID: <transistorsoft/react-native-background-geolocation/issues/1993/2057091244 @github.com>

[trupsis]

The event value seems to nearly always be null even though the documentation

This isn't related to your issue.

But is it possible to address the question anyway? It was one of the two original concerns we raised when logging this issue.

[trupsis]

Restating from original post...

Why is event: null in nearly every record? The documentation says it is a string and should have a value of motionchange, geofence, or heartbeat. Yet, throughout the entire period of this test, only a few records ever reflect one of those values.

[christocracy]

event param represents a location recorded from an event (eg onMotionChange, onProviderChange).

It’s supposed to generally be unset.