You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@kafka.apache.org by Sambhaji Gayake <ga...@gmail.com> on 2020/11/12 13:13:44 UTC
After sending 200+ records to a particular topic, Kafka producer
fails to send record to any other topic
Hi,
While using Kafka, I found this strange behavior. Note that all topics are
already created. Following is a sequence of events.
1. Kafka Producer sends 200+ records on a particular topic in one go. For
the first record, since the producer does not have metadata, it requests
one from the broker. After getting it, it produces the first record.
DEBUG | 2020-10-30 07:01:13,031 | CProducer.java | sendToBroker:74 | Trying
to produce to Kafka topic array.harrypotter.com.xyz.cm.xln messageNo 1 key
xln1.zip.split.1 partition null Broker pusntzh135.apac.xyz.com:32090
TRACE | 2020-10-30 07:01:13,032 | KafkaProducer.java | waitOnMetadata:976 |
[Producer clientId=Client10.133.87.9] Requesting metadata update for topic
array.harrypotter.com.xyz.cm.xln.
TRACE | 2020-10-30 07:01:13,033 | NetworkClient.java | leastLoadedNode:670
| [Producer clientId=Client10.133.87.9] Found least loaded node
pusntzh135.apac.xyz.com:32090 (id: -1 rack: null)
DEBUG | 2020-10-30 07:01:13,033 | NetworkClient.java | maybeUpdate:1085 |
[Producer clientId=Client10.133.87.9] Initialize connection to node
pusntzh135.apac.xyz.com:32090 (id: -1 rack: null) for sending metadata
request
DEBUG | 2020-10-30 07:01:13,033 | NetworkClient.java | initiateConnect:914
| [Producer clientId=Client10.133.87.9] Initiating connection to node
pusntzh135.apac.xyz.com:32090 (id: -1 rack: null) using address
pusntzh135.apac.xyz.com/10.133.81.135
DEBUG | 2020-10-30 07:01:13,404 | NetworkClient.java | maybeUpdate:1069 |
[Producer clientId=Client10.133.87.9] Sending metadata request
(type=MetadataRequest, topics=array.harrypotter.com.xyz.cm.xln) to node
pusntzh135.apac.xyz.com:32090 (id: -1 rack: null)
DEBUG | 2020-10-30 07:01:13,407 | Metadata.java | update:290 | Updated
cluster metadata version 2 to Cluster(id = 3n4wJLb3R3GDli2sXMlM0g, nodes = [
pusntzh135.apac.xyz.com:32090 (id: 0 rack: null),
pusntzh135.apac.xyz.com:32091 (id: 1 rack: null),
pusntzh135.apac.xyz.com:32092 (id: 2 rack: null)], partitions =
[Partition(topic = array.harrypotter.com.xyz.cm.xln, partition = 0, leader
= 0, replicas = [0,2,1], isr = [0,2,1], offlineReplicas = [])], controller
= pusntzh135.apac.xyz.com:32090 (id: 0 rack: null))
TRACE | 2020-10-30 07:01:13,415 | KafkaProducer.java | doSend:893 |
[Producer clientId=Client10.133.87.9] Sending record
ProducerRecord(topic=array.harrypotter.com.xyz.cm.xln, partition=null,
headers=RecordHeaders(headers = [], isReadOnly = true),
key=xln1.zip.split.1, value=[B@f4fe21e, timestamp=null) with callback
com.xyz.kafkaclient.producer.CProducer$1@1dbcc03c to topic
array.harrypotter.com.xyz.cm.xln partition 0
So the first record to topic array.harrypotter.com.xyz.cm.xln is produced
successfully.
2. For subsequent records to the same topic
array.harrypotter.com.xyz.cm.xln, producer doesn't try to get metadata
again as the producer already has one.
3. Now the producer tries to produce on a different
topic array.harrypotter.com.xyz.cm.metadata. Producer doesn't have metadata
for this topic, so tries to get one from the broker.
DEBUG | 2020-10-30 07:01:36,729 | CProducer.java | sendToBroker:74 | Trying
to produce to Kafka topic array.harrypotter.com.xyz.cm.metadata messageNo
208 key metakey partition null Broker pusntzh135.apac.xyz.com:32090
TRACE | 2020-10-30 07:01:36,730 | KafkaProducer.java | waitOnMetadata:976 |
[Producer clientId=Client10.133.87.9] Requesting metadata update for topic
array.harrypotter.com.xyz.cm.metadata.
However nothing happens after this, i.e. functions maybeUpdate,
leastLoadedNode, initiateConnect etc. are not called. producer.send then
times out after 60 seconds. This means the producer did not send out any
request to Kafka Broker.
ERROR | 2020-10-30 07:02:36,741 | CProducer.java | onCompletion:89 | Can
not produce to Kafka topic array.harrypotter.com.xyz.cm.metadata messageNo
208 key = metakey because of
org.apache.kafka.common.errors.TimeoutException: Topic
array.harrypotter.com.xyz.cm.metadata not present in metadata after 60000
ms., have been trying for 60002ms to produce to
pusntzh135.apac.xyz.com:32090
DEBUG | 2020-10-30 07:02:36,742 | CProducer.java | sendToBroker:74 | Trying
to produce to Kafka topic array.harrypotter.com.xyz.cm.metadata messageNo
208 key metakey partition null Broker pusntzh135.apac.xyz.com:32090
After this producer is not able to send on any topic (all topics are
already created) for which it doesn't have metadata. There are two
workarounds.
1. Restart Kafka Producer.
2. Before producing 200+ records, get metadata for all topics by
calling producer.partitionsFor.
Can someone please tell me why the producer is not able to send out
metadata request in step 3? I have attached logs as well.
Thanks,
Sambhaji
Re: After sending 200+ records to a particular topic, Kafka producer fails to send record to any other topic
Posted by Sambhaji Gayake <ga...@gmail.com>.
Hi All,
Does anyone have any inputs?
Thanks,
Sambhaji
On 2020/11/12 13:13:44, Sambhaji Gayake <ga...@gmail.com> wrote:
> Hi,
>
> While using Kafka, I found this strange behavior. Note that all topics are
> already created. Following is a sequence of events.
>
> 1. Kafka Producer sends 200+ records on a particular topic in one go. For
> the first record, since the producer does not have metadata, it requests
> one from the broker. After getting it, it produces the first record.
>
> DEBUG | 2020-10-30 07:01:13,031 | CProducer.java | sendToBroker:74 | Trying
> to produce to Kafka topic array.harrypotter.com.xyz.cm.xln messageNo 1 key
> xln1.zip.split.1 partition null Broker pusntzh135.apac.xyz.com:32090
> TRACE | 2020-10-30 07:01:13,032 | KafkaProducer.java | waitOnMetadata:976 |
> [Producer clientId=Client10.133.87.9] Requesting metadata update for topic
> array.harrypotter.com.xyz.cm.xln.
> TRACE | 2020-10-30 07:01:13,033 | NetworkClient.java | leastLoadedNode:670
> | [Producer clientId=Client10.133.87.9] Found least loaded node
> pusntzh135.apac.xyz.com:32090 (id: -1 rack: null)
> DEBUG | 2020-10-30 07:01:13,033 | NetworkClient.java | maybeUpdate:1085 |
> [Producer clientId=Client10.133.87.9] Initialize connection to node
> pusntzh135.apac.xyz.com:32090 (id: -1 rack: null) for sending metadata
> request
> DEBUG | 2020-10-30 07:01:13,033 | NetworkClient.java | initiateConnect:914
> | [Producer clientId=Client10.133.87.9] Initiating connection to node
> pusntzh135.apac.xyz.com:32090 (id: -1 rack: null) using address
> pusntzh135.apac.xyz.com/10.133.81.135
> DEBUG | 2020-10-30 07:01:13,404 | NetworkClient.java | maybeUpdate:1069 |
> [Producer clientId=Client10.133.87.9] Sending metadata request
> (type=MetadataRequest, topics=array.harrypotter.com.xyz.cm.xln) to node
> pusntzh135.apac.xyz.com:32090 (id: -1 rack: null)
> DEBUG | 2020-10-30 07:01:13,407 | Metadata.java | update:290 | Updated
> cluster metadata version 2 to Cluster(id = 3n4wJLb3R3GDli2sXMlM0g, nodes = [
> pusntzh135.apac.xyz.com:32090 (id: 0 rack: null),
> pusntzh135.apac.xyz.com:32091 (id: 1 rack: null),
> pusntzh135.apac.xyz.com:32092 (id: 2 rack: null)], partitions =
> [Partition(topic = array.harrypotter.com.xyz.cm.xln, partition = 0, leader
> = 0, replicas = [0,2,1], isr = [0,2,1], offlineReplicas = [])], controller
> = pusntzh135.apac.xyz.com:32090 (id: 0 rack: null))
> TRACE | 2020-10-30 07:01:13,415 | KafkaProducer.java | doSend:893 |
> [Producer clientId=Client10.133.87.9] Sending record
> ProducerRecord(topic=array.harrypotter.com.xyz.cm.xln, partition=null,
> headers=RecordHeaders(headers = [], isReadOnly = true),
> key=xln1.zip.split.1, value=[B@f4fe21e, timestamp=null) with callback
> com.xyz.kafkaclient.producer.CProducer$1@1dbcc03c to topic
> array.harrypotter.com.xyz.cm.xln partition 0
>
> So the first record to topic array.harrypotter.com.xyz.cm.xln is produced
> successfully.
>
> 2. For subsequent records to the same topic
> array.harrypotter.com.xyz.cm.xln, producer doesn't try to get metadata
> again as the producer already has one.
>
> 3. Now the producer tries to produce on a different
> topic array.harrypotter.com.xyz.cm.metadata. Producer doesn't have metadata
> for this topic, so tries to get one from the broker.
>
> DEBUG | 2020-10-30 07:01:36,729 | CProducer.java | sendToBroker:74 | Trying
> to produce to Kafka topic array.harrypotter.com.xyz.cm.metadata messageNo
> 208 key metakey partition null Broker pusntzh135.apac.xyz.com:32090
> TRACE | 2020-10-30 07:01:36,730 | KafkaProducer.java | waitOnMetadata:976 |
> [Producer clientId=Client10.133.87.9] Requesting metadata update for topic
> array.harrypotter.com.xyz.cm.metadata.
>
> However nothing happens after this, i.e. functions maybeUpdate,
> leastLoadedNode, initiateConnect etc. are not called. producer.send then
> times out after 60 seconds. This means the producer did not send out any
> request to Kafka Broker.
>
> ERROR | 2020-10-30 07:02:36,741 | CProducer.java | onCompletion:89 | Can
> not produce to Kafka topic array.harrypotter.com.xyz.cm.metadata messageNo
> 208 key = metakey because of
> org.apache.kafka.common.errors.TimeoutException: Topic
> array.harrypotter.com.xyz.cm.metadata not present in metadata after 60000
> ms., have been trying for 60002ms to produce to
> pusntzh135.apac.xyz.com:32090
> DEBUG | 2020-10-30 07:02:36,742 | CProducer.java | sendToBroker:74 | Trying
> to produce to Kafka topic array.harrypotter.com.xyz.cm.metadata messageNo
> 208 key metakey partition null Broker pusntzh135.apac.xyz.com:32090
>
> After this producer is not able to send on any topic (all topics are
> already created) for which it doesn't have metadata. There are two
> workarounds.
>
> 1. Restart Kafka Producer.
> 2. Before producing 200+ records, get metadata for all topics by
> calling producer.partitionsFor.
>
> Can someone please tell me why the producer is not able to send out
> metadata request in step 3? I have attached logs as well.
>
> Thanks,
> Sambhaji
>