feat: [SDK-5065] add bounded retry/backoff to remote log export - #21
Conversation
Dropping OpenTelemetry silently removed retry behavior that OtlpHttpLogRecordExporter enabled by default: RetryUtil treated 429/502/503/504 as retryable and the okhttp sender's RetryInterceptor applied exponential backoff with jitter across ~5 attempts. The hand-rolled replacement did one POST and dropped the batch, so a transient 503 permanently lost up to 100 records and a 429 was ignored instead of backed off. Adds ExportRetrier in the shared batch/export path, so Android and iOS both inherit it: 5 attempts, 1s initial backoff x1.6 up to 5s, 20% jitter, 15s total elapsed ceiling. 429/502/503/504, transport failures (statusCode -1) and thrown senders are retried; 4xx and the -2 "logging disabled" sentinel are not. Waiting uses delay so cancellation propagates. The crash-upload path is untouched — it already retries across launches. No change to the ILogHttpSender/LogHttpResponse contract; retryability is derived from the statusCode both platform senders already report. Co-authored-by: Cursor <cursoragent@cursor.com>
|
Retry path looks right for fast 429/503. A few things the claims and tests don't currently pin down:
Happy to ignore the rest (500 not retried, no |
…andling Three issues from review, plus the tests that were supposed to be protecting against them. The elapsed ceiling only gated the backoff delay, not the next attempt. With a 10s HTTP timeout on both platforms a run could reach ~21s against a documented 15s ceiling, while the caller stayed blocked on it. Re-checks the budget after sleeping. LogBatchProcessor caught Exception, and CancellationException is an Exception in Kotlin, so the consumer swallowed cancellation and spun until isActive flipped. Rethrows it. The catch in attemptPost that a reviewer asked about is load-bearing for the same reason, so the comment now says why rather than leaving it looking redundant. Without it a cancelled send is classified RETRYABLE and the retrier keeps posting; on the paths that return before the next delay() the cancellation is lost entirely. Test changes, all of which I confirmed fail against the pre-fix code: - The cancellation test threw from a lambda handed straight to ExportRetrier.execute, which never reaches attemptPost — it passed with the guard deleted. Replaced with one that drives a cancelling sender through the real telemetry. - The elapsed-cap test advanced its clock on every read, so the result tracked how many times the retrier happened to call nowMillis() rather than elapsed time, and asserted `attempts < 10` where the answer is 2. Now uses virtual time and pins the count. - The crash path staying single-shot was untested: every existing case used 500, which is PERMANENT and yields one attempt either way, so routing exportEncoded through the retrier would have stayed green. Adds 503 and throwing-sender cases. - "Same batch re-posted" compared payload lengths, which passes for any two distinct payloads of equal size. Compares contents. - FakeHttpSender drained its queues outside the mutex guarding sentRequests. Co-authored-by: Cursor <cursoragent@cursor.com>
iOS returned the -1 transport sentinel both when a request got no usable response and when the URL could not be constructed at all. The first is worth retrying; the second fails identically every time, so a malformed base URL or app id burned all five attempts and ~10s of backoff on every batch, forever, with the pipeline blocked behind it. That is exactly what the PERMANENT classification exists to prevent. iOS now reports -3 for the unbuildable case, which the shared policy already classifies as permanent via its catch-all. Documents the distinction on TRANSPORT_FAILURE_STATUS_CODE so the next sender implementation does not collapse the two again, and pins -3 with a test. Co-authored-by: Cursor <cursoragent@cursor.com>
The elapsed ceiling could not do what it claimed. It was only ever checked between attempts, so an attempt starting just inside the budget still ran to the sender's own 10s timeout, and against connect timeouts — the slow-failure case retry exists for — a 15s ceiling yielded ~2 attempts instead of the 5 the policy advertised. Charge the budget against sleeping only (maxTotalBackoffMillis) so the attempt count is the real bound and holds regardless of how slow each attempt is, and state the resulting worst case (attempts x sender timeout plus backoff) plainly instead of a stall bound nothing enforces. Teardown gets an explicit lever instead. shutdown() completes an abort signal that wakes an in-flight backoff immediately, so a disable landing on a backend blip no longer queues behind a retry cycle whose delays alone (~9s) outlast the 5s flush budget — which on Android blocks a lifecycle thread and then drops the batch anyway. Raising the flush timeout would only block that thread longer. Tests pin the backoff schedule, the jitter factor, the budget clamp, and both abort behaviours in virtual time. Co-authored-by: Cursor <cursoragent@cursor.com>
|
Thanks — all three land. Partly addressed as of 3. Tests — mostly done. You're right that nothing asserts backoff duration — that's still missing. With 1. Elapsed cap — you're right, and the second half is the part I'd underweighted. I'd added a budget re-check after the backoff, which stops a new attempt starting once the budget is spent but does nothing about an attempt that starts just inside it and then sits on a 10s sender timeout. So the ceiling still isn't a wall-clock bound. The observation that a 15s ceiling against 10s timeouts yields ~2 attempts rather than 5 is the sharper problem: the policy under-delivers precisely on the slow-failure case retry exists for, and no wording change fixes that. Leaning toward charging the ceiling against cumulative backoff only — it makes the attempt count predictable and honest, at the cost of a real worst case of 2. Shutdown budget — not addressed yet, and it's worse than the numbers suggest. Agreed on the 5s-vs-~9s mismatch. The part that makes it urgent is where that path runs from: on Android Planning to cancel the in-flight export rather than align the budgets. Raising the timeout just means blocking a lifecycle thread longer for a batch we're likely to drop regardless. Agreed on leaving 500-not-retried and Will follow up here when 1 and 2 are pushed. |
|
Following up as promised — 1 and 2 are pushed in 1. Elapsed cap. Took your first option: the ceiling is charged against backoff only. Your second sentence is what decided it. A wall-clock ceiling isn't enforceable here at all — The cost, now stated plainly in the
2. Shutdown. Cancelling rather than aligning budgets, for the reason you gave. Abort stops retrying without cancelling work, so the attempt in flight finishes and shutdown's flush still gets one honest post. I did not requeue the aborted batch — it's mid-retry precisely because the backend is rejecting it, so a final attempt just buys another round trip during teardown. Happy to change that if you'd rather keep it. 3. Backoff duration. Every new test was run against a deliberately broken implementation first and observed to fail, one perturbation at a time. The one I'd single out is 18 tests, 0 failures on both |
|
nits:
|
…-test tradeoff The classify comment listed only -2 among the permanent sentinels, so -3 "request could not be built" looked like it fell through by accident rather than by design. Both are now named at the branch that decides it. Also records why the shutdown abort is covered where it is. Removing `abortSignal = shutdownSignal` from exportBatch makes shutdownFlushesOnceWithoutEnteringARetryCycle post three times instead of once, so the integration guard does exist — but its setup aborts before the retry cycle rather than during a backoff. I tried the variant that parks first and it passed against that same broken build: shutdown() is deliberately non-suspend and uses runBlocking, so it does not interleave with runTest's virtual clock and the assertion observes nothing. Dropped it rather than ship a test that asserts nothing, and noted the constraint so the next person does not rediscover it. Co-authored-by: Cursor <cursoragent@cursor.com>
|
All three fair.
Integration test of The coverage does exist, just not where the name suggests: What it doesn't do is park in a backoff first, so I wrote the variant you're describing. It passed against that same broken build — asserting nothing. The reason is structural: If you'd rather have that case covered end to end, the way in is making 18 tests, 0 failures on |
What OTel did by default, and what we lost
The remote-log exporter used to be
OtlpHttpLogRecordExporter, which came with retryturned on without anyone writing a config line for it — which is exactly why nobody
noticed when it went away. In the pinned
1.55.0:io/opentelemetry/exporter/internal/RetryUtilhardcodes the retryable HTTP statuses429, 502, 503, 504.
opentelemetry-exporter-sender-okhttpships aRetryInterceptorthat appliesexponential backoff with jitter across roughly 5 attempts.
The hand-rolled replacement does one POST and throws the batch away:
LogBatchProcessorcaught the export failure and deliberately dropped("best-effort drop (no retry)"), and
LogTelemetryRemoteImpl.exportBatchdiscardedpost()'s return value, so a 503 was indistinguishable from a 200.Consequence: one transient backend blip permanently lost up to 100 remote log records
(
maxQueueSize/maxExportBatchSizeare both 100), and a 429 was ignored rather thanbacked off, so a rate-limited client kept posting at the same cadence.
Retry policy
ExportRetrier(kmp/src/commonMain/.../internal/LogExportRetry.kt) sits in the sharedbatch/export path, so Android and iOS both inherit it. Defaults mirror OTel's:
What is and is not bounded. The attempt count is the real bound, and it holds no
matter how slow each attempt is. The 15s is charged against sleeping only, and at 5
attempts the schedule already sums to ~9.3s, so it binds only if
maxAttemptsis raised;it is there so raising it cannot silently produce an unbounded sleep. The final backoff is
clamped to whatever budget is left.
There is deliberately no wall-clock ceiling. This retrier cannot cancel a send once it
is running —
ILogHttpSendertakes no deadline and neither platform implementation acceptsone — so a wall-clock ceiling could only be checked between attempts, which bounds nothing:
an attempt starting just inside the budget still runs to the sender's own 10s timeout. It
also under-delivers exactly where retry matters most; against connect timeouts a 15s
ceiling with 10s timeouts yields ~2 attempts, not 5. So the honest statement of the worst
case for one export is
maxAttempts × senderTimeout + total backoff— ~59s with today'sdefaults — on a background export coroutine with no caller blocked on it.
Retryable vs permanent.
classifyStatustreats 429/502/503/504 as retryable, plustransport-level failures — a thrown sender, or
statusCode == -1, the sentinel bothplatform senders already return when there is no HTTP response (DNS, timeout, reset).
Everything else is permanent: 4xx, the
-2"remote logging disabled" sentinel, and the-3"could not build the request" sentinel iOS returns(OneSignal-iOS-SDK#1727).
No contract change.
ILogHttpSender/LogHttpResponseare untouched — retryabilityis derived entirely from the
statusCodeboth senders already report, so there is nofollow-up needed in the Android or iOS repos.
Retry-Afteris not honored — deliberately. Neither platform sender surfaces responseheaders, so plumbing it through means adding a field to
LogHttpResponse. Kotlin defaultarguments are not exported to Objective-C, so a new constructor parameter would break the
Swift build until the iOS repo was updated in lockstep. That is not cheap, so it is left
out rather than half-done. Jittered exponential backoff still de-escalates against a 429.
Teardown
Retrying happens inside
onExport, which the batch processor runs underexportMutex—the same mutex
forceFlushandshutdownneed. A teardown landing mid-retry wouldtherefore queue behind a cycle whose backoffs alone (~9s) outlast the 5s shutdown flush
budget: the caller blocks for the full 5s and the batch is dropped anyway. On Android that
caller is a lifecycle thread — a log-level change routes through
LoggerLifecycleManagerunder
runBlocking— so a config change during a backend degradation would deterministicallystall it.
shutdown()completes an abort signal before asking for the flush. That wakes an in-flightbackoff immediately and stops further attempts, so the wait collapses to at most the single
attempt already in flight. Raising the flush timeout instead would just block that lifecycle
thread longer. The aborted batch is not requeued: it is mid-retry precisely because the
backend is rejecting it, so a final attempt would only cost another round trip during
teardown.
enqueueonly takes the separate buffer mutex, so new records keep flowing while a retry isin flight; they fill the existing bounded queue and are dropped past
maxQueueSizeasbefore. Only the batch under retry is held, so memory is capped at two batches. Waiting is
suspension, never a blocking sleep, and
CancellationExceptionpropagates.Happy path is unchanged: one POST, no added latency, no delay ever entered.
Out of scope
The crash-upload path is untouched.
LogCrashUploader.sendReportsalready retriescorrectly — it deletes a record only after success and breaks on first failure, so
failures retry on the next launch.
exportEncoded, which it calls, still uses theoriginal single-shot
post, and two tests pin that split.Tests
kmp/src/commonTest/kotlin/com/onesignal/logger/LogExportRetryTest.kt, 18 tests, using theexisting
FakeHttpSender(which gained anexceptionsqueue so a send can throw). Timingis asserted in virtual time via the
runTestscheduler, so there are no wall-clock sleeps.happyPathPostsExactlyOnceretryableStatusIsRetriedUntilSuccess(503 → 429 → 200, same body each attempt)transportFailureIsRetried(thrown sender, then-1, then 200)permanentStatusIsNotRetried(400)attemptCapIsHonoredWhenBackendKeepsFailingexportEncodedIsNotRetriedOnARetryableStatus/...WhenTheSenderThrows(crash path stays single-shot)backoffFollowsTheAdvertisedSchedule(1000/1600/2560/4096/5000/5000 — the table above)jitterScalesEachDelayByTheConfiguredFactor(±20%)theBackoffBudgetClampsTheLastDelayAndThenStopsRetryingtheAttemptCapHoldsNoMatterHowSlowEachAttemptIs(10s attempts still get all 5)anAbortSignalWakesAnInFlightBackoffImmediatelyanAlreadyAbortedSignalStillLetsTheAttemptInFlightFinishshutdownFlushesOnceWithoutEnteringARetryCycleaCancelledSenderIsNotReclassifiedAsATransientFailurecancellationDuringBackoffDelayPropagatesaRequestThatCouldNotBeBuiltIsPermanent,classifiesStatusCodesEvery test was checked against a deliberately broken implementation and observed to fail:
dropping the per-delay cap and the jitter breaks the three schedule tests; wrapping the loop
in a wall-clock
withTimeoutdropstheAttemptCapHolds...to 2 attempts; replacing theabort-aware wait with a plain
delaybreaks both abort tests; and removing theshutdownSignal.complete(...)line makesshutdownFlushesOnce...post 3 times before the5s budget cancels it.
./gradlew :kmp:allTests spotlessCheckpasses. Confirmed from the result XML that all 18ran with 0 failures on both
iosSimulatorArm64TestandtestDebugUnitTest.