Re: Streams constantly reblancing,
That definitely sounds pretty odd if no new logs are showing up on the Streams side. This is just a guess, but is there any chance the source topics aren't being found during startup? I was just reminded of a bug in an old-ish version where Streams would gracefully shutdown but remain in the REBALANCING state when it couldn't detect the source topics. What version are you using? On Thu, Sep 3, 2020 at 8:11 AM Steve Jones wrote: > There are zero events on the stream in the case with the log files, I've > had the same behaviour when running with 6 events. Its constantly > reporting rebalancing but from a CPU perspective nothing appears to > actually be doing anything. > > I've run it for several hours just to see if something happened (checking > every 30 seconds) and there are no log events from Kafka during those > times. So the log file (filter.log) shows the logs for about an hour and a > quarter run, my confusion comes from the fact that looking via JMX and at > the CPU logs it appears that nothing much is actually being done on the > Kafka side but there aren't any exceptions. > > Help and hints appreciated. > > Steve > > On Wed, 2 Sep 2020 at 12:27, Sophie Blee-Goldman > wrote: > > > Hey steve, > > > > I guess the first question I have is, is the consumer group actually > > rebalancing > > or does KafkaStreams just appear to be "stuck" in the REBALANCING state? > If > > this application has been run before and there is a large amount of data > in > > the > > changelog topics, it might take a while to rebuild the local state stores > > from the > > changelog. During this time it would appear to be in REBALANCING, but > it's > > actually > > just restoring. > > > > Just one possibility of many. How long did you let it run without seeing > it > > stabilize? > > It's difficult to diagnose from just the small snippet of logs above, so > I > > would > > try and take a look at the full picture over more than just a minute. > There > > *should* > > be something slightly more helpful logged if it really is stuck in a > cycle > > of endless > > rebalances (eg timing out on the session interval) > > > > On Wed, Sep 2, 2020 at 11:52 AM Steve Jones > > wrote: > > > > > Just an addition to this in case someone can help, I'm seeing zero > thread > > > activity in the rebalancing but I'm also not seeing anything being > logged > > > by Kafka to indicate its doing anything on rebalancing (Logging level > set > > > to ALL), producer and consumer code works fine but streams just appears > > to > > > hang. > > > > > > On Mon, 31 Aug 2020 at 12:49, Steve Jones > > wrote: > > > > > >> When running an application on the Mac it works fine, when running > > >> exactly the same app and config on the Raspberry Pi it constantly says > > it > > >> is "Rebalancing" the streams > > >> > > >> 2020-08-31 12:47:11 INFO > > >> org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka > > version: > > >> 2.6.0 > > >> > > >> ''2020-08-31 12:47:11 INFO > > >> org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka > > commitId: > > >> 62abe01bee039651 > > >> > > >> ''2020-08-31 12:47:11 INFO > > >> org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka > > >> startTimeMs: 1598903231499 > > >> > > >> ''2020-08-31 12:47:11 WARNING org.apache.kafka.streams.StreamsConfig > > >> checkIfUnexpectedUserSpecifiedConsumerConfig Unexpected user-specified > > >> consumer config: enable.auto.commit found. User setting (true) will be > > >> ignored and the Streams default setting (false) will be used > > >> > > >> ''2020-08-31 12:47:11 INFO org.apache.kafka.streams.KafkaStreams > > setState > > >> stream-client [pi-test-84721b40-dfa1-4848-b3de-5c7561048403] State > > >> transition from CREATED to REBALANCING > > >> > > >> ''2020-08-31 12:47:11 INFO > > >> com.businesssoa.home.events.filter.dispatcher.kafka.SensorPipe start > > Pipe > > >> STARTED > > >> > > >> ''2020-08-31 12:47:11 INFO > > >> org.apache.kafka.streams.processor.internals.StreamThread run > > stream-thread > > >> [pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1] Starting > > >> > > >> ''2020-08-31 12:47:11 INFO > > >> org.apache.kafka.streams.processor.internals.StreamThread setState > > >> stream-thread > > [pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1] > > >> State transition from CREATED to STARTING > > >> > > >> ''2020-08-31 12:47:11 INFO > > >> org.apache.kafka.clients.consumer.KafkaConsumer subscribe [Consumer > > >> > > > clientId=pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1-consumer, > > >> groupId=pi-test] Subscribed to topic(s): filtered-topic, reading-topic > > >> > > >> ''2020-08-31 12:47:11 INFO com.businesssoa.home.events.filter.App > > >> waitTillStarted Status is REBALANCING , 1 > > >> > > >> ''2020-08-31 12:47:12 INFO org.apache.kafka.clients.Metadata update > > >> [Producer > > >> > > > clientId=pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1-producer] > > >> Cluster ID: 1AOC2O8zSqq7nuQKACXFxQ > > >
Re: Streams constantly reblancing,
There are zero events on the stream in the case with the log files, I've had the same behaviour when running with 6 events. Its constantly reporting rebalancing but from a CPU perspective nothing appears to actually be doing anything. I've run it for several hours just to see if something happened (checking every 30 seconds) and there are no log events from Kafka during those times. So the log file (filter.log) shows the logs for about an hour and a quarter run, my confusion comes from the fact that looking via JMX and at the CPU logs it appears that nothing much is actually being done on the Kafka side but there aren't any exceptions. Help and hints appreciated. Steve On Wed, 2 Sep 2020 at 12:27, Sophie Blee-Goldman wrote: > Hey steve, > > I guess the first question I have is, is the consumer group actually > rebalancing > or does KafkaStreams just appear to be "stuck" in the REBALANCING state? If > this application has been run before and there is a large amount of data in > the > changelog topics, it might take a while to rebuild the local state stores > from the > changelog. During this time it would appear to be in REBALANCING, but it's > actually > just restoring. > > Just one possibility of many. How long did you let it run without seeing it > stabilize? > It's difficult to diagnose from just the small snippet of logs above, so I > would > try and take a look at the full picture over more than just a minute. There > *should* > be something slightly more helpful logged if it really is stuck in a cycle > of endless > rebalances (eg timing out on the session interval) > > On Wed, Sep 2, 2020 at 11:52 AM Steve Jones > wrote: > > > Just an addition to this in case someone can help, I'm seeing zero thread > > activity in the rebalancing but I'm also not seeing anything being logged > > by Kafka to indicate its doing anything on rebalancing (Logging level set > > to ALL), producer and consumer code works fine but streams just appears > to > > hang. > > > > On Mon, 31 Aug 2020 at 12:49, Steve Jones > wrote: > > > >> When running an application on the Mac it works fine, when running > >> exactly the same app and config on the Raspberry Pi it constantly says > it > >> is "Rebalancing" the streams > >> > >> 2020-08-31 12:47:11 INFO > >> org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka > version: > >> 2.6.0 > >> > >> ''2020-08-31 12:47:11 INFO > >> org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka > commitId: > >> 62abe01bee039651 > >> > >> ''2020-08-31 12:47:11 INFO > >> org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka > >> startTimeMs: 1598903231499 > >> > >> ''2020-08-31 12:47:11 WARNING org.apache.kafka.streams.StreamsConfig > >> checkIfUnexpectedUserSpecifiedConsumerConfig Unexpected user-specified > >> consumer config: enable.auto.commit found. User setting (true) will be > >> ignored and the Streams default setting (false) will be used > >> > >> ''2020-08-31 12:47:11 INFO org.apache.kafka.streams.KafkaStreams > setState > >> stream-client [pi-test-84721b40-dfa1-4848-b3de-5c7561048403] State > >> transition from CREATED to REBALANCING > >> > >> ''2020-08-31 12:47:11 INFO > >> com.businesssoa.home.events.filter.dispatcher.kafka.SensorPipe start > Pipe > >> STARTED > >> > >> ''2020-08-31 12:47:11 INFO > >> org.apache.kafka.streams.processor.internals.StreamThread run > stream-thread > >> [pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1] Starting > >> > >> ''2020-08-31 12:47:11 INFO > >> org.apache.kafka.streams.processor.internals.StreamThread setState > >> stream-thread > [pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1] > >> State transition from CREATED to STARTING > >> > >> ''2020-08-31 12:47:11 INFO > >> org.apache.kafka.clients.consumer.KafkaConsumer subscribe [Consumer > >> > clientId=pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1-consumer, > >> groupId=pi-test] Subscribed to topic(s): filtered-topic, reading-topic > >> > >> ''2020-08-31 12:47:11 INFO com.businesssoa.home.events.filter.App > >> waitTillStarted Status is REBALANCING , 1 > >> > >> ''2020-08-31 12:47:12 INFO org.apache.kafka.clients.Metadata update > >> [Producer > >> > clientId=pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1-producer] > >> Cluster ID: 1AOC2O8zSqq7nuQKACXFxQ > >> > >> ''2020-08-31 12:47:12 INFO org.apache.kafka.clients.Metadata update > >> [Consumer > >> > clientId=pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1-consumer, > >> groupId=pi-test] Cluster ID: 1AOC2O8zSqq7nuQKACXFxQ > >> > >> ''2020-08-31 12:47:41 INFO com.businesssoa.home.events.filter.App > >> waitTillStarted Status is REBALANCING , 2 > >> > >> ''2020-08-31 12:48:11 INFO com.businesssoa.home.events.filter.App > >> waitTillStarted Status is REBALANCING , 3 > >> > >> Any guidance on how I can debug the streams as to why its constantly > >> rebalancing? > >> > >> Steve > >> > >> >
Re: Streams constantly reblancing,
Hey steve, I guess the first question I have is, is the consumer group actually rebalancing or does KafkaStreams just appear to be "stuck" in the REBALANCING state? If this application has been run before and there is a large amount of data in the changelog topics, it might take a while to rebuild the local state stores from the changelog. During this time it would appear to be in REBALANCING, but it's actually just restoring. Just one possibility of many. How long did you let it run without seeing it stabilize? It's difficult to diagnose from just the small snippet of logs above, so I would try and take a look at the full picture over more than just a minute. There *should* be something slightly more helpful logged if it really is stuck in a cycle of endless rebalances (eg timing out on the session interval) On Wed, Sep 2, 2020 at 11:52 AM Steve Jones wrote: > Just an addition to this in case someone can help, I'm seeing zero thread > activity in the rebalancing but I'm also not seeing anything being logged > by Kafka to indicate its doing anything on rebalancing (Logging level set > to ALL), producer and consumer code works fine but streams just appears to > hang. > > On Mon, 31 Aug 2020 at 12:49, Steve Jones wrote: > >> When running an application on the Mac it works fine, when running >> exactly the same app and config on the Raspberry Pi it constantly says it >> is "Rebalancing" the streams >> >> 2020-08-31 12:47:11 INFO >> org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka version: >> 2.6.0 >> >> ''2020-08-31 12:47:11 INFO >> org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka commitId: >> 62abe01bee039651 >> >> ''2020-08-31 12:47:11 INFO >> org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka >> startTimeMs: 1598903231499 >> >> ''2020-08-31 12:47:11 WARNING org.apache.kafka.streams.StreamsConfig >> checkIfUnexpectedUserSpecifiedConsumerConfig Unexpected user-specified >> consumer config: enable.auto.commit found. User setting (true) will be >> ignored and the Streams default setting (false) will be used >> >> ''2020-08-31 12:47:11 INFO org.apache.kafka.streams.KafkaStreams setState >> stream-client [pi-test-84721b40-dfa1-4848-b3de-5c7561048403] State >> transition from CREATED to REBALANCING >> >> ''2020-08-31 12:47:11 INFO >> com.businesssoa.home.events.filter.dispatcher.kafka.SensorPipe start Pipe >> STARTED >> >> ''2020-08-31 12:47:11 INFO >> org.apache.kafka.streams.processor.internals.StreamThread run stream-thread >> [pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1] Starting >> >> ''2020-08-31 12:47:11 INFO >> org.apache.kafka.streams.processor.internals.StreamThread setState >> stream-thread [pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1] >> State transition from CREATED to STARTING >> >> ''2020-08-31 12:47:11 INFO >> org.apache.kafka.clients.consumer.KafkaConsumer subscribe [Consumer >> clientId=pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1-consumer, >> groupId=pi-test] Subscribed to topic(s): filtered-topic, reading-topic >> >> ''2020-08-31 12:47:11 INFO com.businesssoa.home.events.filter.App >> waitTillStarted Status is REBALANCING , 1 >> >> ''2020-08-31 12:47:12 INFO org.apache.kafka.clients.Metadata update >> [Producer >> clientId=pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1-producer] >> Cluster ID: 1AOC2O8zSqq7nuQKACXFxQ >> >> ''2020-08-31 12:47:12 INFO org.apache.kafka.clients.Metadata update >> [Consumer >> clientId=pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1-consumer, >> groupId=pi-test] Cluster ID: 1AOC2O8zSqq7nuQKACXFxQ >> >> ''2020-08-31 12:47:41 INFO com.businesssoa.home.events.filter.App >> waitTillStarted Status is REBALANCING , 2 >> >> ''2020-08-31 12:48:11 INFO com.businesssoa.home.events.filter.App >> waitTillStarted Status is REBALANCING , 3 >> >> Any guidance on how I can debug the streams as to why its constantly >> rebalancing? >> >> Steve >> >>
Re: Streams constantly reblancing,
Just an addition to this in case someone can help, I'm seeing zero thread activity in the rebalancing but I'm also not seeing anything being logged by Kafka to indicate its doing anything on rebalancing (Logging level set to ALL), producer and consumer code works fine but streams just appears to hang. On Mon, 31 Aug 2020 at 12:49, Steve Jones wrote: > When running an application on the Mac it works fine, when running exactly > the same app and config on the Raspberry Pi it constantly says it is > "Rebalancing" the streams > > 2020-08-31 12:47:11 INFO > org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka version: > 2.6.0 > > ''2020-08-31 12:47:11 INFO > org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka commitId: > 62abe01bee039651 > > ''2020-08-31 12:47:11 INFO > org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka > startTimeMs: 1598903231499 > > ''2020-08-31 12:47:11 WARNING org.apache.kafka.streams.StreamsConfig > checkIfUnexpectedUserSpecifiedConsumerConfig Unexpected user-specified > consumer config: enable.auto.commit found. User setting (true) will be > ignored and the Streams default setting (false) will be used > > ''2020-08-31 12:47:11 INFO org.apache.kafka.streams.KafkaStreams setState > stream-client [pi-test-84721b40-dfa1-4848-b3de-5c7561048403] State > transition from CREATED to REBALANCING > > ''2020-08-31 12:47:11 INFO > com.businesssoa.home.events.filter.dispatcher.kafka.SensorPipe start Pipe > STARTED > > ''2020-08-31 12:47:11 INFO > org.apache.kafka.streams.processor.internals.StreamThread run stream-thread > [pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1] Starting > > ''2020-08-31 12:47:11 INFO > org.apache.kafka.streams.processor.internals.StreamThread setState > stream-thread [pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1] > State transition from CREATED to STARTING > > ''2020-08-31 12:47:11 INFO org.apache.kafka.clients.consumer.KafkaConsumer > subscribe [Consumer > clientId=pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1-consumer, > groupId=pi-test] Subscribed to topic(s): filtered-topic, reading-topic > > ''2020-08-31 12:47:11 INFO com.businesssoa.home.events.filter.App > waitTillStarted Status is REBALANCING , 1 > > ''2020-08-31 12:47:12 INFO org.apache.kafka.clients.Metadata update > [Producer > clientId=pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1-producer] > Cluster ID: 1AOC2O8zSqq7nuQKACXFxQ > > ''2020-08-31 12:47:12 INFO org.apache.kafka.clients.Metadata update > [Consumer > clientId=pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1-consumer, > groupId=pi-test] Cluster ID: 1AOC2O8zSqq7nuQKACXFxQ > > ''2020-08-31 12:47:41 INFO com.businesssoa.home.events.filter.App > waitTillStarted Status is REBALANCING , 2 > > ''2020-08-31 12:48:11 INFO com.businesssoa.home.events.filter.App > waitTillStarted Status is REBALANCING , 3 > > Any guidance on how I can debug the streams as to why its constantly > rebalancing? > > Steve > >
Streams constantly reblancing,
When running an application on the Mac it works fine, when running exactly the same app and config on the Raspberry Pi it constantly says it is "Rebalancing" the streams 2020-08-31 12:47:11 INFO org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka version: 2.6.0 ''2020-08-31 12:47:11 INFO org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka commitId: 62abe01bee039651 ''2020-08-31 12:47:11 INFO org.apache.kafka.common.utils.AppInfoParser$AppInfo Kafka startTimeMs: 1598903231499 ''2020-08-31 12:47:11 WARNING org.apache.kafka.streams.StreamsConfig checkIfUnexpectedUserSpecifiedConsumerConfig Unexpected user-specified consumer config: enable.auto.commit found. User setting (true) will be ignored and the Streams default setting (false) will be used ''2020-08-31 12:47:11 INFO org.apache.kafka.streams.KafkaStreams setState stream-client [pi-test-84721b40-dfa1-4848-b3de-5c7561048403] State transition from CREATED to REBALANCING ''2020-08-31 12:47:11 INFO com.businesssoa.home.events.filter.dispatcher.kafka.SensorPipe start Pipe STARTED ''2020-08-31 12:47:11 INFO org.apache.kafka.streams.processor.internals.StreamThread run stream-thread [pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1] Starting ''2020-08-31 12:47:11 INFO org.apache.kafka.streams.processor.internals.StreamThread setState stream-thread [pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1] State transition from CREATED to STARTING ''2020-08-31 12:47:11 INFO org.apache.kafka.clients.consumer.KafkaConsumer subscribe [Consumer clientId=pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1-consumer, groupId=pi-test] Subscribed to topic(s): filtered-topic, reading-topic ''2020-08-31 12:47:11 INFO com.businesssoa.home.events.filter.App waitTillStarted Status is REBALANCING , 1 ''2020-08-31 12:47:12 INFO org.apache.kafka.clients.Metadata update [Producer clientId=pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1-producer] Cluster ID: 1AOC2O8zSqq7nuQKACXFxQ ''2020-08-31 12:47:12 INFO org.apache.kafka.clients.Metadata update [Consumer clientId=pi-test-84721b40-dfa1-4848-b3de-5c7561048403-StreamThread-1-consumer, groupId=pi-test] Cluster ID: 1AOC2O8zSqq7nuQKACXFxQ ''2020-08-31 12:47:41 INFO com.businesssoa.home.events.filter.App waitTillStarted Status is REBALANCING , 2 ''2020-08-31 12:48:11 INFO com.businesssoa.home.events.filter.App waitTillStarted Status is REBALANCING , 3 Any guidance on how I can debug the streams as to why its constantly rebalancing? Steve