lizhimins opened a new issue, #11168:
URL: https://github.com/apache/rocketmq/issues/11168
### Before Creating the Bug Report
- [x] I found a bug, not just asking a question.
- [x] I have searched the GitHub Issues and Discussions of this repository
and believe that this is not a duplicate.
- [x] I have confirmed that this bug belongs to the current repository, not
other repositories of RocketMQ.
### Runtime platform environment
Linux / Kubernetes. Tiered storage enabled with an S3-style object storage
provider (Alibaba Cloud OSS) behind an HTTP load balancer.
### RocketMQ version
`develop`. The affected code paths are unchanged since `026a910b26` (#7899,
2024-03-18), so 5.3.x / 5.4.x / 5.5.x are all affected. Observed in production
on builds pinning kernel `5.2.1.7`, `5.3.2-10`, `5.3.2-18` and `5.5.0-8`.
### JDK Version
Not JDK specific (observed on 11 and 21).
### Describe the Bug
Five independent defects in the tiered storage module, found while analysing
24h of production `tiered_store.log` in one region (302M lines, of which 16,902
ERROR).
**1. A transient upload failure is reported as `get file size error after
commit`, although no size lookup ever happened.**
`TieredStoreException` defaults `position` to `-1`
(`exception/TieredStoreException.java:23`), which collides with
`FileSegment.GET_FILE_SIZE_ERROR = -1L` (`provider/FileSegment.java:42`). In
`handleCommitException`:
```java
long fileSize = rootCause instanceof TieredStoreException ?
((TieredStoreException) rootCause).getPosition() : this.getSize();
if (fileSize == GET_FILE_SIZE_ERROR) {
log.error("... get file size error after commit ...");
```
`OSSFileSegment`-style providers only call `setPosition()` when they
received an HTTP error response. A transport-level failure
(`RemotelyClosedException`, `Connection reset by peer`) has no response, so
`position` stays `-1`, is read back as `fileSize`, and takes the same branch as
a genuinely failed HEAD. The message names a lookup that never ran.
Production evidence: in 7,379 occurrences over 24h, `expect == commit +
content` held in every single line, i.e. all values were local and no branch
ever performed a remote lookup.
**2. `handleCommitException` can perform a blocking remote lookup on a netty
IO thread.**
It is registered as `.exceptionally(this::handleCommitException)` with no
executor, so it runs on whichever thread completed the future — for a network
provider, a netty IO thread. Production logs confirm the thread name:
```
ERROR [AsyncHttpClient-3-4] FileSegment#handleCommitException, get file size
error after commit, ...
```
The `else` side of the ternary above calls `this.getSize()`, which for a
network provider is a synchronous object-metadata request. Blocking a shared IO
thread stalls every other object storage request on that broker.
**3. `handleCommitException` logs three differently worded messages with
three different field sets.**
One of them describes a *success* (the append landed remotely and only the
response was lost) under a method named `handleCommitException`. The three
messages also disagree on field names: the same quantity is `content` here and
`buffer` in `commitAsync`, and `commit` is logged *after* `correctPosition` may
have overwritten it, so `commit + content == expect` does not hold on the
reconciled paths.
**4. `FlatAppendFile#destroyExpiredFile` deletes the remote object before
unregistering its metadata.**
```java
fileSegment.destroyFile();
if (!fileSegment.exists()) {
fileSegmentTable.remove(0);
metadataStore.deleteFileSegment(filePath, fileType,
fileSegment.getBaseOffset());
}
```
A crash between the delete and the unregister leaves a metadata row pointing
at a deleted object. `recover()` reloads it on every restart, and every later
read of that segment fails with `NoSuchKey`. In production this produced 844
such failures in 24h against only **4 distinct object names**, concentrated on
3 of 11 affected instances — the signature of permanent phantom metadata rather
than transient errors.
The reverse order fails safe: an orphaned object costs storage, a phantom
metadata row breaks reads forever.
**5. `FileSegment#readAsync` silently shortens a read and logs it at DEBUG.**
```java
int readableBytes = (int) (currentCommitPosition - position);
if (readableBytes < length) {
log.debug("FileSegment#readAsync, request position exceeds commit
position, ...");
length = readableBytes;
}
```
The truncated buffer surfaces much later as a
`MessageFormatUtil#splitMessageBuffer` failure, whose own message carries no
topic, queueId or offset. The cause is therefore invisible in production: we
observed 391 `message buffer offset exceeded limit` errors in 24h on one
instance and could not attribute them to a queue from the logs alone.
**6. `MessageStoreFetcherImpl` compares an entry count against a byte
count.**
```java
boolean cacheBusy = fetcherCache.estimatedSize() > memoryMaxSize * 0.8;
```
`estimatedSize()` counts entries; `memoryMaxSize` is bytes (`maxMemory() *
readAheadCacheSizeThresholdRate`), and the cache is bounded by `maximumWeight`
with a weigher returning `buffer.getSize()`. The comparison is effectively
always false, so the read-ahead cache is never treated as busy.
### Steps to Reproduce
Defects 1–3 and 6 are readable directly from the code. For defect 1, any
transport-level failure during `commit0` reproduces it: the provider throws
without a response, `position` stays `-1`, and the log claims a file-size
lookup failed.
For defect 4: kill the broker between the object delete and
`deleteFileSegment`, restart, and read that segment.
For defect 5: request a range whose end exceeds the segment's
`commitPosition`; the only trace is a DEBUG line.
The production numbers above come from aggregating 24h of `tiered_store.log`
for one region and clustering all 16,902 ERROR lines by root cause.
### What Did You Expect to See?
- A transient upload failure reported as what it is — an append that did not
land and will be reconciled on the next commit — at WARN, not as a file-size
lookup error at ERROR.
- No blocking remote lookup inside a completion callback that runs on a
netty IO thread.
- One log line per commit failure, with a stable field set and a
discriminator for the outcome.
- Segment expiry that fails safe: metadata unregistered before the object is
deleted.
- A shortened read logged at a level visible in production.
- `cacheBusy` comparing bytes against bytes.
### What Did You See Instead?
- 7,379 `get file size error after commit` ERROR lines in 24h in one region,
none of which corresponded to an actual failed lookup. The real event — a
transient connection reset by the object storage frontend, fully recovered by
the next commit round — was indistinguishable from a genuine metadata failure.
- Those ERROR lines emitted on `AsyncHttpClient-3-N` threads.
- Three message formats for one event, one of them describing a success.
- 844 `NoSuchKey` read failures in 24h against 4 distinct object names,
retried periodically forever.
- The truncation that precedes `splitMessageBuffer` failures logged only at
DEBUG.
- A read-ahead cache whose busy check can never trigger.
To be explicit about what is **not** broken: the retry itself is correct and
loses no data. `commitPosition` is not advanced on failure, the next
`commitAsync` performs a real lookup, `correctPosition` takes the
server-reported length as authoritative, and the stream is then rewound or
rebuilt from `getCommitOffset()`. Measured over 24h: 4,739 distinct files
across 7,274 failures (mean 1.5, max 13 for a single file), no permanently
stuck file, and zero `PositionNotEqualToLength`. These defects are about
reporting and about a latent IO-thread hazard, not about durability.
### Additional Context
I have a patch covering all six items on a branch, with `FileSegmentTest`
extended to assert that `handleCommitException` never performs a remote lookup.
`mvn -pl tieredstore test` passes (127 tests) and checkstyle is clean against
`style/rmq_checkstyle.xml`. I will open the PR once this issue is numbered.
Two notes on the fix's shape, in case maintainers prefer a different split:
- Items 1–3 are one change: stop looking up the remote size in the callback,
reconcile only from what the provider reported, and emit a single line with
`result=REMOTE_LANDED | RETRY_AFTER_REWIND | RETRY_AFTER_RECONCILE`.
`commitAsync`'s existing lookup-failure log joins the same vocabulary as
`result=SIZE_LOOKUP_FAILED`. This also gives `GET_FILE_SIZE_ERROR` a single
meaning again, so item 1 disappears by construction rather than needing a
disambiguating branch.
- Items 4, 5 and 6 are independent one-liners and could be split into
separate PRs if that is easier to review.
--
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]
