Ryan19929 opened a new pull request, #68300:
URL: https://github.com/apache/doris/pull/68300
### What problem does this PR solve?
Issue Number: none (found during internal investigation)
Problem Summary:
`BinlogManager.writeTBinlogToStream` persists every binlog record of the FE
image
with the *capacity* of its serialization buffer instead of the number of
bytes
actually serialized:
```java
TMemoryBuffer buffer = new TMemoryBuffer(BUFFER_SIZE); // BUFFER_SIZE =
16KB
TBinaryProtocol protocol = new TBinaryProtocol(buffer);
binlog.write(protocol);
byte[] data = buffer.getArray(); // the whole expanded backing array
dos.writeInt(data.length); // capacity, not the valid byte count
dos.write(data);
```
libthrift's `TMemoryBuffer.getArray()` returns the backing array of its
`TByteArrayOutputStream` — allocated at `BUFFER_SIZE` and grown by doubling —
while `length()` is the number of valid bytes. Verified on both libthrift
0.16.0
and 0.24.0 (the version master uses today); the behaviour is identical.
Consequences:
- every record occupies at least `4 + 16384` bytes in the image, whatever
its real
size. A `DUMMY` record — one per database and one per table that has
produced a
binlog, see `DBBinlog.getAllBinlogs()` — serializes to 52 bytes, so it
should take
56 bytes of stream and instead takes 16388, **292x**;
- a record larger than 16KB is padded up to the next doubled capacity, so up
to **2x**;
- on load, `readTBinlogFromStream` allocates a `byte[]` of that padded
length for
every record. `Checkpoint.doCheckpoint()` loads the image, saves the new
one and
then loads it again to validate it, so this happens twice per checkpoint,
plus
once on FE startup;
- the master pushes the whole image file to every non-master frontend after
each
checkpoint.
Write `buffer.length()` bytes instead.
The bug has been present since #17881 (May 2023). This PR targets `master`;
the same
code is present on the release branches, so maintainers may want to consider
it there
as well.
It only materializes when `enable_feature_binlog = true`; with the default
`false`,
`Env.saveBinlogs` returns before writing anything, so this change is a no-op
for those
clusters.
### Measurements
**1. Real FE images.** The `binlogs` module of FE images from three
binlog-enabled test
clusters, parsed offline (record count, bytes on disk, bytes actually
needed):
| image | records | on disk | actual | ratio |
| --- | --- | ---: | ---: | ---: |
| CCR source cluster | 7 (6 `DUMMY`, 1 `DROP_TABLE`) | 112.03 KB | 556 B |
206.3x |
| CCR destination cluster | 4 (`DUMMY`) | 64.02 KB | 228 B | 287.5x |
| a third binlog-enabled cluster | 2 (`DUMMY`) | 32.01 KB | 116 B | 282.6x |
Every `DUMMY` record in all three images is 292.6x — 16388 bytes on disk for
56 bytes of
stream — and the single `DROP_TABLE` is 75.9x, 16388 for 216. These clusters
are idle and
retain almost no real binlogs, so the absolute sizes are small; the ratios
are the point.
**2. How large is a binlog record, by type.** The 16KB floor only dominates
if real
records are well below it, so each type was measured with its own record
class, the
same `GsonUtils.GSON` that `BinlogManager.addXxxRecord` uses, and the real
`TBinlog`
thrift encoding (record bytes include the 4 byte length prefix):
| type | shape | record B | < 16KB |
| --- | --- | ---: | :---: |
| `DUMMY` | one per db, one per table with binlog | 56 | yes |
| `DROP_TABLE` | the one found in the CCR source image above | 216 | yes |
| `UPSERT` | 1 table, 1 partition, 1 tablet | 478 | yes |
| `UPSERT` | 1 table, 1 partition, 32 tablets | 974 | yes |
| `UPSERT` | 1 table, 4 partitions x 32 tablets | 2990 | yes |
| `UPSERT` | 1 table, 16 partitions x 32 tablets | 11054 | yes |
| `UPSERT` | 5 tables, 4 partitions x 32 tablets | 14046 | yes |
| `CREATE_TABLE` | 5 / 50 / 200 columns | 760 / 3135 / 11285 | yes |
| `ADD_PARTITION` | 32 buckets x 3 replicas | 18602 | **no** |
`UPSERT` is emitted once per committed transaction, so it dominates the
record
population of any actively ingesting cluster, and `DUMMY` is one per
database and per
table. For an `UPSERT` to reach 16KB a *single* transaction has to touch
about 92
partitions (1 tablet each), or 24 partitions x 32 tablets, or 8 partitions x
128
tablets — roughly 500 to 1000 tablets in one commit. A `CREATE_TABLE`
reaches 16KB at
about 293 columns.
`ADD_PARTITION` is the exception and is worth stating plainly:
`AddPartitionRecord`
embeds the whole `Partition` -> `MaterializedIndex` -> `Tablet` -> `Replica`
tree, and
crosses 16KB at about 28 buckets x 3 replicas, which is an ordinary table
layout. Those
records are still padded, just to the next doubled capacity rather than to
16KB, so the
fix is worth ~2x for them instead of ~40x. They are also emitted once per
partition
creation rather than once per transaction.
**3. A/B on a realistic workload.** Records written to a real file with
`fsync`, then
read back through the released `BinlogManager`. JDK 17, one JVM per
configuration.
Image size and allocation are deterministic and came out byte-identical in
every run;
wall clock is given as the range over the runs, because the host is a shared
and
heavily loaded test machine.
*5000 table dummies + 20 db dummies + 100000 UPSERT binlogs (~300 B json
each), 105020 records — 6 runs*
| | image bytes | write ms | read ms | write alloc | read alloc |
| --- | ---: | ---: | ---: | ---: | ---: |
| before | 1.60 GB | 14923-16562 | 2131-2830 | 1.68 GB | 1.76 GB |
| after | 41.16 MB | 933-1150 | 83-166 | 1.68 GB | 162.71 MB |
| | **39.9x** | 13-18x | 13-34x | 1.0x | **11.1x** |
*20000 table dummies + 50 db dummies + 10000 UPSERT binlogs, 30050 records
(dummy dominated) — 3 runs*
| | image bytes | write ms | read ms | write alloc | read alloc |
| --- | ---: | ---: | ---: | ---: | ---: |
| before | 469.65 MB | 5689-5886 | 1525-1663 | 487.89 MB | 536.8 MB |
| after | 5.15 MB | 469-634 | 17-22 | 487.2 MB | 30.91 MB |
| | **91.2x** | 9-13x | 69-98x | 1.0x | **17.3x** |
Note the write-side allocation is unchanged (1.0x): this PR does not touch
the
`TMemoryBuffer` growth chain, only what gets written out of it. The read-side
reduction comes from `readTBinlogFromStream` no longer allocating padded
arrays.
**4. Sensitivity to a partition-creation heavy workload.** Starting from the
measured
run above (its 429 B average `UPSERT` record) and mixing in `ADD_PARTITION`
records of
32 buckets x 3 replicas:
| mix | before | after | ratio |
| --- | ---: | ---: | ---: |
| no `ADD_PARTITION` (the measured run) | 1.60 GB | 41.18 MB | 39.9x |
| 1 new partition/day for 10% of tables | 1.62 GB | 50.05 MB | 33.1x |
| 1 new partition/day for every table | 1.76 GB | 129.88 MB | 13.8x |
| hourly partitions for every table | 5.27 GB | 2.12 GB | 2.5x |
The gain degrades gracefully with the share of large records and never turns
negative.
The per-type and real-image numbers were produced against a released 4.0.5
binary, so
the `ADD_PARTITION` row reflects that version's `Partition` serialization;
the `UPSERT`
record layout is unchanged on master.
### Compatibility
The record framing is unchanged (`int length` + payload), no `FeMetaVersion`
bump is
needed, and `writeTBinlogToStream` has a single caller — the image write
path. The CCR
`get_binlog` RPC path is not involved.
Both directions were measured, not just argued, by feeding both formats to
the
`BinlogManager` of a **released Doris 4.0.5** binary:
```
legacy (buffer capacity) -> released 4.0.5 reader: OK, 105020 records,
identical payloads: true
fixed (actual length) -> released 4.0.5 reader: OK, 105020 records,
identical payloads: true
```
- An old image read by a new FE: the padding sits after the thrift STOP
field and is
ignored by the generated `TBinlog.read()`; the read side is unchanged by
this PR.
- A new image read by an old FE: it is simply a sequence of shorter records.
### Release note
None
### Check List (For Author)
- Test: Unit Test (`BinlogManagerTest.testWriteTBinlogWithActualLength`:
writes a small
and a larger-than-`BUFFER_SIZE` binlog, asserts that every record length
in the stream
equals the actual thrift serialized length rather than the buffer
capacity, that the
stream contains no trailing bytes, and that the binlogs still round trip).
`BinlogManagerTest` is 7/7 green with this change. Reverting only the
production
change and keeping the test makes it fail with `expected: <52> but was:
<16384>`
at the per-record length assertion, i.e. it is a real regression test for
this bug.
- Behavior changed: No
- Does this need documentation: No
---
🤖 Generated with [Claude Code](https://claude.com/claude-code)
--
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]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
