StiffCoconut opened a new issue, #11498:
URL: https://github.com/apache/rocketmq/issues/11498
### Runtime platform environment
Linux ARM64 (Kylin); isolated boundary probe also run on Windows x64.
### RocketMQ version
5.5.1, using the official 5.5.1 store JAR. The deployed Proxy has an
unrelated null-Settings guard; no Broker/store code was modified.
### JDK Version
Production: JDK 17.0.19. Local isolated probe: JDK 17.0.18.
### Describe the Bug
The scheduled `TimerMessageStore.checkAndReviseMetrics()` can emit a
misleading `Offset not matched` warning when the timer wheel has no eligible
slot but a TimerLog mapped file still exists.
Sanitized observed log:
```text
WARN TimerScheduledThread1 - Offset not matched. Request offset:
9223372036854775807, firstOffset: 0, lastOffset: 104857600, mappedFileSize:
104857600, mappedFiles count: 1
```
We observed one warning on each of four Broker processes during the same
scheduled metrics-check window. Immediately following logs showed the metric
count for `rmq_sys_REVIVE_LOG_DefaultCluster` revised from 0 to 0, and the task
completed in 31–41 ms. Timer processing queues and offset backlog were zero
around that window. We have not observed message loss or a delivery stall
caused by this warning.
### Root cause analysis
1. `TimerWheel.checkPhyPos(readTimeMs, 0)` initializes `minFirst` to
`Long.MAX_VALUE` and returns that sentinel when no matching slot is found.
2. `checkAndReviseMetrics()` passes this result directly to
`timerLog.getWholeBuffer(currOffsetPy)` without checking the sentinel.
3. `MappedFileQueue.findMappedFileByOffset` logs the out-of-range warning
and returns null.
4. The metrics scan breaks and performs its usual metrics update.
### Steps to Reproduce
The following is a minimal, local-only probe of the boundary call chain, not
a full Broker integration test. No Producer or Consumer is started. Run with
the official 5.5.1 libraries:
```java
Path root = Files.createTempDirectory("timer-offset-probe-");
TimerWheel wheel = new TimerWheel(root.resolve("timerwheel").toString(), 16,
1000);
TimerLog log = new TimerLog(root.resolve("timerlog").toString(), 104857600);
// Allocate a local file to represent retained TimerLog storage.
log.getMappedFileQueue().getLastMappedFile(0);
long now = System.currentTimeMillis() / 1000 * 1000;
long offset = wheel.checkPhyPos(now, 0);
assert offset == Long.MAX_VALUE;
assert log.getWholeBuffer(offset) == null;
// With the store-error logger enabled, the lookup emits the warning above.
wheel.shutdown();
log.getMappedFileQueue().shutdown(1000);
```
A local probe with an allocated TimerLog and an empty wheel confirmed the
sentinel/null-lookup behavior. A subsequent valid-slot lookup still succeeded.
Production logs supply the full scheduled-task observation.
### Expected behavior
An empty eligible timer-wheel range should be handled explicitly without
attempting a file lookup at `Long.MAX_VALUE` and without an alarming
out-of-range warning. Preserve the existing metrics reconciliation semantics.
### Suggested direction
Guard the sentinel before entering the scan loop. Avoid an unconditional
early return from the entire method if that would skip the intended zero-count
metrics reconciliation. Add empty-wheel and valid-slot regression coverage.
### Related reports checked
- #9947 / #9948: BLANK record / BufferUnderflowException.
- #10165: metrics overwritten after timer-engine switch.
- #10668: stale TimerLog references after CommitLog truncation.
These appear to have different triggers from this empty-range sentinel case.
Searches for `Offset not matched`, `checkAndReviseMetrics`, `checkPhyPos`, and
`9223372036854775807` did not find an exact duplicate.
### Source references
-
https://github.com/apache/rocketmq/blob/rocketmq-all-5.5.1/store/src/main/java/org/apache/rocketmq/store/timer/TimerWheel.java
-
https://github.com/apache/rocketmq/blob/rocketmq-all-5.5.1/store/src/main/java/org/apache/rocketmq/store/timer/TimerMessageStore.java
-
https://github.com/apache/rocketmq/blob/rocketmq-all-5.5.1/store/src/main/java/org/apache/rocketmq/store/timer/TimerLog.java
-
https://github.com/apache/rocketmq/blob/rocketmq-all-5.5.1/store/src/main/java/org/apache/rocketmq/store/MappedFileQueue.java
The same unguarded scan entry is present in develop at
592d59d12db356f8c98332d9e355a89d92590db3.
--
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]
