CXP-533 Improve event feeds context handling - #133
CXP-533 Improve event feeds context handling#133JavierCarnelli-ConductorOne wants to merge 13 commits into
Conversation
Each per-user (and per-app, for OAuth) Reports API activities.list call used no startTime and had no timeout of its own, so a single slow call could exceed the sync's overall deadline. Add a 180-day startTime bound (matches Google's Reports retention window and its documented guidance that narrower time ranges respond faster), a per-lookup sub-timeout that skips just that lookup instead of failing the whole batch, and widen maxResults to reduce pagination risk. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
| ctxzap.Extract(ctx).Warn("google-workspace-connector: timed out listing saml login activities, skipping", | ||
| zap.String("user", user.Email)) | ||
| return nil, nil |
There was a problem hiding this comment.
🟡 Suggestion: this warning fires once per user (and once per user+app in usage_event_feed.go), so a broadly slow or throttled tenant emits one line per user for every 25-user batch across the whole directory walk. Per repo logging guidance, a warning that can fire per-resource should use logarithmic sampling (1, 10, 100, every 1000) with a total_occurrences field rather than logging unconditionally.
There was a problem hiding this comment.
For this item I think we will test it first, since the Warn log is intended only for visibility when we first test this
Connector PR Review: CXP-533 Improve event feeds context handlingBlocking Issues: 0 | Suggestions: 0 new (1 prior still open) | Threads Resolved: 0 Review SummaryThe new commits are documentation and test-hygiene only: Security IssuesNone found. Correctness IssuesNone found. Suggestions
|
The per-lookup sub-deadline previously wrapped the whole retry loop (quota wait + backoff + all attempts), so a persistently throttled 429/503 lookup could get cut off mid-backoff and be misclassified as "one slow call, skip silently" instead of surfacing as retryable throttling. Scope a 25s timeout to just the individual ListActivities call inside the retry loop, and raise each feed's per-lookup deadline to 45s so normal backoff (~31s worst case) has room to complete. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
reportsPerAttemptTimeout previously applied to every caller of listActivitiesFilteredRateLimited, including app_login.go's unbounded, deadline-less lookups. There, every attempt timeout looked like a "hung attempt" and got retried, so a legitimately slow (but successful) call could burn all retries and fail outright. Extract the retry/backoff/timeout policy into retryListActivities, parameterized for testing, and only wrap attemptCtx with a sub-timeout when the caller's ctx already has a deadline. Add table-driven tests covering the hung-attempt-retry and caller-deadline-expired paths. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
…tx.Deadline() Inferring "does this caller want a per-attempt cap" from ctx.Deadline() was an implicit contract: it only exempted app_login.go's unbounded lookups because their ctx happens to have no deadline today. If the SDK ever attaches a deadline to the sync context, those callers would silently regain the 25s per-attempt cap and reintroduce the same DeadlineExceeded regression this fix removed. retryListActivities now takes perAttemptTimeout as an explicit parameter (0 = no cap) instead of inspecting ctx. Event feed callers opt in via new listActivitiesRateLimitedBounded / listActivitiesFilteredRateLimitedBounded wrappers that pass reportsPerAttemptTimeout explicitly; app_login.go's existing listActivitiesRateLimited / listActivitiesFilteredRateLimited calls now explicitly pass 0, so they stay unbounded regardless of what ctx carries. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
| // can drive it with a fake call and short durations. perAttemptTimeout == 0 means "no per-attempt | ||
| // cap" — the caller's own ctx is used as-is and a DeadlineExceeded from it is never retried as | ||
| // a hung attempt. | ||
| func retryListActivities( |
There was a problem hiding this comment.
retryListActivities is up to 14 params now, 7 of which just get passed straight through to call(...). no bug today (call sites match), but 6 consecutive strings with no compiler check on order is asking for a future swap. could close over the args in the wrapper instead
…iesRateLimited It had shrunk to a single caller (its own unfiltered sibling), so inline the retryListActivities call directly and drop the extra layer. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
…ate helper blockingCallWrappedTimeout was a near-copy of blockingCallWithDelays that only differed in how it wrapped a ctx-done error, and it dropped the per-call results parameter. Add blockingCallWithDelaysWrapped(wrapCtxErr) so both timeout-wrapping shapes and per-call results are expressible from one helper, and delete the duplicate. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
| // ctx still being live means attemptCtx's own timeout fired, not the caller's deadline — | ||
| // treat that like a retryable 429/503 rather than "out of time." | ||
| hungAttempt := applyPerAttemptTimeout && errors.Is(err, context.DeadlineExceeded) && ctx.Err() == nil | ||
| if attempt >= maxRetries || (!isRetryableReportsError(err) && !hungAttempt) { | ||
| return nil, err |
There was a problem hiding this comment.
Rate-limit storms now surface as a bare DeadlineExceeded that the callers silently swallow.
When the retry budget is exhausted this returns err unchanged, and when the backoff select gives up it returns a bare ctx.Err() (L197). Neither carries any signal about why the deadline fired, so at the call site a genuine 429 storm is indistinguishable from "one attempt hung":
// usage_event_feed.go:145, saml_event_feed.go:77, google_login_event_feed.go:69
if errors.Is(err, context.DeadlineExceeded) && ctx.Err() == nil {
// skip this one app instead of failing the whole batch
return nil, nil
}Concrete scenario: Google rate-limits the tenant for a minute. The backoff sleeps alone are 0.5+1+2+4+8+16 with up to 2x jitter (~31-63s), plus six round-trips — so the caller's 60s lookupCtx fires before the retry loop finishes. The 429 comes back as a plain DeadlineExceeded, ctx.Err() on the outer context is still nil, and the caller takes the skip branch. scanUsersForEvents then advances cursor.PendingUsers past all 25 users in the batch, emits zero events, and reports success. The only trace is a Debug line.
Before this PR the 429 propagated as a real error and the cursor was preserved for retry, so the batch was retried rather than dropped.
Suggest making the hung-attempt case explicit rather than inferring it from the error type at the call site — e.g. have retryListActivities return a sentinel (errHungLookup) only when it actually gave up on a hung attempt with the caller's ctx still live, and let everything else (including an exhausted retry budget) propagate as an error. The callers then match on the sentinel instead of on DeadlineExceeded.
| lookupCtx, cancel := context.WithTimeout(ctx, oauthAppLookupTimeout) | ||
| defer cancel() | ||
|
|
||
| r, err := listActivitiesFilteredRateLimitedBounded(lookupCtx, client, user.Email, "token", "authorize", startTime, "", filters, oauthAppLookupMaxResults) | ||
| if err != nil { | ||
| if errors.Is(err, context.DeadlineExceeded) && ctx.Err() == nil { |
There was a problem hiding this comment.
The new timeout is per-app inside an unbounded per-user loop, so it bounds one attempt but not the work.
lookupUser iterates every deduped client_id and calls lookupAppLogin, and each call starts a fresh oauthAppLookupTimeout (60s) derived from the outer ctx. Nothing bounds the aggregate.
A user with 20 authorized OAuth apps against a slow Reports API can burn 20 x 60s = 20 minutes — and scanUsersForEvents runs 25 such users per ListEvents call. So a single ListEvents invocation can now legitimately block for hours while emitting nothing, which is the opposite of what the sub-deadline was added to prevent.
A per-lookupUser (or per-batch) budget would give the intended bound: derive one deadline before the loop and let each app share it, so the loop exits once the whole user's lookup has spent its allowance. The per-app timeout can stay on top of it as a per-attempt cap.
No description provided.