Johnny Malizia created KAFKA-10207:
--------------------------------------
Summary: Untrimmed Index files cause premature log segment
deletions on startup
Key: KAFKA-10207
URL: https://issues.apache.org/jira/browse/KAFKA-10207
Project: Kafka
Issue Type: Bug
Components: log
Affects Versions: 2.4.1, 2.3.1, 2.4.0
Reporter: Johnny Malizia
[KIP-263|https://cwiki.apache.org/confluence/display/KAFKA/KIP-263%3A+Allow+broker+to+skip+sanity+check+of+inactive+segments+on+broker+startup#KIP263:Allowbrokertoskipsanitycheckofinactivesegmentsonbrokerstartup-Evaluation]
appears to have introduced a change explicitly deciding to not call the
sanityCheck method on the time or offset index files that are loaded by Kafka
at startup. I found a particularly nasty bug using the following configuration
{code:java}
jvm=1.8.0_191 zfs=0.6.5.6 kernel=4.4.0-1013-aws kafka=2.4.1{code}
The bug was that the retention period for a topic or even the broker level
configuration seemed to not be respected, no matter what, when the broker
started up it would decide that all log segments on disk were breaching the
retention window and the data would be purged away.
{code:java}
Found deletable segments with base offsets [11610665,12130396,12650133] due to
retention time 86400000ms breach {code}
{code:java}
Rolled new log segment at offset 12764291 in 1 ms. (kafka.log.Log)
Scheduling segments for deletion List(LogSegment(baseOffset=11610665,
size=1073731621, lastModifiedTime=1592532125000, largestTime=0),
LogSegment(baseOffset=12130396, size=1073727967,
lastModifiedTime=1592532462000, largestTime=0), LogSegment(baseOffset=12650133,
size=235891971, lastModifiedTime=1592532531000, largestTime=0)) {code}
Further logging showed that this issue was happening when loading the files,
indicating the final writes to trim the index were not successful
{code:java}
DEBUG Loaded index file
/mnt/kafka-logs/test_topic-0/00000000000017221277.timeindex with maxEntries =
873813, maxIndexSize = 10485760, entries = 873813, lastOffset =
TimestampOffset(0,17221277), file position = 10485756
(kafka.log.TimeIndex){code}
So, because the index leaves the preallocated 0 bytes at the tail, when the
index is loaded again after restarting Kafka, the next timestamp is 0 and this
leads to a premature TTL deletion of the log segments.
I tracked the issue down to being caused by the jvm version being used as
upgrading resolved this issue, but I think that Kafka should never delete data
by mistake like this as doing a rolling restart with this bug in place would
cause complete data-loss across the cluster.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
