[
https://issues.apache.org/jira/browse/KAFKA-7657?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16710573#comment-16710573
]
Patrik Kleindl commented on KAFKA-7657:
---------------------------------------
[~guozhang]
I have tried to grab the relevant part of the log and remove all client
references, not much to be seen.
{code:java}
2018-11-30 08:50:06,885 INFO
[org.apache.kafka.clients.consumer.internals.AbstractCoordinator]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ... [Consumer
clientId=client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16-consumer,
groupId=client-appname] Group coordinator broker:9092 (id: 2147483644 rack:
null) is unavailable or invalid, will attempt rediscovery
2018-11-30 08:50:06,986 INFO
[org.apache.kafka.clients.consumer.internals.AbstractCoordinator]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ... [Consumer
clientId=client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16-consumer,
groupId=client-appname] Discovered group coordinator broker:9092 (id:
2147483644 rack: null)
2018-11-30 08:50:06,986 INFO
[org.apache.kafka.clients.consumer.internals.AbstractCoordinator]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ... [Consumer
clientId=client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16-consumer,
groupId=client-appname] Group coordinator broker:9092 (id: 2147483644 rack:
null) is unavailable or invalid, will attempt rediscovery
2018-11-30 08:50:07,087 INFO
[org.apache.kafka.clients.consumer.internals.AbstractCoordinator]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ... [Consumer
clientId=client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16-consumer,
groupId=client-appname] Discovered group coordinator broker:9092 (id:
2147483644 rack: null)
2018-11-30 09:08:45,717 INFO
[org.apache.kafka.clients.consumer.internals.AbstractCoordinator]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ... [Consumer
clientId=client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16-consumer,
groupId=client-appname] Attempt to heartbeat failed since group is rebalancing
2018-11-30 09:08:45,749 INFO
[org.apache.kafka.clients.consumer.internals.ConsumerCoordinator]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ... [Consumer
clientId=client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16-consumer,
groupId=client-appname] Revoking previously assigned partitions [...]
2018-11-30 09:08:45,750 INFO
[org.apache.kafka.streams.processor.internals.StreamThread]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ...
stream-thread [client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16]
State transition from RUNNING to PARTITIONS_REVOKED
2018-11-30 09:08:45,750 INFO [org.apache.kafka.streams.KafkaStreams]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ...
stream-client [client-610151c7-8769-4cc5-9254-969a831e4a4d] State transition
from RUNNING to REBALANCING
2018-11-30 09:08:45,865 INFO
[org.apache.kafka.streams.processor.internals.StreamThread]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ...
stream-thread [client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16]
partition revocation took 115 ms.
2018-11-30 09:08:45,865 INFO
[org.apache.kafka.clients.consumer.internals.AbstractCoordinator]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ... [Consumer
clientId=client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16-consumer,
groupId=client-appname] (Re-)joining group
2018-11-30 09:08:47,544 INFO
[org.apache.kafka.clients.consumer.internals.AbstractCoordinator]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ... [Consumer
clientId=client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16-consumer,
groupId=client-appname] Successfully joined group with generation 3374
2018-11-30 09:08:47,547 INFO
[org.apache.kafka.clients.consumer.internals.ConsumerCoordinator]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ... [Consumer
clientId=client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16-consumer,
groupId=client-appname] Setting newly assigned partitions [...]
2018-11-30 09:08:47,547 INFO
[org.apache.kafka.streams.processor.internals.StreamThread]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ...
stream-thread [client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16]
State transition from PARTITIONS_REVOKED to PARTITIONS_ASSIGNED
2018-11-30 09:08:47,574 INFO
[org.apache.kafka.streams.processor.internals.StreamThread]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ...
stream-thread [client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16]
partition assignment took 27 ms.
2018-11-30 09:08:47,874 INFO
[org.apache.kafka.streams.processor.internals.StreamThread]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ...
stream-thread [client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16]
State transition from PARTITIONS_ASSIGNED to RUNNING
{code}
After this line the state of the streams application was stuck at rebalancing
for this node:
{code:java}
2018-11-30 09:08:45,750 INFO [org.apache.kafka.streams.KafkaStreams]
(client-610151c7-8769-4cc5-9254-969a831e4a4d-StreamThread-16) - ...
stream-client [client-610151c7-8769-4cc5-9254-969a831e4a4d] State transition
from RUNNING to REBALANCING{code}
> Invalid reporting of stream state in Kafka streams application
> --------------------------------------------------------------
>
> Key: KAFKA-7657
> URL: https://issues.apache.org/jira/browse/KAFKA-7657
> Project: Kafka
> Issue Type: Bug
> Components: streams
> Affects Versions: 2.0.1
> Reporter: Thomas Crowley
> Priority: Major
> Labels: bug
>
> We have a streams application with 3 instances running, two of which are
> reporting the state of REBALANCING even after they have been running for
> days. Restarting the application has no effect on the stream state.
> This seems suspect because each instance appears to be processing messages,
> and the kafka-consumer-groups CLI tool reports hardly any offset lag in any
> of the partitions assigned to the REBALANCING consumers. Each partition seems
> to be processing an equal amount of records too.
> Inspecting the state.dir on disk, it looks like the RocksDB state has been
> built and hovers at the expected size on disk.
> This problem has persisted for us after we rebuilt our Kafka cluster and
> reset topics + consumer groups in our dev environment.
> There is nothing in the logs (with level set to DEBUG) in both the broker or
> the application that suggests something exceptional has happened causing the
> application to be stuck REBALANCING.
> We are also running multiple streaming applications where this problem does
> not exist.
> Two differences between this application and our other streaming applications
> are:
> * We have processing.guarantee set to exactly_once
> * We are using a ValueTransformer which fetches from and puts data on a
> windowed state store
> The REBALANCING state is returned from both polling the state method of our
> KafkaStreams instance, and our custom metric which is derived from some logic
> in a KafkaStreams.StateListener class attached via the setStateListener
> method.
>
> While I have provided a bit of context, before I reply with some reproducible
> code - is there a simple way in which I can determine that my streams
> application is in a RUNNING state without relying on the same mechanisms as
> used above?
> Further, given that it seems like my application is actually running - could
> this perhaps be a bug to do with how the stream state is being reported (in
> the context of a transactional stream using the processor API)?
>
>
>
>
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
