Kafka Producer cannot send to a topic with transactional producer

Question

I am using Spring Cloud Stream with Kafka binder. I have configured a transactional producer. However, I have one topic with a large number of partitions (135), and it seems to cause trouble with this approach. I am using StreamBridge to produce messages. It appears to attempt to create a transactional producer only when I send the first message to the stream. I then see it attempting to get information about each partition, but the operation times out. It is then caching a MessageChannel with fullChannelName set to "unknown.channel.name" which causes all subsequent calls to StreamBridge.send to fail for that channel.

Are there any suggestions on what I can do to get the message sent? Is there a way to gather the partition data on application start so that my messages can just send?

This is the log that seems to be repeated for each partition:

2021-08-24 16:45:01.160 ERROR 59629 --- [   scheduling-1] o.s.c.s.b.k.p.KafkaTopicProvisioner      : Failed to obtain partition information

org.springframework.kafka.KafkaException: initTransactions() failed; nested exception is org.apache.kafka.common.errors.TimeoutException: Timeout expired after 60000 milliseconds while awaiting InitProducerId
    at org.springframework.kafka.core.DefaultKafkaProducerFactory.doCreateTxProducer(DefaultKafkaProducerFactory.java:732) ~[spring-kafka-2.7.6.jar:2.7.6]
    at org.springframework.kafka.core.DefaultKafkaProducerFactory.createTransactionalProducer(DefaultKafkaProducerFactory.java:673) ~[spring-kafka-2.7.6.jar:2.7.6]
    at org.springframework.kafka.core.DefaultKafkaProducerFactory.createTransactionalProducerForPartition(DefaultKafkaProducerFactory.java:594) ~[spring-kafka-2.7.6.jar:2.7.6]
    at org.springframework.kafka.core.DefaultKafkaProducerFactory.doCreateProducer(DefaultKafkaProducerFactory.java:530) ~[spring-kafka-2.7.6.jar:2.7.6]
    at org.springframework.kafka.core.DefaultKafkaProducerFactory.createProducer(DefaultKafkaProducerFactory.java:519) ~[spring-kafka-2.7.6.jar:2.7.6]
    at org.springframework.kafka.core.DefaultKafkaProducerFactory.createProducer(DefaultKafkaProducerFactory.java:513) ~[spring-kafka-2.7.6.jar:2.7.6]
    at org.springframework.cloud.stream.binder.kafka.KafkaMessageChannelBinder.lambda$createProducerMessageHandler$0(KafkaMessageChannelBinder.java:396) ~[spring-cloud-stream-binder-kafka-3.1.3.jar:3.1.3]
    at org.springframework.cloud.stream.binder.kafka.provisioning.KafkaTopicProvisioner.lambda$getPartitionsForTopic$6(KafkaTopicProvisioner.java:535) ~[spring-cloud-stream-binder-kafka-core-3.1.3.jar:3.1.3]

This is the log I see related to the binder:

2021-08-24 16:45:12.768 ERROR 59629 --- [   scheduling-1] o.s.cloud.stream.binding.BindingService  : Failed to create producer binding; retrying in 30 seconds

org.springframework.cloud.stream.binder.BinderException: Cannot initialize binder:
    at org.springframework.cloud.stream.binder.kafka.provisioning.KafkaTopicProvisioner.getPartitionsForTopic(KafkaTopicProvisioner.java:591) ~[spring-cloud-stream-binder-kafka-core-3.1.3.jar:3.1.3]
    at org.springframework.cloud.stream.binder.kafka.KafkaMessageChannelBinder.createProducerMessageHandler(KafkaMessageChannelBinder.java:394) ~[spring-cloud-stream-binder-kafka-3.1.3.jar:3.1.3]
    at org.springframework.cloud.stream.binder.kafka.KafkaMessageChannelBinder.createProducerMessageHandler(KafkaMessageChannelBinder.java:158) ~[spring-cloud-stream-binder-kafka-3.1.3.jar:3.1.3]
    at org.springframework.cloud.stream.binder.AbstractMessageChannelBinder.doBindProducer(AbstractMessageChannelBinder.java:226) ~[spring-cloud-stream-3.1.3.jar:3.1.3]
    at org.springframework.cloud.stream.binder.AbstractMessageChannelBinder.doBindProducer(AbstractMessageChannelBinder.java:91) ~[spring-cloud-stream-3.1.3.jar:3.1.3]
    at org.springframework.cloud.stream.binder.AbstractBinder.bindProducer(AbstractBinder.java:152) ~[spring-cloud-stream-3.1.3.jar:3.1.3]
    at org.springframework.cloud.stream.binding.BindingService.lambda$rescheduleProducerBinding$4(BindingService.java:343) ~[spring-cloud-stream-3.1.3.jar:3.1.3]
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.3.9.jar:5.3.9]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java) ~[na:na]
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na]
    at java.base/java.lang.Thread.run(Thread.java:829) ~[na:na]

As well as this error, repeated throughout:

2021-08-24 17:08:02.753 ERROR 59629 --- [   scheduling-1] o.s.c.s.b.k.p.KafkaTopicProvisioner      : Cannot initialize Binder

java.lang.IllegalStateException: The number of expected partitions was: 1, but 0 has been found instead
    at org.springframework.cloud.stream.binder.kafka.provisioning.KafkaTopicProvisioner.lambda$getPartitionsForTopic$6(KafkaTopicProvisioner.java:579) ~[spring-cloud-stream-binder-kafka-core-3.1.3.jar:3.1.3]
    at org.springframework.retry.support.RetryTemplate.doExecute(RetryTemplate.java:329) ~[spring-retry-1.3.1.jar:na]
    at org.springframework.retry.support.RetryTemplate.execute(RetryTemplate.java:209) ~[spring-retry-1.3.1.jar:na]
    at org.springframework.cloud.stream.binder.kafka.provisioning.KafkaTopicProvisioner.getPartitionsForTopic(KafkaTopicProvisioner.java:530) ~[spring-cloud-stream-binder-kafka-core-3.1.3.jar:3.1.3]
    at org.springframework.cloud.stream.binder.kafka.KafkaMessageChannelBinder.createProducerMessageHandler(KafkaMessageChannelBinder.java:394) ~[spring-cloud-stream-binder-kafka-3.1.3.jar:3.1.3]
    at org.springframework.cloud.stream.binder.kafka.KafkaMessageChannelBinder.createProducerMessageHandler(KafkaMessageChannelBinder.java:158) ~[spring-cloud-stream-binder-kafka-3.1.3.jar:3.1.3]
    at org.springframework.cloud.stream.binder.AbstractMessageChannelBinder.doBindProducer(AbstractMessageChannelBinder.java:226) ~[spring-cloud-stream-3.1.3.jar:3.1.3]
    at org.springframework.cloud.stream.binder.AbstractMessageChannelBinder.doBindProducer(AbstractMessageChannelBinder.java:91) ~[spring-cloud-stream-3.1.3.jar:3.1.3]
    at org.springframework.cloud.stream.binder.AbstractBinder.bindProducer(AbstractBinder.java:152) ~[spring-cloud-stream-3.1.3.jar:3.1.3]
    at org.springframework.cloud.stream.binding.BindingService.lambda$rescheduleProducerBinding$4(BindingService.java:343) ~[spring-cloud-stream-3.1.3.jar:3.1.3]
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.3.9.jar:5.3.9]
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:264) ~[na:na]
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java) ~[na:na]
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na]
    at java.base/java.lang.Thread.run(Thread.java:829) ~[na:na]

Finally, I see the message send fail and return execution to my application

2021-08-24 16:59:43.224 ERROR 59629 --- [nio-8080-exec-4] s.s.e.RestResponseEntityExceptionHandler : org.springframework.messaging.MessageDeliveryException: Dispatcher has no subscribers for channel 'unknown.channel.name'.; nested exception is org.springframework.integration.MessageDispatchingException: Dispatcher has no subscribers, failedMessage=GenericMessage [payload=byte[235], headers={<snip>}, ce-source=https://spring.io/, kafka_messageKey=d15140aa-3b64-416a-9b1f-8829ee7c8319, ce-type=<my type>, message-type=cloudevent, specversion=1.0.8, id=c05e84b6-40ad-3787-32b8-54096cb735aa, contentType=application/avro, timestamp=1629841968540}], failedMessage=GenericMessage [payload=byte[235], headers={<snip>, contentType=application/avro, timestamp=1629841968540}]

org.springframework.messaging.MessageDeliveryException: Dispatcher has no subscribers for channel 'unknown.channel.name'.; nested exception is org.springframework.integration.MessageDispatchingException: Dispatcher has no subscribers, failedMessage=GenericMessage [payload=byte[235], headers={<snip>, contentType=application/avro, timestamp=1629841968540}]
    at org.springframework.integration.channel.AbstractSubscribableChannel.doSend(AbstractSubscribableChannel.java:76) ~[spring-integration-core-5.5.3.jar:5.5.3]
    at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:317) ~[spring-integration-core-5.5.3.jar:5.5.3]
    at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:272) ~[spring-integration-core-5.5.3.jar:5.5.3]
    at org.springframework.cloud.stream.function.StreamBridge.send(StreamBridge.java:215) ~[spring-cloud-stream-3.1.3.jar:3.1.3]
    at org.springframework.cloud.stream.function.StreamBridge.send(StreamBridge.java:156) ~[spring-cloud-stream-3.1.3.jar:3.1.3]
...my app stacktrace...

`The number of expected partitions was: 1, but 0 has been found instead` seems like your issue. Does the broker have the transactions topic? — OneCricketeer, Aug 24 '21 at 22:20
What is a transactions topic? I should add that everything works if I don’t use a transactional producer. — Bert S., Aug 25 '21 at 12:33
Transactions are maintained in their own topic in addition to the topic you're actually writing to. Look at the server properties https://kafka.apache.org/documentation/#brokerconfigs_transaction.state.log.num.partitions If that transaction topic doesn't exist, or is otherwise unhealthy (as the error says, 0 partitions found), then transactions don't work — OneCricketeer, Aug 25 '21 at 12:45
Usually such timeouts occur if there are not enough replicas to support transactions. Look at the server logs. See these broker properties `transaction.state.log.replication.factor` and `transaction.state.log.min.isr`. — Gary Russell, Aug 25 '21 at 14:55
I am now able to confirm that transaction.state.log.min.isr = 2, transaction.state.log.num.partitions = 50, and transaction.state.log.replication.factor = 3 — Bert S., Aug 26 '21 at 16:46
@OneCricketeer my broker is not creating the __transaction_state topic. Is there something that needs to be enabled for that to be created? — Bert S., Aug 26 '21 at 21:10
Only a freshly installed cluster above version `0.11` will create that, I think... You should be able to manually create it (with 50 partitions and 3 replicas, like your settings have), if it doesn't exist already. — OneCricketeer, Aug 26 '21 at 21:50

Kafka Producer cannot send to a topic with transactional producer

0 Answers0