[
https://issues.apache.org/jira/browse/KAFKA-13664?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18114729#comment-18114729
]
Mykyta Bozhenko commented on KAFKA-13664:
-----------------------------------------
Reproduced on trunk (c130b7382c) and on 4.3.1. The cause is
FileRecords.readInto.
Setup: three brokers, log.preallocate=true, __consumer_offsets with replication
factor 3. Kill the broker that leads __consumer_offsets-0. A neighbour becomes
coordinator and loads the partition from its own replica, which was never
trimmed
by a clean shutdown and never truncated by recovery, so the preallocated zero
tail
is still in the file. This is why the error appears on the brokers that did not
restart.
readInto fills the caller's buffer up to the end of the file instead of the end
of
the records, so CoordinatorLoaderImpl parses that zero tail:
{code}
ByteBufferLogInputStream.nextBatchSize() <- CorruptRecordException
RecordBatchIterator.makeNext()
CoordinatorLoaderImpl.processMemoryRecords() line 229
CoordinatorLoaderImpl.doLoad() line 153
{code}
The load then fails and every group on the partition is unloaded. There is no
retry: CoordinatorRuntime moves the context to FAILED, so the partition stays
unloaded until leadership moves again.
[PR 23446|https://github.com/apache/kafka/pull/23446] for KAFKA-20841 bounds
readInto to the records it covers. Same commit, one change:
|| || trunk || patched ||
| Failed to load metadata | 4 runs of 4 | 0 of 4 |
| Finished loading of metadata | 0 of 4 | 4 of 4 |
On 4.3.1: 2 of 2 without the fix, 0 of 2 with it backported. The recovery path
is
unaffected - LogSegment.recover reads batch headers from the channel, not
through
readInto; measured identical before and after.
TransactionStateManager uses the same call pattern, so __transaction_state
loading
looks exposed as well. I have not reproduced that.
Not reviewed by anyone; these are my own measurements. Per the ASF generative
tooling guidance: produced with AI assistance, and I am responsible for it.
> log.preallocate option causes CorruptRecordException
> ----------------------------------------------------
>
> Key: KAFKA-13664
> URL: https://issues.apache.org/jira/browse/KAFKA-13664
> Project: Kafka
> Issue Type: Bug
> Components: core
> Affects Versions: 2.8.1
> Reporter: Vyacheslav Ksenz
> Priority: Major
>
> If we create multibroker cluster with log.preallocate option restarting one
> of the brokers causes losing part of the offset data.
> How to reproduce. I created a cluster with three brokers and log.preallocate
> enabled. I create topic 'topic', produce there some data and write some
> offsets.
>
> If I reboot one of brokers on the both others there are errors like:
>
> {code:java}
> [2022-02-10 08:47:55,051] ERROR [GroupMetadataManager brokerId=3] Error
> loading offsets from __consumer_offsets-39
> (kafka.coordinator.group.GroupMetadataManager)
> org.apache.kafka.common.errors.CorruptRecordException: Record size 0 is less
> than the minimum record overhead (14){code}
>
> There is a trace log:
> {code:java}
> [2022-02-09 08:48:30,784] INFO [GroupMetadataManager brokerId=2] Scheduling
> loading of offsets and group metadata from __consumer_offsets-48 for epoch 3
> (kafka.coordinator.group.GroupMetadataManager) [2022-02-09 08:48:30,784]
> DEBUG Scheduling task __consumer_offsets-48 with initial delay 0 ms and
> period -1 ms. (kafka.utils.KafkaScheduler) [2022-02-09 08:48:30,784] TRACE
> Beginning execution of scheduled task '__consumer_offsets-48'.
> (kafka.utils.KafkaScheduler) [2022-02-09 08:48:30,784] DEBUG
> [GroupMetadataManager brokerId=2] Started loading offsets and group metadata
> from __consumer_offsets-48 for epoch 3
> (kafka.coordinator.group.GroupMetadataManager) [2022-02-09 08:48:30,784]
> TRACE [Log partition=__consumer_offsets-48, dir=/var/lib/kafka] Reading
> maximum 5242880 bytes at offset 0 from log with total length 542972 bytes
> (kafka.log.Log) [2022-02-09 08:48:30,857] ERROR [GroupMetadataManager
> brokerId=2] Error loading offsets from __consumer_offsets-48
> (kafka.coordinator.group.GroupMetadataManager)
> org.apache.kafka.common.errors.CorruptRecordException: Record size 0 is less
> than the minimum record overhead (14) [2022-02-09 08:48:30,858] TRACE
> Completed execution of scheduled task '__consumer_offsets-48'.
> (kafka.utils.KafkaScheduler){code}
>
> And some of the consumer groups are absent
>
> According to the source we trying to read the file like its size is 1Gb and
> we get zero batch size after all real data. Looks like problem in this ticket
> - https://issues.apache.org/jira/browse/KAFKA-5431
> And maybe it's linked. If you enabled log.preallocate flag, you get
> CorruptRecordException when trying to read any log segments with
> kafka-dump-log.sh
> {code:java}
> root@somehost /var/lib/kafka/topic-0 # /opt/kafka/bin/kafka-dump-log.sh
> --files 00000000000000000000.log
> Dumping 00000000000000000000.log
> Starting offset: 0
> Exception in thread "main"
> org.apache.kafka.common.errors.CorruptRecordException: Found record size 0
> smaller than minimum record overhead (14) in file
> 00000000000000000000.log.{code}
>
> When you look at log segments on disk it zero-filled big files:
> {code:java}
> root@somehost /var/lib/kafka/topic-0 # ls -lh
> total 4.0K
> rw-rr- 1 kafka kafka 10M Feb 9 17:23 00000000000000000000.index
> rw-rr- 1 kafka kafka 1.0G Feb 9 17:23 00000000000000000000.log
> rw-rr- 1 kafka kafka 10M Feb 9 17:23 00000000000000000000.timeindex
> rw-rr- 1 kafka kafka 8 Feb 9 17:23 leader-epoch-checkpoint{code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
