[Bug] Timer metrics check logs Offset not matched for Long.MAX_VALUE when no eligible timer slot exists

Open
#11,498 1 comment 0 reactions 0 assignees View on GitHub

Maintainers usually reply within 1 day

@Ajax-1 is already working on this.

Since Oct 28, 2026.

Assessment

Difficulty
3/5
Estimated time
1-2 days
Newbie friendliness
64/100
Issue type
Bug
Clarity
Clearly specified
Activity status
Active
Tech stack
java

Research direction

Read TimerMessageStore.checkAndReviseMetrics() and TimerWheel.checkPhyPos() in the store timer package, then inspect the existing timer store tests for metrics reconciliation and timer wheel lookups. Add regression coverage for an empty eligible wheel range and a valid slot; done means the empty range avoids a lookup at Long.MAX_VALUE, valid-slot behavior still works, and zero-count metrics reconciliation is preserved.

Written by the indexing model from the issue text.

Description

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:

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:

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

The same unguarded scan entry is present in develop at 592d59d12db356f8c98332d9e355a89d92590db3.

Dominant language
Java
Stars
22.7k
Forks
12k
Avg merge
3d 18h
Merged PRs (30d)
17

Getting set up

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

More from apache/rocketmq

All issues in apache/rocketmq

Similar issues

More Java issues

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.