You are viewing a plain text version of this content. The canonical link for it is here.
Posted to jira@kafka.apache.org by "Raghu Baddam (JIRA)" <ji...@apache.org> on 2018/12/23 16:05:00 UTC

[jira] [Comment Edited] (KAFKA-6947) Mirrormaker Closing producer due to send failure

    [ https://issues.apache.org/jira/browse/KAFKA-6947?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16727992#comment-16727992 ] 

Raghu Baddam edited comment on KAFKA-6947 at 12/23/18 4:04 PM:
---------------------------------------------------------------

Even we are facing the same issue in Kafka 1.1.1 version.

 

{code}

[2018-12-23 15:23:51,800] INFO Closing producer due to send failure. (kafka.tools.MirrorMaker$)

[2018-12-23 15:23:51,800] INFO [Producer clientId=producer-1] Closing the Kafka producer with timeoutMillis = 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
[2018-12-23 15:23:51,800] INFO [Producer clientId=producer-1] Proceeding to force close the producer since pending requests could not be completed within timeout 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
[2018-12-23 15:23:51,800] ERROR Error when sending message to topic vulcan_carrier_tracking_updates_enriched_walmart_prod-az-uswest with key: 36 bytes, value: 978 bytes with error: (org.apache.kafka.clients.producer.internals.ErrorLoggingCallback)
java.lang.IllegalStateException: Producer is closed forcefully.
 at org.apache.kafka.clients.producer.internals.RecordAccumulator.abortBatches(RecordAccumulator.java:696)
 at org.apache.kafka.clients.producer.internals.RecordAccumulator.abortIncompleteBatches(RecordAccumulator.java:683)
 at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:185)
 at java.lang.Thread.run(Thread.java:745)
[2018-12-23 15:23:51,800] INFO Closing producer due to send failure. (kafka.tools.MirrorMaker$)
[2018-12-23 15:23:51,800] INFO [Producer clientId=producer-1] Closing the Kafka producer with timeoutMillis = 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
[2018-12-23 15:23:51,800] INFO [Producer clientId=producer-1] Proceeding to force close the producer since pending requests could not be completed within timeout 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
[2018-12-23 15:23:51,800] ERROR Error when sending message to topic vulcan_carrier_tracking_updates_enriched_walmart_prod-az-uswest with key: 36 bytes, value: 1235 bytes with error: (org.apache.kafka.clients.producer.internals.ErrorLoggingCallback)
java.lang.IllegalStateException: Producer is closed forcefully.
 at org.apache.kafka.clients.producer.internals.RecordAccumulator.abortBatches(RecordAccumulator.java:696)
 at org.apache.kafka.clients.producer.internals.RecordAccumulator.abortIncompleteBatches(RecordAccumulator.java:683)
 at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:185)
 at java.lang.Thread.run(Thread.java:745)
[2018-12-23 15:23:51,800] INFO Closing producer due to send failure. (kafka.tools.MirrorMaker$)
[2018-12-23 15:23:51,800] INFO [Producer clientId=producer-1] Closing the Kafka producer with timeoutMillis = 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
[2018-12-23 15:23:51,800] INFO [Producer clientId=producer-1] Proceeding to force close the producer since pending requests could not be completed within timeout 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
[2018-12-23 15:23:51,800] ERROR Error when sending message to topic vulcan_carrier_tracking_updates_enriched_walmart_prod-az-uswest with key: 36 bytes, value: 1175 bytes with error: (org.apache.kafka.clients.producer.internals.ErrorLoggingCallback)
java.lang.IllegalStateException: Producer is closed forcefully.
 at org.apache.kafka.clients.producer.internals.RecordAccumulator.abortBatches(RecordAccumulator.java:696)
 at org.apache.kafka.clients.producer.internals.RecordAccumulator.abortIncompleteBatches(RecordAccumulator.java:683)
 at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:185)
{code}

 

{code}
bash-4.2$ cat mirrormaker.properties 
{code}

{code}
# This file is generated by chef
# Any manual changes will be overwritten!
# To make changes, edit the template in the mirrormaker cookbook
#

whitelist=<list of topics>

num.streams=4
{code}

{code}
bash-4.2$ cat producer.properties 
{code}
{code}
# This file is generated by chef
# Any manual changes will be overwritten!
# To make changes, edit the template in the mirrormaker cookbook
#

bootstrap.servers=<list of kafka servers>
request.timeout.ms=60000

-bash-4.2$ 
-bash-4.2$ cat consumer.properties 
# This file is generated by chef
# Any manual changes will be overwritten!
# To make changes, edit the template in the mirrormaker cookbook
#
# mirror cluster's consumer group id
group.id=KafkaMirror-vulcan-sc

auto.offset.reset=earliest

bootstrap.servers=<list of kafka servers>

{code}


was (Author: raghu98499@gmail.com):
Even we are facing the same issue in Kafka 1.1.1 version.

 

{code}

[2018-12-23 15:23:51,800] INFO Closing producer due to send failure. (kafka.tools.MirrorMaker$)

[2018-12-23 15:23:51,800] INFO [Producer clientId=producer-1] Closing the Kafka producer with timeoutMillis = 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
[2018-12-23 15:23:51,800] INFO [Producer clientId=producer-1] Proceeding to force close the producer since pending requests could not be completed within timeout 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
[2018-12-23 15:23:51,800] ERROR Error when sending message to topic vulcan_carrier_tracking_updates_enriched_walmart_prod-az-uswest with key: 36 bytes, value: 978 bytes with error: (org.apache.kafka.clients.producer.internals.ErrorLoggingCallback)
java.lang.IllegalStateException: Producer is closed forcefully.
 at org.apache.kafka.clients.producer.internals.RecordAccumulator.abortBatches(RecordAccumulator.java:696)
 at org.apache.kafka.clients.producer.internals.RecordAccumulator.abortIncompleteBatches(RecordAccumulator.java:683)
 at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:185)
 at java.lang.Thread.run(Thread.java:745)
[2018-12-23 15:23:51,800] INFO Closing producer due to send failure. (kafka.tools.MirrorMaker$)
[2018-12-23 15:23:51,800] INFO [Producer clientId=producer-1] Closing the Kafka producer with timeoutMillis = 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
[2018-12-23 15:23:51,800] INFO [Producer clientId=producer-1] Proceeding to force close the producer since pending requests could not be completed within timeout 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
[2018-12-23 15:23:51,800] ERROR Error when sending message to topic vulcan_carrier_tracking_updates_enriched_walmart_prod-az-uswest with key: 36 bytes, value: 1235 bytes with error: (org.apache.kafka.clients.producer.internals.ErrorLoggingCallback)
java.lang.IllegalStateException: Producer is closed forcefully.
 at org.apache.kafka.clients.producer.internals.RecordAccumulator.abortBatches(RecordAccumulator.java:696)
 at org.apache.kafka.clients.producer.internals.RecordAccumulator.abortIncompleteBatches(RecordAccumulator.java:683)
 at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:185)
 at java.lang.Thread.run(Thread.java:745)
[2018-12-23 15:23:51,800] INFO Closing producer due to send failure. (kafka.tools.MirrorMaker$)
[2018-12-23 15:23:51,800] INFO [Producer clientId=producer-1] Closing the Kafka producer with timeoutMillis = 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
[2018-12-23 15:23:51,800] INFO [Producer clientId=producer-1] Proceeding to force close the producer since pending requests could not be completed within timeout 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
[2018-12-23 15:23:51,800] ERROR Error when sending message to topic vulcan_carrier_tracking_updates_enriched_walmart_prod-az-uswest with key: 36 bytes, value: 1175 bytes with error: (org.apache.kafka.clients.producer.internals.ErrorLoggingCallback)
java.lang.IllegalStateException: Producer is closed forcefully.
 at org.apache.kafka.clients.producer.internals.RecordAccumulator.abortBatches(RecordAccumulator.java:696)
 at org.apache.kafka.clients.producer.internals.RecordAccumulator.abortIncompleteBatches(RecordAccumulator.java:683)
 at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:185)\{code}

 

{code}bash-4.2$ cat mirrormaker.properties \{code}

{code}# This file is generated by chef
# Any manual changes will be overwritten!
# To make changes, edit the template in the mirrormaker cookbook
#

whitelist=<list of topics>

num.streams=4

{code}

{code}bash-4.2$ cat producer.properties \{code}
{code}# This file is generated by chef
# Any manual changes will be overwritten!
# To make changes, edit the template in the mirrormaker cookbook
#

bootstrap.servers=<list of kafka servers>
request.timeout.ms=60000

-bash-4.2$ 
-bash-4.2$ cat consumer.properties 
# This file is generated by chef
# Any manual changes will be overwritten!
# To make changes, edit the template in the mirrormaker cookbook
#
# mirror cluster's consumer group id
group.id=KafkaMirror-vulcan-sc

auto.offset.reset=earliest

bootstrap.servers=<list of kafka servers>

{code}

> Mirrormaker Closing producer due to send failure
> ------------------------------------------------
>
>                 Key: KAFKA-6947
>                 URL: https://issues.apache.org/jira/browse/KAFKA-6947
>             Project: Kafka
>          Issue Type: Bug
>          Components: mirrormaker
>    Affects Versions: 0.11.0.0
>            Reporter: Andrew Holford
>            Priority: Major
>
> Hi
> On occasion our mirrormakers fail with the below error....
> [2018-05-25 05:10:31,695] ERROR Error when sending message to topic com_snapshot--demo with key: 13 bytes, value: 355 bytes with error: (org.apache.kafka.clients.producer.internals.ErrorLoggingCallback)
> org.apache.kafka.common.errors.TimeoutException: Expiring 38 record(s) for com_snapshot--demo-5: 91886 ms has passed since last append
> [2018-05-25 05:10:31,710] INFO Closing producer due to send failure. (kafka.tools.MirrorMaker$)
> [2018-05-25 05:10:31,710] INFO Closing the Kafka producer with timeoutMillis = 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
> [2018-05-25 05:10:31,710] INFO Proceeding to force close the producer since pending requests could not be completed within timeout 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
> and just after this:
> [2018-05-25 05:10:32,041] ERROR Error when sending message to topic com_snapshot--demo with key: 13 bytes, value: 323 bytes with error: (org.apache.kafka.clients.producer.internals.ErrorLoggingCallback)
>  org.apache.kafka.common.errors.TimeoutException: Expiring 15 record(s) for com_snapshot--demo-5: 89429 ms has passed since batch creation plus linger time
>  [2018-05-25 05:10:32,041] INFO Closing producer due to send failure. (kafka.tools.MirrorMaker$)
>  [2018-05-25 05:10:32,041] INFO Closing the Kafka producer with timeoutMillis = 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
>  [2018-05-25 05:10:32,041] INFO Proceeding to force close the producer since pending requests could not be completed within timeout 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
> and sometimes we get:
> [2018-05-25 08:24:29,249] ERROR Error when sending message to topic com_snapshot--demo with key: 13 bytes, value: 354 bytes with error: (org.apache.kafka.clients.producer.internals.ErrorLoggingCallback)
> java.lang.IllegalStateException: Producer is closed forcefully.
>  at org.apache.kafka.clients.producer.internals.RecordAccumulator.abortBatches(RecordAccumulator.java:609)
>  at org.apache.kafka.clients.producer.internals.RecordAccumulator.abortIncompleteBatches(RecordAccumulator.java:596)
>  at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:183)
>  at java.lang.Thread.run(Thread.java:745)
> [2018-05-25 08:24:29,249] INFO Closing producer due to send failure. (kafka.tools.MirrorMaker$)
> [2018-05-25 08:24:29,249] INFO Closing the Kafka producer with timeoutMillis = 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
> [2018-05-25 08:24:29,249] INFO Proceeding to force close the producer since pending requests could not be completed within timeout 0 ms. (org.apache.kafka.clients.producer.KafkaProducer)
>  then it completely shuts down:
> [2018-05-25 05:10:32,060] INFO Exiting on send failure, skip committing offsets. (kafka.tools.MirrorMaker$)
>  [2018-05-25 05:10:32,083] INFO [mirrormaker-thread-0] Flushing producer. (kafka.tools.MirrorMaker$MirrorMakerThread)
>  [2018-05-25 05:10:32,094] INFO [mirrormaker-thread-0] Committing consumer offsets. (kafka.tools.MirrorMaker$MirrorMakerThread)
>  [2018-05-25 05:10:32,094] INFO Exiting on send failure, skip committing offsets. (kafka.tools.MirrorMaker$)
>  [2018-05-25 05:10:32,105] INFO [mirrormaker-thread-0] Shutting down consumer connectors. (kafka.tools.MirrorMaker$MirrorMakerThread)
>  [2018-05-25 05:10:32,138] INFO Publish thread interrupted! (io.confluent.monitoring.clients.interceptor.MonitoringInterceptor)
>  [2018-05-25 05:10:32,144] INFO Publishing Monitoring Metrics stopped for clientID=peach-prod2prod3-mirrormaker-0 (io.confluent.monitoring.clients.interceptor.MonitoringInterceptor)
>  [2018-05-25 05:10:32,148] INFO Closing the Kafka producer with timeoutMillis = 9223372036854775807 ms. (org.apache.kafka.clients.producer.KafkaProducer)
>  [2018-05-25 05:10:32,183] INFO Closed monitoring interceptor for client ID=peach-prod2prod3-mirrormaker-0 (io.confluent.monitoring.clients.interceptor.MonitoringInterceptor)
>  [2018-05-25 05:10:32,197] INFO [mirrormaker-thread-0] Mirror maker thread stopped (kafka.tools.MirrorMaker$MirrorMakerThread)
>  [2018-05-25 05:10:32,202] FATAL [mirrormaker-thread-0] Mirror maker thread exited abnormally, stopping the whole mirror maker. (kafka.tools.MirrorMaker$MirrorMakerThread)
>  [2018-05-25 05:10:32,203] INFO [mirrormaker-thread-0] Mirror maker thread shutdown complete (kafka.tools.MirrorMaker$MirrorMakerThread)
>  [2018-05-25 05:10:32,245] INFO Start clean shutdown. (kafka.tools.MirrorMaker$)
>  [2018-05-25 05:10:32,245] INFO Shutting down consumer threads. (kafka.tools.MirrorMaker$)
>  [2018-05-25 05:10:32,261] INFO [mirrormaker-thread-0] mirrormaker-thread-0 shutting down (kafka.tools.MirrorMaker$MirrorMakerThread)
>  [2018-05-25 05:10:32,265] INFO [mirrormaker-thread-0] Mirror maker thread shutdown complete (kafka.tools.MirrorMaker$MirrorMakerThread)
> On the broker side we see:
> WARN Attempting to send response via channel for which there is no open connection, connection id 10.82.6.105:9093-172.27.205.216:32796 (kafka.network.Processor)
> Does anyone know what could cause this and what a possible solution could be?
> Im a little confused by the "timeoutMillis = 0 ms" as well mentioned, is this some setting which needs adjusting somewhere? We have request.timeout.ms=60000 on the producer config with most other settings left as the defaults. 



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)