After sending 200+ records to a particular topic, Kafka producer fails to send record to any other topic

Keywords: Kafka - Other - Technical issue - Other
Description:
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.

  1. 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.

  2. 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

Hi @gayake.sambhaji,

Are you running a container or a SingleVM? Did you change any configuration files? Could you run the bnsupport tool and paste the generated code ID here?

Best regards,
Michiel

This topic was automatically closed 14 days after the last reply. New replies are no longer allowed.