matrixorigin / matrixorigin/matrixone
[Bug]: FileService: concurrent disk-cache hits duplicate reads/decodes and can evict warm entries before key deduplication
- Dominant language
- Go
- Stars
- 1.9k
- Forks
- 311
- Avg merge
- 1d 3h
- Merged PRs (30d)
- 768
Description
### Is there an existing issue for the same bug?
- [x] I have checked the existing issues.
Related workload umbrella: #28627. This report deliberately isolates a **deterministically reproduced FileService mechanism**, rather than opening another generic Wiki-10M performance report: concurrent memory misses for the same disk-cached extent perform independent reads; when scoped decode sharing cannot admit them, duplicate decoded allocations can displace other useful cache entries before duplicate insertion is detected.
Recent open/closed searches for `disk cache`, `decode`, and `stampede` did not identify another specific report for this counterfactual. #28784 is a disk-finalization UT scheduling flake, not this mechanism.
### Branch Name
`main` (exact-SHA mechanism reproduction); `4.2-dev` (related measured disk-read/decompression amplification, with different allocation internals).
### Commit ID
- Main incident and deterministic reproduction: `bb358ea76aeb44a6eed5079616e7e75ba35e75b9`.
- Latest compared 4.2-dev incident: `b122da6dc20985cbfcb2fcc642ae6729d70d8516`.
These are the tested MO commits, not the workflow repository commits. This report does not claim an introducing PR or that every later main HEAD was tested.
### Other Environment Information
**Nightly workload**
- Wiki 10M, 768-dimensional float32 vectors, IVF-FLAT.
- Two consecutive `l2_only/pre` rounds; 10,000 queries/round, 100 concurrent workers, `k=10`, `probe_limit=5`, `ivf_preload_entries=0`.
- Benchmark revision: `0bae04528673d7756c4ee2478ac8e4e41f54df1b`.
- Family topology: one TP CN and two AP CNs; benchmark uses AP routing.
- Each AP: 14 CPU, 55Gi container memory, 16Gi FileService MemCache, `GOMEMLIMIT=25000MiB`.
- Main namespace: `mo-main-family-34810554122-1`.
- 4.2 namespace: `mo-42-family-34859841116-1`. Both APs have zero restarts in the collected Pod status.
**Deterministic diagnostic**
- macOS arm64, Go 1.26.4, static jemalloc 5.3.1.
- Exact main commit above, no tracked production-source edits.
- Real S3FS, DiskCache, MemCache, FIFO, IOMerger, jemalloc and LZ4.
- S3FS uses its local `Endpoint: disk` object-storage backend; this is not an external COS/S3 service test.
- Eight immutable 128KiB decoded blocks, a 1MiB memory cache that can hold all eight, seven initially memory-cached blocks.
- Scoped sharing budget scaled to 256KiB/two blocks, versus production's 64MiB maximum. Two completed-but-unreleased reads occupy the two sharing slots in saturated variants.
### Actual Behavior
#### Summary and impact
DiskCache warmth does not prevent a severe repeated-read/decode regime. Concurrent readers can each read the same cached extent before any of them publishes decoded data to MemCache. Main's capacity reservations occur before duplicate-key detection, so multiple copies of one missing key can evict other warm keys, which then miss in following requests.
The isolated test reproduces this feedback **with a total working set that fits the cache, without CN routing changes, merges, external cache-eviction requests, or mutable input data**.
Observed impact is a substantial performance cliff, repeated device I/O, repeated decoding/allocation, and sustained high CN CPU. This report does **not** establish corruption, a permanent memory leak, an unrecoverable hang, or an OOM caused by this mechanism.
#### Production-like nightly evidence
| Run/job | MO version | Round | Wall time | QPS | AP block-device read bytes |
| --- | --- | --- | ---: | ---: | ---: |
| [34810554122 / 103925373129](https://github.com/matrixorigin/mo-nightly-regression/actions/runs/34810554122/job/103925373129) | main `bb358ea76a` | 1 | 265.84s | 37.62 | approximately 0.126 TB |
| same | same | 2 | 1902.53s | 5.26 | approximately 5.755 TB |
| [34859841116 / 104103204673](https://github.com/matrixorigin/mo-nightly-regression/actions/runs/34859841116/job/104103204673) | 4.2 `b122da6dc2` | 1 | 2125.35s | 4.71 | approximately 6.200 TB |
| same | same | 2 | 677.66s | 14.76 | approximately 2.690 TB |
The latest job's approximately 46.7 minutes is **35.42 + 11.29 minutes**, not another slow-second-round example. Both jobs nevertheless enter the expensive repeated-read/decode regime.
Windows, UTC on 2026-09-14:
- Main R1: approximately 09:30:41-09:35:07; R2: 09:35:08-10:06:50.
- 4.2 R1: approximately 18:38:30-19:13:57; R2: 19:13:57-19:25:15.
- Beijing time is UTC+08:00; the 4.2 windows are on September 15 locally.
The following counters include **only the two AP CNs**, not TP or TN:
| Metric | Main R1 | Main R2 | 4.2 R1 | 4.2 R2 |
| --- | ---: | ---: | ---: | ---: |
| FileService disk-entry read attempts | 68,850 | 1,665,918 | 1,715,552 | 768,976 |
| FileService disk-entry hits | 44,105 | 1,658,763 | 1,699,345 | 767,611 |
| FileService S3 entry-read counter | 15,401 | 6,067 | 13,658 | 1,446 |
| CPU core-seconds | 2,365 | 50,344 | 56,241 | 16,616 |
Main R2 performs approximately 24x as many disk-entry attempts, 45.7x as many block-device read bytes and 21.3x as much AP CPU work as R1. R1 is already overwhelmingly memory-hit over the whole round: entry hit rate approximately 99.71%, versus 90.50% in R2. It is not valid to describe every R1 query as a cold S3 read and every R2 query as an equivalent warm-memory read.
In the new 4.2 run, DiskCache eviction counters remain unchanged. DiskCache occupancy is approximately 0.88-1.04TB per AP against a 1.93TB capacity; the observed read traffic is not explained by exhausting and refilling that disk-file capacity.
#### Direct same-CN, same-key evidence
Main AP `nightly-regression-dis-ap-cn-qm4fh`, UTC 2026-09-14 09:35:15:
```text
FilePath: 01a09f13-eb79-72e6-995b-776c4d5d59df_00000
offset: 76142618
size: 25305920
Policy: 0
```
At least seven overlapping requests for this exact key independently record `io.ReadFull begin/end` and `ToCacheData begin/end`. Two examples:
| Log timestamp UTC | ReadFull duration | ToCacheData duration |
| --- | ---: | ---: |
| 09:35:15.804878 | 252.77ms | 238.62ms |
| 09:35:15.805233 | 298.51ms | 125.95ms |
New 4.2 AP `nightly-regression-dis-ap-cn-mkvjf`, UTC 19:15:01-19:15:02, similarly has at least nine separate reads/conversions of:
```text
01a0a10b-97ed-7e4e-8fdc-c6d91360ccca_00000
offset=76142893, size=25305920, Policy=0
```
One sampled request records `memory cache postSet begin`; other overlapping requests still perform their own read/conversion without inserting a new key. These `Policy=0` samples do not support blaming explicit `SkipMemoryCacheWrites` for these particular reads.
Slow-event logs only include operations exceeding 500ms. These samples prove repeated work, but their duplicate ratio must not be extrapolated to all requests.
#### CPU profiles
4.2 slow-round samples, UTC 18:50-18:55:
| Function | AP mkvjf | AP qjqqb |
| --- | ---: | ---: |
| DiskCache.Read, inclusive | 85.48% | 89.63% |
| compress.Decompress, inclusive | 56.25% | 59.75% |
| runtime.memmove, flat | 56.00% | 59.34% |
| syscall, flat | 36.84% | 36.68% |
| L2DistanceSq, inclusive | approximately 0.15% | approximately 0.15% |
The extra work is dominated by the read/materialization path, not vector-distance arithmetic. Inclusive and flat percentages overlap and must not be added.
#### Measurement limitations
- TB denotes decimal bytes from AP `container_fs_reads_bytes_total`, selecting `container="main"` and `/dev/vdb`. Raw labels were checked for duplicate scrape/container series. This is guest/cgroup block-device accounting, not unique file size or guaranteed physical-media accesses inside the storage provider.
- FileService read/hit counters count entries, not HTTP requests or byte-weighted cache hits.
- ObjectIO metadata counters refer to a separate cache. Subtracting them from FileService memory counters is invalid.
- `read-disk-cache` duration sums include concurrent read, allocation and conversion time; they are not pure disk latency. Syscall samples are not all I/O wait.
- We have not apportioned the entire 5.755/6.200 TB among same-key duplication, ordinary working-set turnover and physical merge/layout changes. The entire nightly performance difference has not been isolated in a fixed-layout A/B.
### Expected Behavior
Overlapping reads of the same immutable extent should not unnecessarily multiply expensive disk reads/conversions and displace an otherwise cacheable working set solely through duplicate in-flight allocations. Warming disk files should not expose substantially more repeated work because that path bypasses the coordination used for cold object reads.
This does not require every memory miss to become a hit, forbid normal capacity eviction, promise identical round latency, or justify exceeding memory/lifecycle budgets. The problem is avoidable duplicate work and its demonstrated feedback, not the existence of cache misses.
### Steps to Reproduce
#### A. Deterministic mechanism test, executed
Use the exact main commit `bb358ea76aeb44a6eed5079616e7e75ba35e75b9`, its existing FileService tests/helpers and a configured Go/CGo/jemalloc build environment. A separate comment on this issue contains the complete diagnostic Go test.
1. Create eight immutable blocks, each 128KiB decoded / 33,305 bytes compressed; use a 1MiB MemCache and warm DiskCache files.
2. Preload seven blocks into MemCache. In saturated variants, hold two completed reads to occupy a scaled two-block shared-decode budget.
3. Submit the same 32 keys: eight requests each for keys 7, 6, 5 and 4.
4. In concurrent variants, use barriers after allocation/conversion and before publication to make duplicate reads overlap. No production timeout or policy is changed.
5. Compare sequential reads, shared concurrent reads, saturated concurrent reads and a cold-object IOMerger control.
Observed deterministic results:
| Mode | Disk entry reads | FS disk bytes | Object-store gets | Conversions | Final cached bytes |
| --- | ---: | ---: | ---: | ---: | ---: |
| Warm, sequential, sharing saturated | 1 | 33,305 | 0 | 1 | 1,048,576 |
| Warm, concurrent, sharing available | 8 | 266,440 | 0 | 1 | 1,048,576 |
| Warm, concurrent, sharing saturated | 32 | 1,065,760 | 0 | 32 | 131,072 |
| Cold object, coalesced, sharing saturated | 0 | 0 | 1 | 1 | 1,048,576 |
The cold control performs one 33,305-byte read from the local object-store backend. The shared warm control still performs eight disk reads despite only one conversion: sharing takes effect **after** the physical-read API.
Assertions for each saturated concurrent wave:
```text
Before publication:
FIFO Used = 0
pending reservations = 1,048,576
# Eight copies of one missing key displaced the previously cached keys.
After publication:
FIFO Used = 131,072
pending reservations = 917,504
# Only one copy was inserted.
After releasing duplicate results:
pending reservations = 0
FIFO Used = 131,072
# Evicted keys are not restored; following accesses reread them.
```
After releasing held sharing scopes and sequentially refilling, replaying all eight keys produces zero disk reads and zero conversions. This demonstrates pressure-dependent feedback, not a permanently broken cache or a reservation leak.
**Executed validation:** normal and race tests passed; each of the two top-level diagnostics separately passed 100 race-enabled repetitions. An additional local race rerun of both tests verified the reported counters. Test commands, after configuring the repository's native dependencies:
```sh
go test -mod=readonly -v -race -count=100 -timeout=60s \
-run '^TestDiagnosticWarmDiskDuplicateFeedback$' ./pkg/fileservice
go test -mod=readonly -v -race -count=100 -timeout=60s \
-run '^TestDiagnosticColdObjectCoalescing$' ./pkg/fileservice
```
This is a **scaled mechanism reproduction**, not a full Wiki-10M run, a Linux page-cache experiment, a PVC throughput benchmark, or an exact reproduction of the 6TB total. It was executed on main, not on the 4.2 commit. The deliberate barriers select reachable overlap; they do not model the production scheduler. The tests measure FileService logical read bytes, not block-device bytes.
#### B. Nightly workload observations
The linked jobs preserve two-round IVF results and provide production-like workload evidence. Physical objects, prior workload and concurrent merge activity were not frozen, so these observations are not a controlled code-version A/B. A stable CN assignment is not needed for diagnostic A and is not the defining condition of this report.
Example evidence queries, evaluated over the UTC windows above:
```promql
sum by (pod, device) (
increase(container_fs_reads_bytes_total{
namespace="mo-main-family-34810554122-1",
container="main", device="/dev/vdb",
pod=~"nightly-regression-dis-ap-cn-.*"
}[1903s])
)
```
```logql
{namespace="mo-main-family-34810554122-1",
pod="nightly-regression-dis-ap-cn-qm4fh"}
|= "slow event"
|= "01a09f13-eb79-72e6-995b-776c4d5d59df_00000"
|= "76142618"
```
The Prometheus example ends at `2026-09-14T10:06:50Z`; the Loki sample window is `2026-09-14T09:35:15Z` to `09:35:20Z`. Profiling uses `process_cpu:cpu:nanoseconds:cpu:nanoseconds` and the exact namespace/pod selectors, over the stated five-minute windows.
### Additional information
#### Exact code paths
1. [S3FS.Read: DiskCache hit returns before IOMerger](https://github.com/matrixorigin/matrixone/blob/bb358ea76aeb44a6eed5079616e7e75ba35e75b9/pkg/fileservice/s3_fs.go#L772). Cold followers can instead wait for a leader and recheck MemCache after publication.
2. [IOEntry.ReadFromOSFile](https://github.com/matrixorigin/matrixone/blob/bb358ea76aeb44a6eed5079616e7e75ba35e75b9/pkg/fileservice/io_entry.go#L55): `io.ReadFull` precedes `setCachedData`/conversion.
3. [prepareSharedDecode](https://github.com/matrixorigin/matrixone/blob/bb358ea76aeb44a6eed5079616e7e75ba35e75b9/pkg/fileservice/shared_decode.go#L323): wraps conversion, not I/O; production sharing is bounded by 64MiB, live generations and participants, with a bounded wait/fallback. Main R2 has approximately 544k `bypass_admission` events; these do not imply that every bypass is a duplicate key.
4. [MemCache.reserveCacheData](https://github.com/matrixorigin/matrixone/blob/bb358ea76aeb44a6eed5079616e7e75ba35e75b9/pkg/fileservice/mem_cache.go#L439): reserves and evicts before the insertion key is known. [Update](https://github.com/matrixorigin/matrixone/blob/bb358ea76aeb44a6eed5079616e7e75ba35e75b9/pkg/fileservice/mem_cache.go#L754) later detects duplicate insertion. Only an inserted value commits its reservation; duplicate results retain theirs until release.
5. Reservation eviction receives `withoutEventLogger(ctx)`. An absence of per-request eviction events is not evidence of no memory-cache turnover.
6. [ReadColumnTopN legacy fallback](https://github.com/matrixorigin/matrixone/blob/bb358ea76aeb44a6eed5079616e7e75ba35e75b9/pkg/objectio/column_topn.go#L57) reads a full column before processing selected rows. A small Top-K result does not imply a small extent read. Chunked-column support does not make legacy extents chunked.
7. [Linux FADV_DONTNEED](https://github.com/matrixorigin/matrixone/blob/bb358ea76aeb44a6eed5079616e7e75ba35e75b9/pkg/fileservice/page_cache_linux.go#L25) is issued after successful disk-cache entry reads. It is advisory, but disk-file presence cannot be equated with OS page-cache residency. Its Linux effect was not exercised by the macOS diagnostic.
**4.2 boundary:** `b122da6dc2` has no main scoped-sharing registry, pending-reservation machinery, IVF `plan_reader.go`, or `column_topn.go`. Its IVF path uses generated SQL and [LoadColumnDataByTopN -> readColumnsData](https://github.com/matrixorigin/matrixone/blob/b122da6dc20985cbfcb2fcc642ae6729d70d8516/pkg/objectio/ioutil/loadfuncs.go#L329). Disk hits still return before IOMerger; its allocation guard uses `EnsureNBytes`. Therefore repeated full-column reads/uncoalesced disk work is shared, while the exact reservation feedback was reproduced only on main and is not asserted to explain every 4.2 byte.
#### Relationship to previous changes
| Change | What it covers | Why this report is not covered by that scope |
| --- | --- | --- |
| #26758, `47c8302f08` | Expensive sparse S3 range fan-out after a full-object merge wait | The reported DiskCache-hit path returns before that S3 merger/fallback logic. The PR explicitly preserves cache-hit paths. |
| #28413, `5b5edde8f8` | Scoped object-column decompression sharing | Explicitly shares conversion only, retaining compressed I/O per reader and bounded independent fallback. |
| #28442, `8fb29299f2` | Extends sharing to the selected vector in fused INCLUDE reads | Its own benchmark reports 8-to-1 conversions while storage reads remain 8; it does not coalesce those reads. |
| #28182, `0cee094f15` | Consolidates cache-allocation ownership | This report does not claim it introduced reservation semantics; duplicate pre-publication allocation remains a separate performance interaction. |
The exact main reproduction commit includes #26758, #28413 and #28442, verified by git ancestry. These improvements are not claimed to be ineffective; this report identifies a remaining mechanism outside their guarantees. No specific regression-introducing PR has been established.
#### Evidence boundaries
Confirmed: same-key independent reads/conversions in nightly logs; high read/decode CPU cost; the exact main mechanism and its amplification/recovery controls.
Not confirmed: a complete online main key-by-key insert -> evict -> reread trace, the fraction of all incident bytes due to stampedes, a full-10M latency recovery, or identical allocation behavior in main and 4.2.
Native allocations for evicted but still consumer-held buffers may remain live. `FIFO Used + pending reservations` is not a hard bound on all consumer-held or process memory. The diagnostic does not establish a leak.
This issue records the defect, evidence and reproduction only. No implementation proposal or production-code patch is included.
Contributor guide
Assessment
This issue has not been assessed yet.