You are viewing a plain text version of this content. The canonical link for it is here.
Posted to jira@kafka.apache.org by "Bruno Cadonna (Jira)" <ji...@apache.org> on 2021/07/01 18:02:00 UTC
[jira] [Comment Edited] (KAFKA-13010) Flaky test
org.apache.kafka.streams.integration.TaskMetadataIntegrationTest.shouldReportCorrectCommittedOffsetInformation()
[ https://issues.apache.org/jira/browse/KAFKA-13010?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17372977#comment-17372977 ]
Bruno Cadonna edited comment on KAFKA-13010 at 7/1/21, 6:01 PM:
----------------------------------------------------------------
Some logs that might be interesting:
{code}
[2021-06-29 12:19:40,200] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2-consumer] Finished unstable assignment of tasks, a followup rebalance will be scheduled. (org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:818)
[2021-06-29 12:19:40,200] WARN [Consumer clientId=TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2-consumer, groupId=TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation] The following subscribed topics are not assigned to any members: [inputTaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation] (org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:611)
[2021-06-29 12:19:40,200] INFO [GroupCoordinator 0]: Assignment received from leader TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2-consumer-0a548162-9e3f-4003-98c5-54ece6f5e1b8 for group TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation for generation 2. The group has 2 members, 0 of which are static. (kafka.coordinator.group.GroupCoordinator:66)
[2021-06-29 12:19:40,201] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-1-consumer] Requested to schedule immediate rebalance for new tasks to be safely revoked from current owner. (org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:1300)
[2021-06-29 12:19:40,201] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] State transition from RUNNING to PARTITIONS_REVOKED (org.apache.kafka.streams.processor.internals.StreamThread:229)
[2021-06-29 12:19:40,201] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-1] Handle new assignment with:
New active tasks: []
New standby tasks: []
Existing active tasks: []
Existing standby tasks: [] (org.apache.kafka.streams.processor.internals.TaskManager:263)
[2021-06-29 12:19:40,201] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-1] State transition from STARTING to PARTITIONS_ASSIGNED (org.apache.kafka.streams.processor.internals.StreamThread:229)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] task [0_0] Suspended RUNNING (org.apache.kafka.streams.processor.internals.StreamTask:1187)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] task [0_0] Suspended running (org.apache.kafka.streams.processor.internals.StreamTask:300)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] partition revocation took 1 ms. (org.apache.kafka.streams.processor.internals.StreamThread:97)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2-consumer] No followup rebalance was requested, resetting the rebalance schedule. (org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:1306)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] Handle new assignment with:
New active tasks: []
New standby tasks: []
Existing active tasks: [0_0]
Existing standby tasks: [] (org.apache.kafka.streams.processor.internals.TaskManager:263)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] task [0_0] Closing record collector clean (org.apache.kafka.streams.processor.internals.RecordCollectorImpl:268)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] task [0_0] Closed clean (org.apache.kafka.streams.processor.internals.StreamTask:524)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] State transition from PARTITIONS_REVOKED to PARTITIONS_ASSIGNED (org.apache.kafka.streams.processor.internals.StreamThread:229)
[2021-06-29 12:19:40,203] INFO [GroupCoordinator 0]: Preparing to rebalance group TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation in state PreparingRebalance with old generation 2 (__consumer_offsets-4) (reason: Leader TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2-consumer-0a548162-9e3f-4003-98c5-54ece6f5e1b8 re-joining group during Stable) (kafka.coordinator.group.GroupCoordinator:66)
[2021-06-29 12:19:40,274] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-1] Restoration took 73 ms for all tasks [] (org.apache.kafka.streams.processor.internals.StreamThread:851)
[2021-06-29 12:19:40,274] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-1] State transition from PARTITIONS_ASSIGNED to RUNNING (org.apache.kafka.streams.processor.internals.StreamThread:229)
[2021-06-29 12:19:40,274] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] Restoration took 72 ms for all tasks [] (org.apache.kafka.streams.processor.internals.StreamThread:851)
[2021-06-29 12:19:40,274] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] State transition from PARTITIONS_ASSIGNED to RUNNING (org.apache.kafka.streams.processor.internals.StreamThread:229)
[2021-06-29 12:19:40,274] INFO stream-client [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5] State transition from REBALANCING to RUNNING (org.apache.kafka.streams.KafkaStreams:315)
[2021-06-29 12:19:40,274] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-1] Triggering the followup rebalance scheduled for 0 ms. (org.apache.kafka.streams.processor.internals.StreamThread:585)
[2021-06-29 12:19:40,274] INFO stream-client [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5] State transition from RUNNING to PENDING_SHUTDOWN (org.apache.kafka.streams.KafkaStreams:315)
[2021-06-29 12:19:40,275] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-1] Informed to shut down (org.apache.kafka.streams.processor.internals.StreamThread:1063)
[2021-06-29 12:19:40,275] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorr
{code}
Especially this log message seems suspicious:
{code}
[2021-06-29 12:19:40,200] WARN [Consumer clientId=TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2-consumer, groupId=TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation] The following subscribed topics are not assigned to any members: [inputTaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation] (org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:611)
{code}
was (Author: cadonna):
Some logs that might be interesting:
{code}
[2021-06-29 12:19:40,200] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2-consumer] Finished unstable assignment of tasks, a followup rebalance will be scheduled. (org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:818)
[2021-06-29 12:19:40,200] WARN [Consumer clientId=TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2-consumer, groupId=TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation] The following subscribed topics are not assigned to any members: [inputTaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation] (org.apache.kafka.clients.consumer.internals.ConsumerCoordinator:611)
[2021-06-29 12:19:40,200] INFO [GroupCoordinator 0]: Assignment received from leader TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2-consumer-0a548162-9e3f-4003-98c5-54ece6f5e1b8 for group TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation for generation 2. The group has 2 members, 0 of which are static. (kafka.coordinator.group.GroupCoordinator:66)
[2021-06-29 12:19:40,201] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-1-consumer] Requested to schedule immediate rebalance for new tasks to be safely revoked from current owner. (org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:1300)
[2021-06-29 12:19:40,201] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] State transition from RUNNING to PARTITIONS_REVOKED (org.apache.kafka.streams.processor.internals.StreamThread:229)
[2021-06-29 12:19:40,201] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-1] Handle new assignment with:
New active tasks: []
New standby tasks: []
Existing active tasks: []
Existing standby tasks: [] (org.apache.kafka.streams.processor.internals.TaskManager:263)
[2021-06-29 12:19:40,201] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-1] State transition from STARTING to PARTITIONS_ASSIGNED (org.apache.kafka.streams.processor.internals.StreamThread:229)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] task [0_0] Suspended RUNNING (org.apache.kafka.streams.processor.internals.StreamTask:1187)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] task [0_0] Suspended running (org.apache.kafka.streams.processor.internals.StreamTask:300)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] partition revocation took 1 ms. (org.apache.kafka.streams.processor.internals.StreamThread:97)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2-consumer] No followup rebalance was requested, resetting the rebalance schedule. (org.apache.kafka.streams.processor.internals.StreamsPartitionAssignor:1306)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] Handle new assignment with:
New active tasks: []
New standby tasks: []
Existing active tasks: [0_0]
Existing standby tasks: [] (org.apache.kafka.streams.processor.internals.TaskManager:263)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] task [0_0] Closing record collector clean (org.apache.kafka.streams.processor.internals.RecordCollectorImpl:268)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] task [0_0] Closed clean (org.apache.kafka.streams.processor.internals.StreamTask:524)
[2021-06-29 12:19:40,202] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] State transition from PARTITIONS_REVOKED to PARTITIONS_ASSIGNED (org.apache.kafka.streams.processor.internals.StreamThread:229)
[2021-06-29 12:19:40,203] INFO [GroupCoordinator 0]: Preparing to rebalance group TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation in state PreparingRebalance with old generation 2 (__consumer_offsets-4) (reason: Leader TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2-consumer-0a548162-9e3f-4003-98c5-54ece6f5e1b8 re-joining group during Stable) (kafka.coordinator.group.GroupCoordinator:66)
[2021-06-29 12:19:40,274] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-1] Restoration took 73 ms for all tasks [] (org.apache.kafka.streams.processor.internals.StreamThread:851)
[2021-06-29 12:19:40,274] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-1] State transition from PARTITIONS_ASSIGNED to RUNNING (org.apache.kafka.streams.processor.internals.StreamThread:229)
[2021-06-29 12:19:40,274] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] Restoration took 72 ms for all tasks [] (org.apache.kafka.streams.processor.internals.StreamThread:851)
[2021-06-29 12:19:40,274] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-2] State transition from PARTITIONS_ASSIGNED to RUNNING (org.apache.kafka.streams.processor.internals.StreamThread:229)
[2021-06-29 12:19:40,274] INFO stream-client [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5] State transition from REBALANCING to RUNNING (org.apache.kafka.streams.KafkaStreams:315)
[2021-06-29 12:19:40,274] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-1] Triggering the followup rebalance scheduled for 0 ms. (org.apache.kafka.streams.processor.internals.StreamThread:585)
[2021-06-29 12:19:40,274] INFO stream-client [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5] State transition from RUNNING to PENDING_SHUTDOWN (org.apache.kafka.streams.KafkaStreams:315)
[2021-06-29 12:19:40,275] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorrectCommittedOffsetInformation-6889e6c9-c4fa-427c-83bf-469b33a34bb5-StreamThread-1] Informed to shut down (org.apache.kafka.streams.processor.internals.StreamThread:1063)
[2021-06-29 12:19:40,275] INFO stream-thread [TaskMetadataTest_TaskMetadataIntegrationTestshouldReportCorr
{code}
> Flaky test org.apache.kafka.streams.integration.TaskMetadataIntegrationTest.shouldReportCorrectCommittedOffsetInformation()
> ---------------------------------------------------------------------------------------------------------------------------
>
> Key: KAFKA-13010
> URL: https://issues.apache.org/jira/browse/KAFKA-13010
> Project: Kafka
> Issue Type: Bug
> Components: streams
> Reporter: Bruno Cadonna
> Priority: Major
> Labels: flaky-test
>
> Integration test {{test org.apache.kafka.streams.integration.TaskMetadataIntegrationTest.shouldReportCorrectCommittedOffsetInformation()}} sometimes fails with
> {code:java}
> java.lang.AssertionError: only one task
> at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:26)
> at org.apache.kafka.streams.integration.TaskMetadataIntegrationTest.getTaskMetadata(TaskMetadataIntegrationTest.java:162)
> at org.apache.kafka.streams.integration.TaskMetadataIntegrationTest.shouldReportCorrectCommittedOffsetInformation(TaskMetadataIntegrationTest.java:117)
> {code}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)