fix(ENGKNOW-3722): self-heal 416 from stale object length, bound session caches

[gmagnu]

ENGKNOW-3722

Problem

GOR queries fail intermittently with S3 Status Code: 416 (Range Not Satisfiable) when opening versioned .link files, each burning ~167 s in retries before hard-failing. 220 occurrences in clinops-prd over 14 days (namespace gregor 163, workflows 57; gor-worker 153, executor 32, Nextflow tasks 22, gregor-web 11).

Cannot create iterator for datasource: ref_gregor/genemb/gmb_disease_map.tsv
Cause: Giving up after 167193 milliseconds and 6 retries
Failed to open S3 object: s3://clinops-reference-data/ref/.../gmb_disease_map.tsv.link
byte range bytes=98674-98824 cannot be satisfied from object with content length 98674
(Service: S3, Status Code: 416)

S3Source.open(RequestRange) clamps every ranged GET to the object length it has cached (S3Source.java:174). Object stores have no append — S3Source.getOutputStream rejects it outright — so LinkFile.appendEntry → save() overwrites the whole object, and versioned-link GC (LinkFile.gcEntries) shrinks it. The writer calls invalidateMeta(), but that only clears its own JVM. Every other pod keeps the pre-rewrite length, requests a range starting at or past the new end, and gets a 416.

The staleness window was effectively unbounded: gor.s3.meta.cache.session=true is the default, and the session cache had no expiry and no size bound (GorSessionCache.java:51), while gor-worker sessions are long-lived.

S3RetryHandler.checkIfShouldRetryException classifies 400/401/403/404 as non-retryable but never 416, so a deterministic failure ran the full ladder — turning a millisecond-wide race into a ~3-minute query outage.

How the range arises

Worth spelling out, because the numbers look arbitrary. LinkFile.readLimitedLinkContent calls StreamUtils.readString(is, 200000), a single 200000-byte read. That exceeds ExtendedRangeStream's 128 kb bookkeeping immediately, so it drains the first request, then reopens at the position reached with double the length:

rlen  = max(200000 - 98674, min(max(131072*2, 131072), 8mb)) = 262144
range = [98674, 98674 + 262144)  ->  clamped to the stale 98825  ->  bytes=98674-98824  ->  416

Distinct signatures from Loki over 14 days, all showing a cached length larger than the actual:

requested range	actual content-length	implied cached length
bytes=8841-8844	8841	8845
bytes=98674-98824	98674	98825
bytes=196608-352972	43	≥ 352973
bytes=196608-458751	34	≥ 458752

The last two are a link file that shrank from ~350 KB to a 43-byte single-line link — a GC/compaction rewrite — while readers still held the pre-rewrite length.

Unrelated to the chronic 429 throttling on the same bucket. Those do not correlate: Aug 1–3 had 416 bursts on baseline 429 traffic, Aug 8 had ~2.5M 429s and zero 416s. The 429 volume is a real separate problem and still needs its own ticket.

Fix

Self-heal, in the source. On a 416, invalidate the cached metadata, re-read the object length, and reissue the range once. The retry is immediate and local, so it never reaches RetryStreamSourceWrapper and costs one HEAD rather than 167 s of sleeps.

Wiring invalidateMeta() in as RetryHandlerBase.perform's existing preRetryOp was considered — the hook is there and RetryStreamSourceWrapper passes null for it. Rejected: invalidateMeta() is private and not on StreamSource, so it needs an interface change, and the hook only fires after a sleep.

Fail fast on what remains. S3RetryHandler and OCIObjectStorageRetryHandler now classify 416 as non-retryable. Anything reaching them has already survived the self-heal, so it is a genuinely unsatisfiable range and should fail in milliseconds.

Bound the session caches. s3MetadataCache gets maximumSize(10000).expireAfterWrite(5, MINUTES), matching the static fallback. This is also what caps the quiet half of the bug: a cached length shorter than the object makes ExtendedRangeWrapper stop at the stale EOF, so readLimitedLinkContent returns truncated link content with no error at all and resolves the wrong data source. Self-healing 416 fixes only the loud half; the expiry bounds both.

linkCache becomes per-session instead of static, with the same bounds, so link content read by one session is no longer served to every later one in the process.

Cache keys. Keys were bucket + key with no separator, so bucket ab + key c and bucket a + key bc both produced abc — two unrelated objects sharing a cached length, and invalidating one clearing the other. The OCI key was worse: it omitted the namespace entirely, so the same bucket and object name in two namespaces shared one entry.

Applied to S3Source, S3SourceAsync and OCIObjectStorageSource. The OCI variant matches on BmcException.getStatusCode(); S3SourceAsync catches RuntimeException rather than GorResourceException because its openRequest does not wrap S3 failures — the async branch lets the CompletionException through and the sync branch catches only SdkClientException.

linkCache keeps its StreamSource-identity key. Re-keying it on path would switch on real link-content caching and reintroduce exactly the cross-pod staleness class this PR closes, one level up. That belongs in its own ticket.

Semantics of the self-heal

A 416 means start >= actual length, so after the refresh the range is empty in every real case and the read reports EOF — readString returns the bytes it already has. If the first chunk and the remainder straddle a rewrite, that content can mix generations; it then fails loudly in link parsing rather than as a 416, which is strictly better than a hard query failure. The cache expiry is what narrows that window. The "object grew between the 416 and the re-HEAD" branch reissues the GET and is covered by its own test.

Tests

Written test-first; every test was watched failing against the production stack before the fix.

• UTestS3SourceStaleMetadata — 416 on a shrunk object reads as EOF; the range is reissued if the refreshed length still covers it; non-416 errors do not trigger a metadata refresh (guards against over-broad invalidation); cache keys do not collide across the bucket boundary. Uses the real caller arguments (262144), derived from the trace above, not hand-picked ones.
• UTestS3RetryHandler / UTestOCIObjectStorageRetryHandler — 416 fails on the first attempt; 500 still retries.
• UTestOCIObjectStorageSourceStaleMetadata — same three cases plus namespace isolation in the cache key.
• UTestGorSessionCache — metadata cache entries expire and the cache is size-bounded; link content cached by one session is not visible to another.
• ITestS3LinkFileRewrite — end to end against real S3: write a versioned .link, read it through the production wrapper chain to seed the cache, have a second writer compact it via the raw S3Client (going through S3Source would call invalidateMeta() and hide the bug, whereas in production the writer is a different pod), then read again. Before the fix this failed with Status Code: 416 and Giving up after ... retries; after, it resolves the compacted entry.

Mutation-checked. The check caught that the OCI 416 branch had been added without a failing test first; that was corrected properly — test written, branch removed, failure observed, branch restored.

• ./gradlew test — 2595 pass, 0 fail, 69 skipped (pre-existing)
• ./gradlew :drivers:integrationTest for S3 + OCI — 88 pass against real object stores

drivers had no mockito; added testImplementation Testing.mockito.core.

Not included: S3SourceAsync.java is untracked work-in-progress in the working tree, so its fix and its test are held back until that file lands, keeping this PR to the bug. Also fixed in passing: OCIObjectStorageSource reported failures as "Failed to open S3 object".

Impact

Every in-flight reader of a .link file was taken down at once whenever that file was rewritten — the bursty shape in the logs, ~6 distinct days in 14. Each failure cost 167 s of retry latency plus a failed query, and the retries held streams and metadata alive longer, marginally widening the race for everyone else.

The quiet half never showed up in the logs at all: a stale-shorter length silently truncated link content and resolved the wrong data source, with no error raised.

Immediate mitigation without this build remains -Dgor.s3.meta.cache.session=false, which falls back to the 5-minute-TTL static cache. Do not use -Dgor.s3.meta.cache=false — disabling caching entirely adds substantial HEAD traffic and would worsen the existing 429 throttling.

🤖 Generated with Claude Code

[github-actions]

Junit Tests - Summary

4 784 tests  +16   4 613 ✅ +16   20m 2s ⏱️ + 1m 38s
  495 suites + 6     171 💤 ± 0 
  495 files   + 6       0 ❌ ± 0 

Results for commit 8e24745. ± Comparison against base commit 36bd22a.

♻️ This comment has been updated with latest results.

[andrimar1]

LGTM - reviewed with @gmagnu