UnderReplicatedPartitions in Strimzi kafka

[venudevops1458]

HI Folks,

We are seeing UnderReplicatedPartitions notifications very frequently in Strimzi kafka

Below are the logs:

2022-08-24 12:56:32,863 DEBUG [Controller id=1] Topics not in preferred replica for broker 0 Map() (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 TRACE [Controller id=1] Leader imbalance ratio for broker 0 is 0.0 (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 DEBUG [Controller id=1] Topics not in preferred replica for broker 5 Map() (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 TRACE [Controller id=1] Leader imbalance ratio for broker 5 is 0.0 (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 DEBUG [Controller id=1] Topics not in preferred replica for broker 1 Map() (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 TRACE [Controller id=1] Leader imbalance ratio for broker 1 is 0.0 (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 DEBUG [Controller id=1] Topics not in preferred replica for broker 6 Map() (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 TRACE [Controller id=1] Leader imbalance ratio for broker 6 is 0.0 (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 DEBUG [Controller id=1] Topics not in preferred replica for broker 2 Map() (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 TRACE [Controller id=1] Leader imbalance ratio for broker 2 is 0.0 (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 DEBUG [Controller id=1] Topics not in preferred replica for broker 7 Map() (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 TRACE [Controller id=1] Leader imbalance ratio for broker 7 is 0.0 (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 DEBUG [Controller id=1] Topics not in preferred replica for broker 3 Map() (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 TRACE [Controller id=1] Leader imbalance ratio for broker 3 is 0.0 (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 DEBUG [Controller id=1] Topics not in preferred replica for broker 4 Map() (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:56:32,863 TRACE [Controller id=1] Leader imbalance ratio for broker 4 is 0.0 (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:57:52,169 INFO [GroupMetadataManager brokerId=1] Removed 0 expired offsets in 0 milliseconds. (kafka.coordinator.group.GroupMetadataManager) [group-metadata-manager-0]
2022-08-24 12:59:37,686 INFO Unable to read additional data from server sessionid 0x100661e15210001, likely server has closed socket, closing socket connection and attempting reconnect (org.apache.zookeeper.ClientCnxn) [zk-session-expiry-handler0-SendThread(localhost:2181)]
2022-08-24 12:59:39,291 INFO Opening socket connection to server localhost/127.0.0.1:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn) [zk-session-expiry-handler0-SendThread(localhost:2181)]
2022-08-24 12:59:39,292 INFO Socket connection established, initiating session, client: /127.0.0.1:58060, server: localhost/127.0.0.1:2181 (org.apache.zookeeper.ClientCnxn) [zk-session-expiry-handler0-SendThread(localhost:2181)]
2022-08-24 12:59:39,331 INFO Session establishment complete on server localhost/127.0.0.1:2181, sessionid = 0x100661e15210001, negotiated timeout = 6000 (org.apache.zookeeper.ClientCnxn) [zk-session-expiry-handler0-SendThread(localhost:2181)]
2022-08-24 12:59:40,174 INFO [Controller id=1] Newly added brokers: , deleted brokers: 5,6, bounced brokers: , all live brokers: 0,1,2,3,4,7 (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:59:40,175 INFO [RequestSendThread controllerId=1] Shutting down (kafka.controller.RequestSendThread) [controller-event-thread]
2022-08-24 12:59:40,176 INFO [RequestSendThread controllerId=1] Stopped (kafka.controller.RequestSendThread) [Controller-1-to-broker-5-send-thread]
2022-08-24 12:59:40,176 INFO [RequestSendThread controllerId=1] Shutdown completed (kafka.controller.RequestSendThread) [controller-event-thread]
2022-08-24 12:59:40,185 INFO [RequestSendThread controllerId=1] Shutting down (kafka.controller.RequestSendThread) [controller-event-thread]
2022-08-24 12:59:40,185 INFO [RequestSendThread controllerId=1] Stopped (kafka.controller.RequestSendThread) [Controller-1-to-broker-6-send-thread]
2022-08-24 12:59:40,185 INFO [RequestSendThread controllerId=1] Shutdown completed (kafka.controller.RequestSendThread) [controller-event-thread]
2022-08-24 12:59:40,191 INFO [Controller id=1] Broker failure callback for 5,6 (kafka.controller.KafkaController) [controller-event-thread]
2022-08-24 12:59:40,194 TRACE [Controller id=1 epoch=99] Changed partition trm-storeonce-custdata-current.blue-1 state from OnlinePartition to OfflinePartition (state.change.logger) [controller-event-thread]
2022-08-24 12:59:40,194 TRACE [Controller id=1 epoch=99] Changed partition trm-ss-sr-hires-data-5 state from OnlinePartition to OfflinePartition (state.change.logger) [controller-event-thread]
2022-08-24 12:59:40,194 TRACE [Controller id=1 epoch=99] Changed partition trm-storeonce-processed-storeonce-notification-support.blue-3 state from OnlinePartition to OfflinePartition (state.change.logger) [controller-event-thread]
2022-08-24 12:59:40,194 TRACE [Controller id=1 epoch=99] Changed partition trm-storeonce-service-instance-performance.blue-0 state from OnlinePartition to OfflinePartition (state.change.logger) [controller-event-thread]
2022-08-24 12:59:40,194 TRACE [Controller id=1 epoch=99] Changed partition trm-ss-system-alerts.blue-1 state from OnlinePartition to OfflinePartition

If it happens once in a while, it's acceptable, but it's repeating for every 1hr

Please help us here, thanks in advance for your help.

[scholzj]

Not sure this code snippet is enough to properly understand it. Is it just complaining about some broker connections? Or what does it do?

[venudevops1458]

Please have a look at below logs

one of Zookeeper:

2022-08-24 13:00:02,682 INFO Processing ruok command from /127.0.0.1:41478 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-2]
2022-08-24 13:00:10,518 INFO Processing ruok command from /127.0.0.1:41522 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-3]
2022-08-24 13:00:12,657 INFO Processing ruok command from /127.0.0.1:41536 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-4]
2022-08-24 13:00:18,569 WARN Exception when following the leader (org.apache.zookeeper.server.quorum.Learner) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
at sun.security.ssl.InputRecord.read(InputRecord.java:503)
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:990)
at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:948)
at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
at java.io.DataInputStream.readInt(DataInputStream.java:387)
at org.apache.jute.BinaryInputArchive.readInt(BinaryInputArchive.java:84)
at org.apache.zookeeper.server.quorum.QuorumPacket.deserialize(QuorumPacket.java:85)
at org.apache.jute.BinaryInputArchive.readRecord(BinaryInputArchive.java:118)
at org.apache.zookeeper.server.quorum.Learner.readPacket(Learner.java:158)
at org.apache.zookeeper.server.quorum.Follower.followLeader(Follower.java:92)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1253)
2022-08-24 13:00:18,570 INFO shutdown called (org.apache.zookeeper.server.quorum.Learner) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
java.lang.Exception: shutdown Follower
at org.apache.zookeeper.server.quorum.Follower.shutdown(Follower.java:201)
at org.apache.zookeeper.server.quorum.QuorumPeer.run(QuorumPeer.java:1257)
2022-08-24 13:00:18,571 INFO Shutting down (org.apache.zookeeper.server.ZooKeeperServer) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2022-08-24 13:00:18,571 INFO shutting down (org.apache.zookeeper.server.ZooKeeperServer) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2022-08-24 13:00:18,571 INFO Shutting down (org.apache.zookeeper.server.quorum.FollowerRequestProcessor) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2022-08-24 13:00:18,571 INFO Shutting down (org.apache.zookeeper.server.quorum.CommitProcessor) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2022-08-24 13:00:18,571 INFO FollowerRequestProcessor exited loop! (org.apache.zookeeper.server.quorum.FollowerRequestProcessor) [FollowerRequestProcessor:1]
2022-08-24 13:00:18,572 INFO CommitProcessor exited loop! (org.apache.zookeeper.server.quorum.CommitProcessor) [CommitProcessor:1]
2022-08-24 13:00:18,572 INFO shutdown of request processor complete (org.apache.zookeeper.server.FinalRequestProcessor) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2022-08-24 13:00:18,680 INFO Shutting down (org.apache.zookeeper.server.SyncRequestProcessor) [QuorumPeermyid=1(secure=0.0.0.0:2181)]
2022-08-24 13:00:18,680 INFO SyncRequestProcessor exited! (org.apache.zookeeper.server.SyncRequestProcessor) [SyncThread:1]
2022-08-24 13:00:18,858 INFO Authenticated Id 'CN=demo-appsite-kafka,O=io.strimzi' for Scheme 'x509' (org.apache.zookeeper.server.auth.X509AuthenticationProvider) [nioEventLoopGroup-7-6]
2022-08-24 13:00:18,859 WARN Closing connection to /10.233.91.13:34410 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-7-6]
java.io.IOException: ZK down
at org.apache.zookeeper.server.NettyServerCnxn.receiveMessage(NettyServerCnxn.java:474)
at org.apache.zookeeper.server.NettyServerCnxn.processMessage(NettyServerCnxn.java:360)
at org.apache.zookeeper.server.NettyServerCnxnFactory$CnxnChannelHandler.channelRead(NettyServerCnxnFactory.java:266)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355)
at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1470)
at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1219)
at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1266)
at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:498)
at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:437)
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:355)
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:377)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:363)
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714)
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650)
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:748)
2022-08-24 13:00:20,513 INFO Processing ruok command from /127.0.0.1:41592 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-4-5]
2022-08-24 13:00:20,513 INFO Authenticated Id 'CN=demo-appsite-entity-operator,O=io.strimzi' for Scheme 'x509' (org.apache.zookeeper.server.auth.X509AuthenticationProvider) [nioEventLoopGroup-7-7]
2022-08-24 13:00:20,514 WARN Closing connection to /10.233.93.12:49356 (org.apache.zookeeper.server.NettyServerCnxn) [nioEventLoopGroup-7-7]
java.io.IOException: ZK down

Strimzi Pod logs:

2022-08-24 12:59:49 INFO AbstractOperator:173 - Reconciliation #3633(timer) Kafka(kafka/demo-appsite): Kafka demo-appsite should be created or updated
2022-08-24 12:59:52 INFO AbstractOperator:318 - Reconciliation #3633(timer) Kafka(kafka/demo-appsite): reconciled
2022-08-24 13:00:59 WARN WatchConnectionManager:209 - Exec Failure
java.net.SocketException: Connection reset
at java.net.SocketInputStream.read(SocketInputStream.java:210) ~[?:1.8.0_252]
at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[?:1.8.0_252]
at sun.security.ssl.InputRecord.readFully(InputRecord.java:465) ~[?:1.8.0_252]
at sun.security.ssl.InputRecord.read(InputRecord.java:503) ~[?:1.8.0_252]
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:990) ~[?:1.8.0_252]
at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:948) ~[?:1.8.0_252]
at sun.security.ssl.AppInputStream.read(AppInputStream.java:105) ~[?:1.8.0_252]
at okio.Okio$2.read(Okio.java:140) ~[com.squareup.okio.okio-1.15.0.jar:?]
at okio.AsyncTimeout$2.read(AsyncTimeout.java:237) ~[com.squareup.okio.okio-1.15.0.jar:?]
at okio.RealBufferedSource.request(RealBufferedSource.java:68) ~[com.squareup.okio.okio-1.15.0.jar:?]
at okio.RealBufferedSource.require(RealBufferedSource.java:61) ~[com.squareup.okio.okio-1.15.0.jar:?]
at okio.RealBufferedSource.readByte(RealBufferedSource.java:74) ~[com.squareup.okio.okio-1.15.0.jar:?]
at okhttp3.internal.ws.WebSocketReader.readHeader(WebSocketReader.java:117) ~[com.squareup.okhttp3.okhttp-3.12.6.jar:?]
at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101) ~[com.squareup.okhttp3.okhttp-3.12.6.jar:?]
at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:274) [com.squareup.okhttp3.okhttp-3.12.6.jar:?]
at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:214) [com.squareup.okhttp3.okhttp-3.12.6.jar:?]
at okhttp3.RealCall$AsyncCall.execute(RealCall.java:203) [com.squareup.okhttp3.okhttp-3.12.6.jar:?]
at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32) [com.squareup.okhttp3.okhttp-3.12.6.jar:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_252]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
2022-08-24 13:00:59 WARN WatchConnectionManager:209 - Exec Failure
java.net.SocketException: Connection reset
at java.net.SocketInputStream.read(SocketInputStream.java:210) ~[?:1.8.0_252]
at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[?:1.8.0_252]
at sun.security.ssl.InputRecord.readFully(InputRecord.java:465) ~[?:1.8.0_252]
at sun.security.ssl.InputRecord.read(InputRecord.java:503) ~[?:1.8.0_252]
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:990) ~[?:1.8.0_252]
at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:948) ~[?:1.8.0_252]
at sun.security.ssl.AppInputStream.read(AppInputStream.java:105) ~[?:1.8.0_252]
at okio.Okio$2.read(Okio.java:140) ~[com.squareup.okio.okio-1.15.0.jar:?]
at okio.AsyncTimeout$2.read(AsyncTimeout.java:237) ~[com.squareup.okio.okio-1.15.0.jar:?]
at okio.RealBufferedSource.request(RealBufferedSource.java:68) ~[com.squareup.okio.okio-1.15.0.jar:?]
at okio.RealBufferedSource.require(RealBufferedSource.java:61) ~[com.squareup.okio.okio-1.15.0.jar:?]
at okio.RealBufferedSource.readByte(RealBufferedSource.java:74) ~[com.squareup.okio.okio-1.15.0.jar:?]
at okhttp3.internal.ws.WebSocketReader.readHeader(WebSocketReader.java:117) ~[com.squareup.okhttp3.okhttp-3.12.6.jar:?]
at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:101) ~[com.squareup.okhttp3.okhttp-3.12.6.jar:?]
at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:274) [com.squareup.okhttp3.okhttp-3.12.6.jar:?]
at okhttp3.internal.ws.RealWebSocket$2.onResponse(RealWebSocket.java:214) [com.squareup.okhttp3.okhttp-3.12.6.jar:?]
at okhttp3.RealCall$AsyncCall.execute(RealCall.java:203) [com.squareup.okhttp3.okhttp-3.12.6.jar:?]
at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32) [com.squareup.okhttp3.okhttp-3.12.6.jar:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_252]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_252]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_252]
2022-08-24 13:01:04 WARN WatchConnectionManager:209 - Exec Failure
java.net.SocketException: Connection reset

Kafka Pod additional logs:

2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-trserv-dag-json.blue-3 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-storeonce-storage-product-json.blue-3 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-trserv-system-best-daily.blue-2 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-storeonce-custdata-daily.blue-3 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-inventory-updates-json.blue-2 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [Log partition=tr-storeonce-config-current.blue-2, dir=/var/lib/kafka/data/kafka-log5] Truncating to 0 has no effect as the largest offset in the log is -1 (kafka.log.Log) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition trs-trserv-sr-hires-data-3 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-storevirtual-largedata-topic-json-1 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition __consumer_offsets-37 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-tenant-json.blue-1 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition __consumer_offsets-2 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:55,848 INFO [GroupCoordinator 5]: Member trserv-lagom-7-297c5063-c87d-44e1-9b8b-68074ac60f89 in group tr_trserv_lagom_service_saturn_blue_20200526_blue has failed, removing it from the group (kafka.coordinator.group.GroupCoordinator) [executor-Heartbeat]
2022-08-24 13:00:55,849 INFO [GroupCoordinator 5]: Preparing to rebalance group tr_trserv_lagom_service_saturn_blue_20200526_blue in tre PreparingRebalance with old generation 111254 (__consumer_offsets-45) (reason: removing member trserv-lagom-7-297c5063-c87d-44e1-9b8b-68074ac60f89 on heartbeat expiration) (kafka.coordinator.group.GroupCoordinator) [executor-Heartbeat]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-trserv-dag-json.blue-3 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-storeonce-storage-product-json.blue-3 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-trserv-system-best-daily.blue-2 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-storeonce-custdata-daily.blue-3 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-inventory-updates-json.blue-2 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [Log partition=tr-storeonce-config-current.blue-2, dir=/var/lib/kafka/data/kafka-log5] Truncating to 0 has no effect as the largest offset in the log is -1 (kafka.log.Log) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition trs-trserv-sr-hires-data-3 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-storevirtual-largedata-topic-json-1 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition __consumer_offsets-37 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-tenant-json.blue-1 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:54,869 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition __consumer_offsets-2 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:55,848 INFO [GroupCoordinator 5]: Member trserv-lagom-7-297c5063-c87d-44e1-9b8b-68074ac60f89 in group tr_trserv_lagom_service_saturn_blue_20200526_blue has failed, removing it from the group (kafka.coordinator.group.GroupCoordinator) [executor-Heartbeat]
2022-08-24 13:00:55,849 INFO [GroupCoordinator 5]: Preparing to rebalance group tr_trserv_lagom_service_saturn_blue_20200526_blue in tre PreparingRebalance with old generation 111254 (__consumer_offsets-45) (reason: removing member trserv-lagom-7-297c5063-c87d-44e1-9b8b-68074ac60f89 on heartbeat expiration) (kafka.coordinator.group.GroupCoordinator) [executor-Heartbeat]
2022-08-24 13:00:56,143 INFO [ReplicaFetcher replicaId=5, leaderId=7, fetcherId=0] Retrying leaderEpoch request for partition __consumer_offsets-31 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-7]
2022-08-24 13:00:56,143 INFO [ReplicaFetcher replicaId=5, leaderId=7, fetcherId=0] Retrying leaderEpoch request for partition trs-data-feed-topic-3 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-7]
2022-08-24 13:00:56,143 INFO [Log partition=trs-full-feed-pro-trserv-3, dir=/var/lib/kafka/data/kafka-log5] Truncating to 0 has no effect as the largest offset in the log is -1 (kafka.log.Log) [ReplicaFetcherThread-0-7]
2022-08-24 13:00:56,143 INFO [Log partition=tr-trserv-system-best-monthly-archive.blue-2, dir=/var/lib/kafka/data/kafka-log5] Truncating to 14704 has no effect as the largest offset in the log is 14703 (kafka.log.Log) [ReplicaFetcherThread-0-7]
2022-08-24 13:00:56,143 INFO [ReplicaFetcher replicaId=5, leaderId=7, fetcherId=0] Retrying leaderEpoch request for partition tr-trserv-sdp-3par-min.blue-1 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-7]
2022-08-24 13:00:56,143 INFO [ReplicaFetcher replicaId=5, leaderId=7, fetcherId=0] Retrying leaderEpoch request for partition tr-trserv-sdp-cpgs.blue-0 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-7]
2022-08-24 13:00:56,191 INFO [GroupCoordinator 5]: Preparing to rebalance group tr_trserv_lagom_service_saturn_blue_20200526_blue in tre PreparingRebalance with old generation 111255 (__consumer_offsets-45) (reason: Adding new member trserv-lagom-14-9989c9db-be1c-4970-a73e-5f12256457c1 with group instanceid None) (kafka.coordinator.group.GroupCoordinator) [data-plane-kafka-request-handler-4]
2022-08-24 13:00:57,177 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-tenant-json.blue-1 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:57,177 INFO [Log partition=__consumer_offsets-2, dir=/var/lib/kafka/data/kafka-log5] Truncating to 2694625 has no effect as the largest offset in the log is 2694624 (kafka.log.Log) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:57,644 INFO [Partition __consumer_offsets-45 broker=5] Shrinking ISR from 4,5,6 to 5,6. Leader: (highWatermark: 27612375, endOffset: 27612376). Out of sync replicas: (brokerId: 4, endOffset: -1). (kafka.cluster.Partition) [kafka-scheduler-6]
2022-08-24 13:00:57,683 INFO [Partition __consumer_offsets-45 broker=5] ISR updated to [5,6] and zkVersion updated to [666] (kafka.cluster.Partition) [kafka-scheduler-6]
2022-08-24 13:00:57,684 INFO [Partition tr-storeonce-config-monthly-snapshot.blue-1 broker=5] Shrinking ISR from 4,6,5 to 6,5. Leader: (highWatermark: 0, endOffset: 0). Out of sync replicas: (brokerId: 4, endOffset: -1). (kafka.cluster.Partition) [kafka-scheduler-6]
2022-08-24 13:00:57,703 INFO [Partition tr-storeonce-config-monthly-snapshot.blue-1 broker=5] ISR updated to [6,5] and zkVersion updated to [540] (kafka.cluster.Partition) [kafka-scheduler-6]
2022-08-24 13:00:57,703 INFO [Partition tr-storeonce-public-api-json.blue-4 broker=5] Shrinking ISR from 4,6,5 to 6,5. Leader: (highWatermark: 0, endOffset: 0). Out of sync replicas: (brokerId: 4, endOffset: -1). (kafka.cluster.Partition) [kafka-scheduler-6]
2022-08-24 13:00:57,735 INFO [Partition tr-storeonce-public-api-json.blue-4 broker=5] ISR updated to [6,5] and zkVersion updated to [538] (kafka.cluster.Partition) [kafka-scheduler-6]
2022-08-24 13:00:57,736 INFO [Partition trs-file-feed-storeonce-config-1 broker=5] Shrinking ISR from 4,6,5 to 6,5. Leader: (highWatermark: 0, endOffset: 0). Out of sync replicas: (brokerId: 4, endOffset: -1). (kafka.cluster.Partition) [kafka-scheduler-6]
2022-08-24 13:00:57,750 INFO [Partition trs-file-feed-storeonce-config-1 broker=5] ISR updated to [6,5] and zkVersion updated to [538] (kafka.cluster.Partition) [kafka-scheduler-6]
2022-08-24 13:00:57,751 INFO [Partition tr-trserv-trs-casenotification-json.blue-3 broker=5] Shrinking ISR from 4,6,5 to 6,5. Leader: (highWatermark: 0, endOffset: 0). Out of sync replicas: (brokerId: 4, endOffset: -1). (kafka.cluster.Partition) [kafka-scheduler-6]
2022-08-24 13:00:57,769 INFO [Partition tr-trserv-trs-casenotification-json.blue-3 broker=5] ISR updated to [6,5] and zkVersion updated to [642] (kafka.cluster.Partition) [kafka-scheduler-6]
2022-08-24 13:00:58,257 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-entitlement-offer-metadata-json-0 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:58,258 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-storevirtual-largedata-topic-json-1 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:58,258 INFO [Log partition=__consumer_offsets-37, dir=/var/lib/kafka/data/kafka-log5] Truncating to 6196938 has no effect as the largest offset in the log is 6196937 (kafka.log.Log) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:58,258 INFO [Log partition=tr-tenant-json.blue-1, dir=/var/lib/kafka/data/kafka-log5] Truncating to 228623 has no effect as the largest offset in the log is 228622 (kafka.log.Log) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:58,323 INFO [Log partition=__consumer_offsets-31, dir=/var/lib/kafka/data/kafka-log5] Truncating to 3821526 has no effect as the largest offset in the log is 3821525 (kafka.log.Log) [ReplicaFetcherThread-0-7]
2022-08-24 13:00:58,323 INFO [Log partition=tr-trserv-sdp-3par-min.blue-1, dir=/var/lib/kafka/data/kafka-log5] Truncating to 21966851 has no effect as the largest offset in the log is 21966850 (kafka.log.Log) [ReplicaFetcherThread-0-7]
2022-08-24 13:00:58,323 INFO [Log partition=tr-trserv-sdp-cpgs.blue-0, dir=/var/lib/kafka/data/kafka-log5] Truncating to 21464493 has no effect as the largest offset in the log is 21464492 (kafka.log.Log) [ReplicaFetcherThread-0-7]
2022-08-24 13:00:59,193 INFO [GroupCoordinator 5]: Stabilized group tr_trserv_lagom_service_saturn_blue_20200526_blue generation 111256 (__consumer_offsets-45) (kafka.coordinator.group.GroupCoordinator) [executor-Rebalance]
2022-08-24 13:00:59,195 INFO [GroupCoordinator 5]: Assignment received from leader for group tr_trserv_lagom_service_saturn_blue_20200526_blue for generation 111256 (kafka.coordinator.group.GroupCoordinator) [data-plane-kafka-request-handler-2]
2022-08-24 13:00:59,647 INFO [Log partition=trs-trserv-firehose-data-1, dir=/var/lib/kafka/data/kafka-log5] Truncating to 1503733 has no effect as the largest offset in the log is 1503732 (kafka.log.Log) [ReplicaFetcherThread-0-4]
2022-08-24 13:00:59,647 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition tr-entitlement-offer-metadata-json-0 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:01:00,708 INFO [ReplicaFetcher replicaId=5, leaderId=4, fetcherId=0] Retrying leaderEpoch request for partition trs-full-feed-pro-trserv-1 as the leader reported an error: UNKNOWN_LEADER_EPOCH (kafka.server.ReplicaFetcherThread) [ReplicaFetcherThread-0-4]
2022-08-24 13:01:00,708 INFO [Log partition=tr-trserv-crashtxt-analysis-data.blue-2, dir=/var/lib/kafka/data/kafka-log5] Truncating to 0 has no effect as the largest offset in the log is -1 (kafka.log.Log) [ReplicaFetcherThread-0-4]
2022-08-24 13:01:00,708 INFO [Log partition=tr-storeonce-config-monthly.blue-1, dir=/var/lib/kafka/data/kafka-log5] Truncating to 307071 has no effect as the largest offset in the log is 307070 (kafka.log.Log) [ReplicaFetcherThread-0-4]
2022-08-24 13:01:00,708 INFO [Log partition=tr-storeonce-storage-product-json.blue-3, dir=/var/lib/kafka/data/kafka-log5] Truncating to 435368 has no effect as the largest offset in the log is 435367 (kafka.log.Log) [ReplicaFetcherThread-0-4]
2022-08-24 13:01:00,709 INFO [Log partition=tr-storeonce-custdata-daily.blue-3, dir=/var/lib/kafka/data/kafka-log5] Truncating to 0 has no effect as the largest offset in the log is -1 (kafka.log.Log) [ReplicaFetcherThread-0-4]
2022-08-24 13:01:00,709 INFO [Log partition=tr-storevirtual-largedata-topic-json-1, dir=/var/lib/kafka/data/kafka-log5] Truncating to 0 has no effect as the largest offset in the log is -1 (kafka.log.Log) [ReplicaFetcherThread-0-4]
2022-08-24 13:01:00,709 INFO [Log partition=tr-trserv-storage-product-current.blue-0, dir=/var/lib/kafka/data/kafka-log5] Truncating to 21476273 has no effect as the largest offset in the log is 21476272 (kafka.log.Log) [ReplicaFetcherThread-0-4]
2022-08-24 13:01:00,709 INFO [Log partition=tr-storeonce-metadata.blue-3, dir=/var/lib/kafka/data/kafka-log5] Truncating to 374993 has no effect as the largest offset in the log is 374992 (kafka.log.Log) [ReplicaFetcherThread-0-4]
2022-08-24 13:01:01,162 INFO [GroupCoordinator 5]: Preparing to rebalance group tr_trserv_lagom_service_saturn_blue_20200526_blue in tre PreparingRebalance with old generation 111256 (__consumer_offsets-45) (reason: Adding new member trserv-lagom-14-12acdc2b-6b7d-406d-bd6d-6162628b0ced with group instanceid None) (kafka.coordinator.group.GroupCoordinator) [data-plane-kafka-request-handler-7]
2022-08-24 13:01:01,540 INFO [Partition tr-storeonce-config-monthly-snapshot.blue-1 broker=5] Expanding ISR from 6,5 to 6,5,4 (kafka.cluster.Partition) [data-plane-kafka-request-handler-2]
2022-08-24 13:01:01,547 INFO [Partition tr-storeonce-config-monthly-snapshot.blue-1 broker=5] ISR updated to [6,5,4] and zkVersion updated to [541] (kafka.cluster.Partition) [data-plane-kafka-request-handler-2]
2022-08-24 13:01:01,547 INFO [Partition tr-trserv-trs-casenotification-json.blue-3 broker=5] Expanding ISR from 6,5 to 6,5,4 (kafka.cluster.Partition) [data-plane-kafka-request-handler-2]
2022-08-24 13:01:01,567 INFO [Partition tr-trserv-trs-casenotification-json.blue-3 broker=5] ISR updated to [6,5,4] and zkVersion updated to [643] (kafka.cluster.Partition) [data-plane-kafka-request-handler-2]
2022-08-24 13:01:01,567 INFO [Partition tr-storeonce-public-api-json.blue-4 broker=5] Expanding ISR from 6,5 to 6,5,4 (kafka.cluster.Partition) [data-plane-kafka-request-handler-2]
2022-08-24 13:01:01,574 INFO [Partition tr-storeonce-public-api-json.blue-4 broker=5] ISR updated to [6,5,4] and zkVersion updated to [539] (kafka.cluster.Partition) [data-plane-kafka-request-handler-2]
2022-08-24 13:01:01,574 INFO [Partition trs-file-feed-storeonce-config-1 broker=5] Expanding ISR from 6,5 to 6,5,4 (kafka.cluster.Partition) [data-plane-kafka-request-handler-2]
2022-08-24 13:01:01,587 INFO [Partition trs-file-feed-storeonce-config-1 broker=5] ISR updated to [6,5,4] and zkVersion updated to [539] (kafka.cluster.Partition) [data-plane-kafka-request-handler-2]
2022-08-24 13:01:01,625 INFO [Partition __consumer_offsets-45 broker=5] Expanding ISR from 5,6 to 5,6,4 (kafka.cluster.Partition) [data-plane-kafka-request-handler-4]
2022-08-24 13:01:01,646 INFO [Partition __consumer_offsets-45 broker=5] ISR updated to [5,6,4] and zkVersion updated to [667] (kafka.cluster.Partition) [data-plane-kafka-request-handler-4]