[jira] [Resolved] (KAFKA-12701) NPE in MetadataRequest when using topic IDs
[
https://issues.apache.org/jira/browse/KAFKA-12701?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
dengziming resolved KAFKA-12701.
Assignee: Justine Olshan (was: dengziming)
Resolution: Fixed
> NPE in MetadataRequest when using topic IDs
> ---
>
> Key: KAFKA-12701
> URL: https://issues.apache.org/jira/browse/KAFKA-12701
> Project: Kafka
> Issue Type: Bug
>Affects Versions: 2.8.0
>Reporter: Travis Bischel
>Assignee: Justine Olshan
>Priority: Major
>
> Authorized result checking relies on topic name to not be null, which, when
> using topic IDs, it is.
> Unlike the logic in handleDeleteTopicsRequest, handleMetadataRequest does not
> check zk for the names corresponding to topic IDs if topic IDs are present.
> {noformat}
> [2021-04-21 05:53:01,463] ERROR [KafkaApi-1] Error when handling request:
> clientId=kgo, correlationId=1, api=METADATA, version=11,
> body=MetadataRequestData(topics=[MetadataRequestTopic(topicId=LmqOoFOASnqQp_4-oJgeKA,
> name=null)], allowAutoTopicCreation=false,
> includeClusterAuthorizedOperations=false,
> includeTopicAuthorizedOperations=false) (kafka.server.RequestHandlerHelper)
> java.lang.NullPointerException: name
> at java.base/java.util.Objects.requireNonNull(Unknown Source)
> at
> org.apache.kafka.common.resource.ResourcePattern.(ResourcePattern.java:50)
> at
> kafka.server.AuthHelper.$anonfun$filterByAuthorized$3(AuthHelper.scala:121)
> at scala.collection.Iterator$$anon$9.next(Iterator.scala:575)
> at scala.collection.mutable.Growable.addAll(Growable.scala:62)
> at scala.collection.mutable.Growable.addAll$(Growable.scala:57)
> at scala.collection.mutable.ArrayBuffer.addAll(ArrayBuffer.scala:142)
> at scala.collection.mutable.ArrayBuffer.addAll(ArrayBuffer.scala:42)
> at scala.collection.mutable.ArrayBuffer$.from(ArrayBuffer.scala:258)
> at scala.collection.mutable.ArrayBuffer$.from(ArrayBuffer.scala:247)
> at scala.collection.SeqFactory$Delegate.from(Factory.scala:306)
> at scala.collection.IterableOnceOps.toBuffer(IterableOnce.scala:1270)
> at scala.collection.IterableOnceOps.toBuffer$(IterableOnce.scala:1270)
> at scala.collection.AbstractIterator.toBuffer(Iterator.scala:1288)
> at kafka.server.AuthHelper.filterByAuthorized(AuthHelper.scala:120)
> at
> kafka.server.KafkaApis.handleTopicMetadataRequest(KafkaApis.scala:1146)
> at kafka.server.KafkaApis.handle(KafkaApis.scala:170)
> at kafka.server.KafkaRequestHandler.run(KafkaRequestHandler.scala:74)
> at java.base/java.lang.Thread.run(Unknown Source)
> [2021-04-21 05:53:01,464] ERROR [Kafka Request Handler 1 on Broker 1],
> Exception when handling request (kafka.server.KafkaRequestHandler)
> java.lang.NullPointerException
> at
> org.apache.kafka.common.message.MetadataResponseData$MetadataResponseTopic.addSize(MetadataResponseData.java:1247)
> at
> org.apache.kafka.common.message.MetadataResponseData.addSize(MetadataResponseData.java:417)
> at
> org.apache.kafka.common.protocol.SendBuilder.buildSend(SendBuilder.java:218)
> at
> org.apache.kafka.common.protocol.SendBuilder.buildResponseSend(SendBuilder.java:200)
> at
> org.apache.kafka.common.requests.AbstractResponse.toSend(AbstractResponse.java:43)
> at
> org.apache.kafka.common.requests.RequestContext.buildResponseSend(RequestContext.java:111)
> at
> kafka.network.RequestChannel$Request.buildResponseSend(RequestChannel.scala:132)
> at
> kafka.server.RequestHandlerHelper.sendResponse(RequestHandlerHelper.scala:185)
> at
> kafka.server.RequestHandlerHelper.sendErrorOrCloseConnection(RequestHandlerHelper.scala:155)
> at
> kafka.server.RequestHandlerHelper.sendErrorResponseMaybeThrottle(RequestHandlerHelper.scala:109)
> at
> kafka.server.RequestHandlerHelper.handleError(RequestHandlerHelper.scala:79)
> at kafka.server.KafkaApis.handle(KafkaApis.scala:229)
> at kafka.server.KafkaRequestHandler.run(KafkaRequestHandler.scala:74)
> at java.base/java.lang.Thread.run(Unknown Source)
> {noformat}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
[jira] [Created] (KAFKA-13222) Records in newly rolled segment couldn't be fetched by consumer
Zhipeng Liu created KAFKA-13222:
---
Summary: Records in newly rolled segment couldn't be fetched by
consumer
Key: KAFKA-13222
URL: https://issues.apache.org/jira/browse/KAFKA-13222
Project: Kafka
Issue Type: Bug
Reporter: Zhipeng Liu
We encountered a issue about Kafka broker in production environment, one of
consumers within a consumer group unable to fetch messages suddenly from the
partition it was assigned. The offset that the consumer couldn't fetch just the
base offset of an new segment file.
{code:java}
# /opt/kafka/bin/kafka-consumer-groups.sh --bootstrap-server localhost:9092
--describe --group privisioning
TOPIC PARTITION CURRENT-OFFSET LOG-END-OFFSET LAG CONSUMER-ID HOST CLIENT-ID
..
nrss_event 0 18898345 18899120 775
consumer-2-0af9de42-7d3d-4a9b-a7af-f70cd51e518f /10.199.149.89 consumer-2
dbqt_event 0 83 83 0 consumer-2-0af9de42-7d3d-4a9b-a7af-f70cd51e518f
/10.199.149.89 consumer-2
..
{code}
Below is the log segments status.
{code:java}
# ls -lrth
total 432K
-rw-r--r-- 1 kafka kafka 10 Aug 4 22:03 18897133.snapshot
-rw-r--r-- 1 kafka kafka 246K Aug 11 11:03 18897133.log
-rw-r--r-- 1 kafka kafka 464 Aug 11 22:29 18897133.index
-rw-r--r-- 1 kafka kafka 708 Aug 11 22:29 18897133.timeindex
-rw-r--r-- 1 kafka kafka 10 Aug 11 22:29 18898345.snapshot
-rw-r--r-- 1 kafka kafka 10M Aug 13 23:32 18898345.timeindex
-rw-r--r-- 1 kafka kafka 10M Aug 13 23:32 18898345.index
-rw-r--r-- 1 kafka kafka 154K Aug 13 23:42 18898345.log
-rw-r--r-- 1 kafka kafka 28 Aug 16 18:46 leader-epoch-checkpoint
{code}
We dumped the older segment 18897133.log (Starting offset:
18897133) and the latest record (offset: 18898344) created at 11:03 Aug 11.
We checked server log on Aug 11 and found a segment rolling happened at 22:29.
{code:java}
[2021-08-11 22:03:46,004] INFO [Log partition=nrss_event-0,
dir=/kafka/kafka/data] Found deletable segments with base offsets [18895822]
due to retention time 60480ms breach (kafka.log.Log)
[2021-08-11 22:03:46,004] INFO [Log partition=nrss_event-0,
dir=/kafka/kafka/data] Scheduling log segment [baseOffset 18895822, size
266974] for deletion. (kafka.log.Log)
[2021-08-11 22:03:46,005] INFO [Log partition=nrss_event-0,
dir=/kafka/kafka/data] Incrementing log start offset to 18897133 (kafka.log.Log)
[2021-08-11 22:04:46,005] INFO [Log partition=nrss_event-0,
dir=/kafka/kafka/data] Deleting segment 18895822 (kafka.log.Log)
[2021-08-11 22:04:46,006] INFO Deleted log
/kafka/kafka/data/nrss_event-0/18895822.log.deleted.
(kafka.log.LogSegment)
[2021-08-11 22:04:46,006] INFO Deleted offset index
/kafka/kafka/data/nrss_event-0/18895822.index.deleted.
(kafka.log.LogSegment)
[2021-08-11 22:04:46,007] INFO Deleted time index
/kafka/kafka/data/nrss_event-0/18895822.timeindex.deleted.
(kafka.log.LogSegment)
{code}
We noticed there is a similar issue KAFKA-10313 reported before about segment
rolling. We checked logging of Kafka client consumer (with logging level INFO
in logback.xml), but not found any similar logging, no offset reset happened at
Kafka client.
We used default segment rotation period (168 hrs) and size (1G), suppose there
should be only one segment in the log folder. But the records in my enviroment
spreads in two segments and the records in the newer segment couldn't be
fetched by consumer. It is quite confused to me and wondering if a Kafka bug
for my broker version.
Version info:
||component||version||
|Kafka broker|2.0.1
|Kafka client|0.11.0.0|
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
[jira] [Resolved] (KAFKA-13218) kafka deleted unexpired message unexpectedly
[
https://issues.apache.org/jira/browse/KAFKA-13218?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
leiminghany resolved KAFKA-13218.
-
Resolution: Not A Problem
> kafka deleted unexpired message unexpectedly
>
>
> Key: KAFKA-13218
> URL: https://issues.apache.org/jira/browse/KAFKA-13218
> Project: Kafka
> Issue Type: Bug
> Components: core
>Affects Versions: 2.7.0
> Environment: docker file :
> from openjdk:11-jre-slim-buster
> RUN apt-get update
> RUN apt-get -y install net-tools iputils-ping curl procps
> RUN curl -OL
> https://mirrors.bfsu.edu.cn/apache/kafka/2.7.0/kafka_2.13-2.7.0.tgz && tar
> -xzf kafka_2.13-2.7.0.tgz && rm -f kafka_2.13-2.7.0.tgz
> ENV PATH "$PATH:/kafka_2.13-2.7.0/bin"
> RUN mkdir /etc/kafka
> COPY server.properties /etc/kafka/server.properties
> CMD ["kafka-server-start.sh", "/etc/kafka/server.properties"]
> configure file:
> broker.id=2
> log.dirs=/var/lib/kafka
> log.segment.bytes=10485760
> zookeeper.connect=zk-cs.default.svc.cluster.local:2181
> sasl.enabled.mechanisms=PLAIN
> sasl.mechanism.inter.broker.protocol=PLAIN
> inter.broker.listener.name=INTERNAL
> listener.security.protocol.map=INTERNAL:SASL_PLAINTEXT,EXTERNAL:SASL_PLAINTEXT
> listeners=INTERNAL://:9092,EXTERNAL://:30101
> advertised.listeners=INTERNAL://kafka-2.kafka.default.svc.cluster.local:9092,EXTERNAL://192.168.0.13:30101
>Reporter: leiminghany
>Priority: Blocker
>
> I created a topic like this :
>
> {code:java}
> kafka-topics.sh --create --zookeeper zk-cs.default.svc.cluster.local:2181
> --partitions 64 --replication-factor 2 --topic signal --config
> retention.ms=6048000{code}
> and then I send several message into partition 2 of this topic .
>
> after than, I try to consumer the message from this partiton, but I can't get
> any messages.
> I read the kafka data directory, I found the log file was rolled, here is
> the files:
>
> {code:java}
> root@kafka-2:/var/lib/kafka/signal-2# ls
> 0005.index 0005.log
> 0005.snapshot 0005.timeindex
> leader-epoch-checkpoint
> {code}
> and the dump info is :
>
>
> {code:java}
> root@kafka-2:/var/lib/kafka/signal-2# kafka-run-class.sh
> kafka.tools.DumpLogSegments --deep-iteration --files 0005.log
> Dumping 0005.log
> Starting offset: 5
> root@kafka-2:/var/lib/kafka/signal-2#
> root@kafka-2:/var/lib/kafka/signal-2# kafka-run-class.sh
> kafka.tools.DumpLogSegments --deep-iteration --files
> 0005.index
> Dumping 0005.index
> root@kafka-2:/var/lib/kafka/signal-2# kafka-run-class.sh
> kafka.tools.DumpLogSegments --deep-iteration --files
> 0005.snapshot
> Dumping 0005.snapshot
> root@kafka-2:/var/lib/kafka/signal-2# kafka-run-class.sh
> kafka.tools.DumpLogSegments --deep-iteration --files
> 0005.timeindex
> Dumping 0005.timeindex
> timestamp: 0 offset: 5
> The following indexed offsets are not found in the log.
> Indexed offset: 5, found log offset: -1
> root@kafka-2:/var/lib/kafka/signal-2# cat leader-epoch-checkpoint
> 0
> 1
> 0 5
> {code}
>
> here is the kafka console log about this partition:
>
> {code:java}
> [2021-08-18 12:04:57,652] INFO [ProducerStateManager partition=signal-2]
> Writing producer snapshot at offset 5 (kafka.log.ProducerStateManager)
> [2021-08-18 12:04:57,653] INFO [Log partition=signal-2, dir=/var/lib/kafka]
> Rolled new log segment at offset 5 in 7 ms. (kafka.log.Log)
> [2021-08-18 12:04:57,653] INFO [Log partition=signal-2, dir=/var/lib/kafka]
> Deleting segment LogSegment(baseOffset=0, size=318,
> lastModifiedTime=1629288220552, largestRecordTimestamp=Some(0)) due to
> retention time 6048000ms breach based on the largest record timestamp in
> the segment (kafka.log.Log)
> [2021-08-18 12:04:57,653] INFO [Log partition=signal-2, dir=/var/lib/kafka]
> Incremented log start offset to 5 due to segment deletion (kafka.log.Log)
> [2021-08-18 12:05:57,671] INFO [Log partition=signal-2, dir=/var/lib/kafka]
> Deleting segment files LogSegment(baseOffset=0, size=318,
> lastModifiedTime=1629288220552, largestRecordTimestamp=Some(0))
> (kafka.log.Log)
> [2021-08-18 12:05:57,672] INFO Deleted log
> /var/lib/kafka/signal-2/.log.deleted.
> (kafka.log.LogSegment)
> [2021-08-18 12:05:57,672] INFO Deleted offset index
> /var/lib/kafka/signal-2/.index.deleted.
> (kafka.log.LogSegment)
> [2021-08-18 12:05:57,673] INFO Deleted time index
> /var/lib/kafka/signal-2/.timeindex.deleted.
> (kafka.log.LogSegment)
> {code}
>
>
>
>
> I think the `largestRecordTimestamp=Some(0)` may be the clue to track this
> problem, But I can not find out the exact
