sjhajharia opened a new pull request, #22849:
URL: https://github.com/apache/kafka/pull/22849

   ### Summary
   
   Share-group DLQ records (KIP-1191) were built with `Time#hiResClockMs()` as 
their timestamp instead of `Time#milliseconds()`. `hiResClockMs()` is 
`System.nanoTime()` converted to milliseconds, explicitly documented as 
measuring elapsed durations from an arbitrary, non-epoch origin, not wall-clock 
time. Every DLQ record ended up stamped with something like `332800244 (~4 days 
after the Unix epoch)` instead of a real 2026 timestamp.
   
   Kafka's log retention decides whether to delete a segment by comparing each 
record's timestamp against the current wall-clock time. With a near-epoch 
timestamp, that comparison is always "yes, delete this"  regardless of the 
configured `retention.ms`. So the DLQ record is produced successfully, and then 
deleted by the very next retention check, typically well under a second later.
   
   ### Impact
   
   This affects every DLQ write, on any broker. Whether it's visible in 
practice depends entirely on how fast something reads the DLQ topic after the 
record lands relative to `log.retention.check.interval.ms` (default 5 minutes, 
but frequently lowered in tiered-storage/testing configs) — so the practical 
exposure ranges from "DLQ appears completely empty" to "DLQ briefly has data 
that vanishes moments later," neither of which produces any error, warning, or 
log line pointing at the cause.
   
   ### Why this was hard to find
   
   - The write path itself is silent on success: the produce request completes 
normally (broker ack, high watermark advances), so there's no exception or log 
line anywhere suggesting anything is wrong.
   - The existing JUnit coverage (`ShareConsumerDLQTest`) reads the DLQ topic 
via a bare `consumer.assign() + seekToBeginning() + poll()` — near-zero setup 
latency. It happened to read the records within a few hundred milliseconds, 
comfortably beating the next retention cycle every time. It was passing by 
winning a timing race, not because the write path was correct.
   - A newer ducktape system test, whose DLQ reader goes through a real 
consumer-group `subscribe()` (requiring a multi-second group join/rebalance 
before it can fetch anything), reliably lost that same race — which is what 
surfaced this as worth investigating rather than dismissing as test-infra 
flakiness.
   - The existing unit tests (`ShareGroupDLQStateManagerTest`) never asserted 
on the actual timestamp value of produced records, only on headers/key/value — 
so there was no test that could have caught a wrong clock being used.
   
   ### Fix
   
   One-line change: `time.hiResClockMs() -> time.milliseconds()`
   
   Added a regression test (`assertDlqRecordTimestampsAreWallClock`, wired into 
`testDlqHappyPathExistingTopic`) asserting the produced record's timestamp 
matches Time#milliseconds(). Confirmed it fails against the pre-fix code and 
passes with the fix, closing the coverage gap above.
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: [email protected]

For queries about this service, please contact Infrastructure at:
[email protected]

Reply via email to