[
https://issues.apache.org/jira/browse/KAFKA-7921?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16767548#comment-16767548
]
ASF GitHub Bot commented on KAFKA-7921:
---------------------------------------
guozhangwang commented on pull request #6262: KAFKA-7921: log at error level
for missing source topic
URL: https://github.com/apache/kafka/pull/6262
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
us...@infra.apache.org
> Instable KafkaStreamsTest
> -------------------------
>
> Key: KAFKA-7921
> URL: https://issues.apache.org/jira/browse/KAFKA-7921
> Project: Kafka
> Issue Type: Bug
> Components: streams, unit tests
> Reporter: Matthias J. Sax
> Assignee: John Roesler
> Priority: Major
>
> {{KafkaStreamsTest}} failed multiple times, eg,
> {quote}java.lang.AssertionError: Condition not met within timeout 15000.
> Streams never started.
> at org.apache.kafka.test.TestUtils.waitForCondition(TestUtils.java:365)
> at org.apache.kafka.test.TestUtils.waitForCondition(TestUtils.java:325)
> at
> org.apache.kafka.streams.KafkaStreamsTest.shouldThrowOnCleanupWhileRunning(KafkaStreamsTest.java:556){quote}
> or
> {quote}java.lang.AssertionError: Condition not met within timeout 15000.
> Streams never started.
> at org.apache.kafka.test.TestUtils.waitForCondition(TestUtils.java:365)
> at org.apache.kafka.test.TestUtils.waitForCondition(TestUtils.java:325)
> at
> org.apache.kafka.streams.KafkaStreamsTest.testStateThreadClose(KafkaStreamsTest.java:255){quote}
>
> The preserved logs are as follows:
> {quote}[2019-02-12 07:02:17,198] INFO Kafka version: 2.3.0-SNAPSHOT
> (org.apache.kafka.common.utils.AppInfoParser:109)
> [2019-02-12 07:02:17,198] INFO Kafka commitId: 08036fa4b1e5b822
> (org.apache.kafka.common.utils.AppInfoParser:110)
> [2019-02-12 07:02:17,199] INFO stream-client [clientId] State transition from
> CREATED to REBALANCING (org.apache.kafka.streams.KafkaStreams:263)
> [2019-02-12 07:02:17,200] INFO stream-thread [clientId-StreamThread-238]
> Starting (org.apache.kafka.streams.processor.internals.StreamThread:767)
> [2019-02-12 07:02:17,200] INFO stream-client [clientId] State transition from
> REBALANCING to PENDING_SHUTDOWN (org.apache.kafka.streams.KafkaStreams:263)
> [2019-02-12 07:02:17,200] INFO stream-thread [clientId-StreamThread-239]
> Starting (org.apache.kafka.streams.processor.internals.StreamThread:767)
> [2019-02-12 07:02:17,200] INFO stream-thread [clientId-StreamThread-238]
> State transition from CREATED to STARTING
> (org.apache.kafka.streams.processor.internals.StreamThread:214)
> [2019-02-12 07:02:17,200] INFO stream-thread [clientId-StreamThread-239]
> State transition from CREATED to STARTING
> (org.apache.kafka.streams.processor.internals.StreamThread:214)
> [2019-02-12 07:02:17,200] INFO stream-thread [clientId-StreamThread-238]
> Informed to shut down
> (org.apache.kafka.streams.processor.internals.StreamThread:1192)
> [2019-02-12 07:02:17,201] INFO stream-thread [clientId-StreamThread-238]
> State transition from STARTING to PENDING_SHUTDOWN
> (org.apache.kafka.streams.processor.internals.StreamThread:214)
> [2019-02-12 07:02:17,201] INFO stream-thread [clientId-StreamThread-239]
> Informed to shut down
> (org.apache.kafka.streams.processor.internals.StreamThread:1192)
> [2019-02-12 07:02:17,201] INFO stream-thread [clientId-StreamThread-239]
> State transition from STARTING to PENDING_SHUTDOWN
> (org.apache.kafka.streams.processor.internals.StreamThread:214)
> [2019-02-12 07:02:17,205] INFO Cluster ID: J8uJhiTKQx-Y_i9LzT0iLg
> (org.apache.kafka.clients.Metadata:365)
> [2019-02-12 07:02:17,205] INFO Cluster ID: J8uJhiTKQx-Y_i9LzT0iLg
> (org.apache.kafka.clients.Metadata:365)
> [2019-02-12 07:02:17,205] INFO [Consumer
> clientId=clientId-StreamThread-238-consumer, groupId=appId] Discovered group
> coordinator localhost:36122 (id: 2147483647 rack: null)
> (org.apache.kafka.clients.consumer.internals.AbstractCoordinator:675)
> [2019-02-12 07:02:17,205] INFO [Consumer
> clientId=clientId-StreamThread-239-consumer, groupId=appId] Discovered group
> coordinator localhost:36122 (id: 2147483647 rack: null)
> (org.apache.kafka.clients.consumer.internals.AbstractCoordinator:675)
> [2019-02-12 07:02:17,206] INFO [Consumer
> clientId=clientId-StreamThread-238-consumer, groupId=appId] Revoking
> previously assigned partitions []
> (org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:458)
> [2019-02-12 07:02:17,206] INFO [Consumer
> clientId=clientId-StreamThread-239-consumer, groupId=appId] Revoking
> previously assigned partitions []
> (org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:458)
> [2019-02-12 07:02:17,206] INFO [Consumer
> clientId=clientId-StreamThread-238-consumer, groupId=appId] (Re-)joining
> group (org.apache.kafka.clients.consumer.internals.AbstractCoordinator:491)
> [2019-02-12 07:02:17,206] INFO [Consumer
> clientId=clientId-StreamThread-239-consumer, groupId=appId] (Re-)joining
> group (org.apache.kafka.clients.consumer.internals.AbstractCoordinator:491)
> [2019-02-12 07:02:17,208] INFO [Consumer
> clientId=clientId-StreamThread-239-consumer, groupId=appId] (Re-)joining
> group (org.apache.kafka.clients.consumer.internals.AbstractCoordinator:491)
> [2019-02-12 07:02:17,208] INFO [Consumer
> clientId=clientId-StreamThread-238-consumer, groupId=appId] (Re-)joining
> group (org.apache.kafka.clients.consumer.internals.AbstractCoordinator:491)
> [2019-02-12 07:02:17,278] INFO Cluster ID: J8uJhiTKQx-Y_i9LzT0iLg
> (org.apache.kafka.clients.Metadata:365)
> [2019-02-12 07:02:17,293] INFO Cluster ID: J8uJhiTKQx-Y_i9LzT0iLg
> (org.apache.kafka.clients.Metadata:365)
> [2019-02-12 07:02:17,301] INFO stream-thread [clientId-StreamThread-239]
> Shutting down (org.apache.kafka.streams.processor.internals.StreamThread:1206)
> [2019-02-12 07:02:17,301] INFO [Consumer
> clientId=clientId-StreamThread-239-restore-consumer, groupId=null]
> Unsubscribed all topics or patterns and assigned partitions
> (org.apache.kafka.clients.consumer.KafkaConsumer:1042)
> [2019-02-12 07:02:17,301] INFO stream-thread [clientId-StreamThread-238]
> Shutting down (org.apache.kafka.streams.processor.internals.StreamThread:1206)
> [2019-02-12 07:02:17,301] INFO [Consumer
> clientId=clientId-StreamThread-238-restore-consumer, groupId=null]
> Unsubscribed all topics or patterns and assigned partitions
> (org.apache.kafka.clients.consumer.KafkaConsumer:1042)
> [2019-02-12 07:02:17,302] INFO [Producer
> clientId=clientId-StreamThread-238-producer] Closing the Kafka producer with
> timeoutMillis = 9223372036854775807 ms.
> (org.apache.kafka.clients.producer.KafkaProducer:1139)
> [2019-02-12 07:02:17,301] INFO [Producer
> clientId=clientId-StreamThread-239-producer] Closing the Kafka producer with
> timeoutMillis = 9223372036854775807 ms.
> (org.apache.kafka.clients.producer.KafkaProducer:1139)
> [2019-02-12 07:02:17,863] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:18,766] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:19,769] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:20,872] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:21,775] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:22,678] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:23,882] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:24,885] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:25,888] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:26,991] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:28,095] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:28,998] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:29,901] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:31,004] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:32,108] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:33,311] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:34,515] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:35,718] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:36,921] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:37,924] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:38,927] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:40,029] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:41,232] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:42,235] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:43,337] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:44,340] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:45,442] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:46,444] WARN [AdminClient clientId=adminclient-233]
> Connection to node 0 (localhost/127.0.0.1:41539) could not be established.
> Broker may not be available. (org.apache.kafka.clients.NetworkClient:722)
> [2019-02-12 07:02:47,305] WARN [Consumer
> clientId=clientId-StreamThread-239-consumer, groupId=appId] Close timed out
> with 1 pending requests to coordinator, terminating client connections
> (org.apache.kafka.clients.consumer.internals.AbstractCoordinator:800)
> [2019-02-12 07:02:47,307] INFO stream-thread [clientId-StreamThread-239]
> State transition from PENDING_SHUTDOWN to DEAD
> (org.apache.kafka.streams.processor.internals.StreamThread:214)
> [2019-02-12 07:02:47,307] INFO stream-thread [clientId-StreamThread-239]
> Shutdown complete
> (org.apache.kafka.streams.processor.internals.StreamThread:1226)
> [2019-02-12 07:02:47,308] WARN [Consumer
> clientId=clientId-StreamThread-238-consumer, groupId=appId] Close timed out
> with 1 pending requests to coordinator, terminating client connections
> (org.apache.kafka.clients.consumer.internals.AbstractCoordinator:800)
> [2019-02-12 07:02:47,313] INFO stream-thread [clientId-StreamThread-238]
> State transition from PENDING_SHUTDOWN to DEAD
> (org.apache.kafka.streams.processor.internals.StreamThread:214)
> [2019-02-12 07:02:47,313] INFO stream-thread [clientId-StreamThread-238]
> Shutdown complete
> (org.apache.kafka.streams.processor.internals.StreamThread:1226)
> [2019-02-12 07:02:47,315] INFO stream-client [clientId] State transition from
> PENDING_SHUTDOWN to NOT_RUNNING (org.apache.kafka.streams.KafkaStreams:263)
> [2019-02-12 07:02:47,315] INFO stream-client [clientId] Streams client
> stopped completely (org.apache.kafka.streams.KafkaStreams:899)
> [2019-02-12 07:02:47,316] INFO stream-client [clientId] Already in the
> pending shutdown state, wait to complete shutdown
> (org.apache.kafka.streams.KafkaStreams:849)
> [2019-02-12 07:02:47,316] INFO stream-client [clientId] Streams client
> stopped completely (org.apache.kafka.streams.KafkaStreams:899){quote}
>
> Note, that the instance goes from
> {quote}[2019-02-12 07:02:17,199] INFO stream-client [clientId] State
> transition from CREATED to REBALANCING
> (org.apache.kafka.streams.KafkaStreams:263){quote}
> to
> {quote}[2019-02-12 07:02:17,200] INFO stream-client [clientId] State
> transition from REBALANCING to PENDING_SHUTDOWN
> (org.apache.kafka.streams.KafkaStreams:263){quote}
> in the very beginning. It's unclear why this happens. Note, that the log
> before the copied snipped is unfortunately not complete (thank you Jenkins):
> {quote}...[truncated 1593438 chars]...{quote}
> Later, `AdminClient` seems to not be able to connect to the brokers (also
> unclear why) and the test times out. If the `AdminClient` issue is related to
> the first issue is unclear atm).
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
