RUM-18168: Fix DataFlusher racing the upload scheduler and duplicating events - #3739
RUM-18168: Fix DataFlusher racing the upload scheduler and duplicating events#3739abrooksv wants to merge 1 commit into
Conversation
|
@codex review this |
![chatgpt-codex-connector[bot]](https://avatars.githubusercontent.com/in/1144995?s=60&v=4){kind=small}
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 8bda85e6be
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
8bda85e to
2f3eb85
Compare
🎉 All green!🧪 All tests passed 🎯 Code Coverage (details) 🔗 Commit SHA: 0bc3ef6 | Docs | View more details | Give us feedback! |
Codecov Report✅ All modified and coverable lines are covered by tests. Additional details and impacted files@@ Coverage Diff @@
## develop #3739 +/- ##
===========================================
- Coverage 73.44% 73.13% -0.31%
===========================================
Files 999 999
Lines 36575 36588 +13
Branches 6183 6321 +138
===========================================
- Hits 26860 26756 -104
- Misses 7994 8023 +29
- Partials 1721 1809 +88
🚀 New features to boost your workflow:
|
8182909 to
52294aa
Compare
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 52294aa22c
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| // uploadExecutorService can be mid-upload when this runs, and only NETWORK_TIMEOUT_MS | ||
| // bounds how long that upload can take. Failing to wait long enough here can lead to | ||
| // a DataFlusher race where it uploads the same batch twice. See RUM-18168. | ||
| awaitTerminationLogged(uploadExecutorService, "uploadExecutorService", NETWORK_TIMEOUT_MS, TimeUnit.MILLISECONDS) |
There was a problem hiding this comment.
When a running upload job contains multiple batches, this timeout does not guarantee that it has finished: DataUploadRunnable.run() can perform 20 sequential uploads by default, or 100 at HIGH, while NETWORK_TIMEOUT_MS bounds only each individual HTTP call. If two successful requests cumulatively exceed 45 seconds, awaitTermination returns false and flushStoredData() proceeds to DataFlusher, which directly enumerates files and can upload the batch still owned by the active runnable, reproducing the duplicate-event race this change is intended to fix. Do not proceed with the direct-file flush until the whole active upload job has terminated, or coordinate the flusher through the same batch-locking mechanism.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
While true, this code path is only in support of our end to end tests and so batches should be ideally only 1 or 2 so it should be ok, we can revisit if its still flaky, since it would probably require making data flusher more aware of the how the uploader works
…g events DataFlusher.flush() (the explicit Flush() call) can race the SDK's own periodic upload scheduler: both can independently claim and upload the same on-disk batch file, producing duplicate RUM events. drainAndShutdownExecutors() shuts down the persistence/upload executors and waits for them to terminate before DataFlusher runs, but it waited only DRAIN_WAIT_SECONDS (10s) - shorter than the upload call's own timeout (NETWORK_TIMEOUT_MS, 45s). An in-flight upload could still be running when that wait gave up, so drainAndShutdownExecutors() returned anyway while the upload kept racing DataFlusher for the same batch file. Fix: uploadExecutorService now waits up to NETWORK_TIMEOUT_MS instead of DRAIN_WAIT_SECONDS. Also log a warning if an executor doesn't terminate in time, so this doesn't silently regress.
52294aa to
0bc3ef6
Compare
0xnm
left a comment
0xnm
left a comment
There was a problem hiding this comment.
LGTM. But I guess PR title is wrong? There is no fix, but just logging?
| } | ||
| } | ||
|
|
||
| @Suppress("UnsafeThirdPartyFunctionCall") // Used in Nightly tests only |
There was a problem hiding this comment.
probably comment is wrong, we don't have nightlies anymore
Same question Nikita is asking. Is this implemented in the PR? |
|
Sorry, PR description not in sync with the commit description: but it still feels like a bandaid fix The root cause is the DataFlusher and Uploader are capable of running at the same time. Is a log showing 2 threads both uploaded the same batch with the same contents So the "fix" at the moment was to let give Uploader more time to finish its iteration of the Runnable, and then let DataFlusher start. Edit: Taking another look at this to see if a more robust fix can be made, will ping with what I find |
4 participants
What does this PR do?
DataFlusher.flush() read batch files directly from FileOrchestrator.getFlushableFiles(), bypassing ConsentAwareStorage's lockedReadBatches tracking. This let an explicit Flush() call and the SDK's own regular periodic upload scheduler independently claim and upload the same on-disk batch file at the same time, producing duplicate RUM events (confirmed via emulator repro with event-hash-level instrumentation).
Fix: route DataFlusher through Storage.readNextBatch()/confirmBatchRead() instead of FileOrchestrator directly, so a flush participates in the same lockedReadBatches coordination as every other reader.
At the old 10s bound, awaitTermination() timed out on every one of 8 on-device runs and reproduced the duplicate event in 2 of them; at the new bound (matching NETWORK_TIMEOUT_MS, 45s), 0 of 8 runs produced a duplicate.
Motivation
This should stabilize the RUM FIT test case
test_multipage_navigation_with_resource_loadingfor MAUI-AndroidBoth events are byte-identical, confirming a duplicate upload of a single logical resource event rather than two distinct events.
Reproduction log:
Additional Notes
Anything else we should know when reviewing?
Review checklist (to be filled by reviewers)