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

[jira] [Commented] (KAFKA-6842) initTransactions hangs when trying to connect to non-existing broker

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

huxihx commented on KAFKA-6842:
-------------------------------

Seems it's a duplicate of [KAFKA-6446|https://issues.apache.org/jira/browse/KAFKA-6446]?

> initTransactions hangs when trying to connect to non-existing broker
> --------------------------------------------------------------------
>
>                 Key: KAFKA-6842
>                 URL: https://issues.apache.org/jira/browse/KAFKA-6842
>             Project: Kafka
>          Issue Type: Bug
>          Components: producer 
>    Affects Versions: 1.1.0
>            Reporter: Alexander Gavrilov
>            Priority: Major
>
>  
> When I specify a non-existing broker as a bootstrap server, 'initTransactions' hangs forever. Here is a simple code to reproduce an issue:
> {code:java}
> Map<String, Object> props = new HashMap<>();
> props.put(ProducerConfig.BOOTSTRAP_SERVERS_CONFIG, "example.com:49092");
> props.put(ProducerConfig.ACKS_CONFIG, "all");
> props.put(ProducerConfig.BATCH_SIZE_CONFIG, 16384);
> props.put(ProducerConfig.LINGER_MS_CONFIG, 1);
> props.put(ProducerConfig.BUFFER_MEMORY_CONFIG, 33554432);
> props.put(ProducerConfig.MAX_BLOCK_MS_CONFIG, 3000);
> props.put(ProducerConfig.REQUEST_TIMEOUT_MS_CONFIG, 3000);
> props.put(ProducerConfig.TRANSACTIONAL_ID_CONFIG, "test_transactional_id");
> Producer<String, byte[]> producer = new KafkaProducer<>(props, new StringSerializer(), new ByteArraySerializer());
> producer.initTransactions();
> {code}
> The trace log file:
> {noformat}
> 979  [main] INFO  org.apache.kafka.common.utils.AppInfoParser  - Kafka version : 1.1.0
> 979  [main] INFO  org.apache.kafka.common.utils.AppInfoParser  - Kafka commitId : fdcf75ea326b8e07
> 981  [main] DEBUG org.apache.kafka.clients.producer.KafkaProducer  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Kafka producer started
> 982  [main] DEBUG org.apache.kafka.clients.producer.internals.TransactionManager  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Transition from state UNINITIALIZED to INITIALIZING
> 982  [main] INFO  org.apache.kafka.clients.producer.internals.TransactionManager  - [Producer clientId=producer-1, transactionalId=test_transactional_id] ProducerId set to -1 with epoch -1
> 1147 [main] DEBUG org.apache.kafka.clients.producer.internals.TransactionManager  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Enqueuing transactional request (type=InitProducerIdRequest, transactionalId=test_transactional_id, transactionTimeoutMs=60000)
> 1147 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.producer.internals.TransactionManager  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Request (type=InitProducerIdRequest, transactionalId=test_transactional_id, transactionTimeoutMs=60000) dequeued for sending
> 1148 [kafka-producer-network-thread | producer-1] DEBUG org.apache.kafka.clients.producer.internals.TransactionManager  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Enqueuing transactional request (type=FindCoordinatorRequest, coordinatorKey=test_transactional_id, coordinatorType=TRANSACTION)
> 1148 [kafka-producer-network-thread | producer-1] DEBUG org.apache.kafka.clients.producer.internals.TransactionManager  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Enqueuing transactional request (type=InitProducerIdRequest, transactionalId=test_transactional_id, transactionTimeoutMs=60000)
> 1149 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.producer.internals.TransactionManager  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Request (type=FindCoordinatorRequest, coordinatorKey=test_transactional_id, coordinatorType=TRANSACTION) dequeued for sending
> 1149 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Found least loaded node example.com:49092 (id: -1 rack: null)
> 1150 [kafka-producer-network-thread | producer-1] DEBUG org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Initiating connection to node example.com:49092 (id: -1 rack: null)
> 4250 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Found least loaded node example.com:49092 (id: -1 rack: null)
> 4250 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Found least loaded node example.com:49092 (id: -1 rack: null)
> 4250 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Found least loaded node example.com:49092 (id: -1 rack: null)
> 4300 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Found least loaded node example.com:49092 (id: -1 rack: null)
> 4351 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Found least loaded node example.com:49092 (id: -1 rack: null)
> 4401 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Found least loaded node example.com:49092 (id: -1 rack: null)
> .... many similar message about 'Found least loaded node'
> 22087 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Found least loaded node example.com:49092 (id: -1 rack: null)
> 22138 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Found least loaded node example.com:49092 (id: -1 rack: null)
> 22154 [kafka-producer-network-thread | producer-1] DEBUG org.apache.kafka.common.metrics.Metrics  - Added sensor with name node--1.bytes-sent
> 22155 [kafka-producer-network-thread | producer-1] DEBUG org.apache.kafka.common.metrics.Metrics  - Added sensor with name node--1.bytes-received
> 22156 [kafka-producer-network-thread | producer-1] DEBUG org.apache.kafka.common.metrics.Metrics  - Added sensor with name node--1.latency
> 22158 [kafka-producer-network-thread | producer-1] DEBUG org.apache.kafka.common.network.Selector  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Connection with example.com/93.184.216.34 disconnected
> java.net.ConnectException: Connection timed out: no further information
>     at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
>     at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717)
>     at org.apache.kafka.common.network.PlaintextTransportLayer.finishConnect(PlaintextTransportLayer.java:50)
>     at org.apache.kafka.common.network.KafkaChannel.finishConnect(KafkaChannel.java:106)
>     at org.apache.kafka.common.network.Selector.pollSelectionKeys(Selector.java:470)
>     at org.apache.kafka.common.network.Selector.poll(Selector.java:424)
>     at org.apache.kafka.clients.NetworkClient.poll(NetworkClient.java:460)
>     at org.apache.kafka.clients.NetworkClientUtils.awaitReady(NetworkClientUtils.java:73)
>     at org.apache.kafka.clients.producer.internals.Sender.awaitLeastLoadedNodeReady(Sender.java:415)
>     at org.apache.kafka.clients.producer.internals.Sender.maybeSendTransactionalRequest(Sender.java:347)
>     at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:214)
>     at org.apache.kafka.clients.producer.internals.Sender.run(Sender.java:163)
>     at java.lang.Thread.run(Thread.java:748)
> 22162 [kafka-producer-network-thread | producer-1] DEBUG org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Node -1 disconnected.
> 22164 [kafka-producer-network-thread | producer-1] WARN  org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Connection to node -1 could not be established. Broker may not be available.
> 22165 [kafka-producer-network-thread | producer-1] DEBUG org.apache.kafka.clients.producer.internals.Sender  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Disconnect from null while trying to send request (type=FindCoordinatorRequest, coordinatorKey=test_transactional_id, coordinatorType=TRANSACTION). Going to back off and retry
> 22268 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Found least loaded node example.com:49092 (id: -1 rack: null)
> 22269 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Found least loaded node example.com:49092 (id: -1 rack: null)
> 22269 [kafka-producer-network-thread | producer-1] DEBUG org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Initialize connection to node example.com:49092 (id: -1 rack: null) for sending metadata request
> 22269 [kafka-producer-network-thread | producer-1] DEBUG org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Initiating connection to node example.com:49092 (id: -1 rack: null)
> 22270 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Found least loaded node example.com:49092 (id: -1 rack: null)
> 22320 [kafka-producer-network-thread | producer-1] TRACE org.apache.kafka.clients.NetworkClient  - [Producer clientId=producer-1, transactionalId=test_transactional_id] Found least loaded node example.com:49092 (id: -1 rack: null)
> {noformat}
>  After this message the cycle repeats again. I'd expect TimeoutException after the specified 'max.block.ms' time.
>  



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