Code Monkey home page Code Monkey logo

Comments (9)

rafariossaa avatar rafariossaa commented on May 25, 2024

Hi,
I deployed a chart using your command and I was not able to reproduce the issue.
I got not error in the deployment and then I could create a client and a producer and send/read messages.
I used the following to create the producer/consumer clients:

To connect a client to your Kafka, you need to create the 'client.properties' configuration files with the content below:

security.protocol=SASL_PLAINTEXT
sasl.mechanism=SCRAM-SHA-256
sasl.jaas.config=org.apache.kafka.common.security.scram.ScramLoginModule required \
    username="user1" \
    password="$(kubectl get secret kafka-user-passwords --namespace default -o jsonpath='{.data.client-passwords}' | base64 -d | cut -d , -f 1)";

To create a pod that you can use as a Kafka client run the following commands:

    kubectl run kafka-client --restart='Never' --image docker.io/bitnami/kafka:3.7.0-debian-12-r2 --namespace default --command -- sleep infinity
    kubectl cp --namespace default /path/to/client.properties kafka-client:/tmp/client.properties
    kubectl exec --tty -i kafka-client --namespace default -- bash

    PRODUCER:
        kafka-console-producer.sh \
            --producer.config /tmp/client.properties \
            --broker-list kafka-controller-0.kafka-controller-headless.default.svc.cluster.local:9092,kafka-controller-1.kafka-controller-headless.default.svc.cluster.local:9092,kafka-controller-2.kafka-controller-headless.default.svc.cluster.local:9092 \
            --topic test

    CONSUMER:
        kafka-console-consumer.sh \
            --consumer.config /tmp/client.properties \
            --bootstrap-server kafka.default.svc.cluster.local:9092 \
            --topic test \
            --from-beginning

from charts.

zjf88865 avatar zjf88865 commented on May 25, 2024

Hi, I deployed a chart using your command and I was not able to reproduce the issue. I got not error in the deployment and then I could create a client and a producer and send/read messages. I used the following to create the producer/consumer clients:

To connect a client to your Kafka, you need to create the 'client.properties' configuration files with the content below:

security.protocol=SASL_PLAINTEXT
sasl.mechanism=SCRAM-SHA-256
sasl.jaas.config=org.apache.kafka.common.security.scram.ScramLoginModule required \
    username="user1" \
    password="$(kubectl get secret kafka-user-passwords --namespace default -o jsonpath='{.data.client-passwords}' | base64 -d | cut -d , -f 1)";

To create a pod that you can use as a Kafka client run the following commands:

    kubectl run kafka-client --restart='Never' --image docker.io/bitnami/kafka:3.7.0-debian-12-r2 --namespace default --command -- sleep infinity
    kubectl cp --namespace default /path/to/client.properties kafka-client:/tmp/client.properties
    kubectl exec --tty -i kafka-client --namespace default -- bash

    PRODUCER:
        kafka-console-producer.sh \
            --producer.config /tmp/client.properties \
            --broker-list kafka-controller-0.kafka-controller-headless.default.svc.cluster.local:9092,kafka-controller-1.kafka-controller-headless.default.svc.cluster.local:9092,kafka-controller-2.kafka-controller-headless.default.svc.cluster.local:9092 \
            --topic test

    CONSUMER:
        kafka-console-consumer.sh \
            --consumer.config /tmp/client.properties \
            --bootstrap-server kafka.default.svc.cluster.local:9092 \
            --topic test \
            --from-beginning

You need to upgrade helm repo to the latest version. Both my two servers and my home computer can reproduce the above problem. You can use the command: helm repo update, or delete bitnami (helm repo remove bitnami) and add it through the command: helm repo add bitnami https://charts.bitnami.com/bitnami Then try again, because the new version has mandatory Sasl security verification, it cannot be started without setting it. Can you give me the allowed clusters using the help command? Instead of running directly through kubectl, version 3.7.0 is required

from charts.

zhengbucuo avatar zhengbucuo commented on May 25, 2024

Hi, I deployed a chart using your command and I was not able to reproduce the issue. I got not error in the deployment and then I could create a client and a producer and send/read messages. I used the following to create the producer/consumer clients:

To connect a client to your Kafka, you need to create the 'client.properties' configuration files with the content below:

security.protocol=SASL_PLAINTEXT
sasl.mechanism=SCRAM-SHA-256
sasl.jaas.config=org.apache.kafka.common.security.scram.ScramLoginModule required \
    username="user1" \
    password="$(kubectl get secret kafka-user-passwords --namespace default -o jsonpath='{.data.client-passwords}' | base64 -d | cut -d , -f 1)";

To create a pod that you can use as a Kafka client run the following commands:

    kubectl run kafka-client --restart='Never' --image docker.io/bitnami/kafka:3.7.0-debian-12-r2 --namespace default --command -- sleep infinity
    kubectl cp --namespace default /path/to/client.properties kafka-client:/tmp/client.properties
    kubectl exec --tty -i kafka-client --namespace default -- bash

    PRODUCER:
        kafka-console-producer.sh \
            --producer.config /tmp/client.properties \
            --broker-list kafka-controller-0.kafka-controller-headless.default.svc.cluster.local:9092,kafka-controller-1.kafka-controller-headless.default.svc.cluster.local:9092,kafka-controller-2.kafka-controller-headless.default.svc.cluster.local:9092 \
            --topic test

    CONSUMER:
        kafka-console-consumer.sh \
            --consumer.config /tmp/client.properties \
            --bootstrap-server kafka.default.svc.cluster.local:9092 \
            --topic test \
            --from-beginning

You need to upgrade helm repo to the latest version. Both my two servers and my home computer can reproduce the above problem. You can use the command: helm repo update, or delete bitnami (helm repo remove bitnami) and add it through the command: helm repo add bitnami https://charts.bitnami.com/bitnami Then try again, because the new version has mandatory Sasl security verification, it cannot be started without setting it. Can you give me the allowed clusters using the help command? Instead of running directly through kubectl, version 3.7.0 is required

There is indeed this issue, and I have also noticed it
my kafka log:
image

from charts.

rafariossaa avatar rafariossaa commented on May 25, 2024

Hi,
This is what I used:

$ helm version
version.BuildInfo{Version:"v3.14.0", GitCommit:"3fc9f4b2638e76f26739cd77c7017139be81d0ea", GitTreeState:"clean", GoVersion:"go1.21.5"}
$ kubectl version --short
Flag --short has been deprecated, and will be removed in the future. The --short output will become the default.
Client Version: v1.27.1
Kustomize Version: v5.0.1
Server Version: v1.28.3
$ helm repo list
NAME            URL                                                                          
bitnami         https://charts.bitnami.com/bitnami                                           
$ helm repo update
Hang tight while we grab the latest from your chart repositories...
...Successfully got an update from the "bitnami" chart repository
Update Complete. ⎈Happy Helming!⎈
$ helm search repo bitnami/kafka
NAME            CHART VERSION   APP VERSION     DESCRIPTION
bitnami/kafka   28.0.4          3.7.0           Apache Kafka is a distributed streaming platfor...
helm install kafka bitnami/kafka --namespace pre-logging \
    --set kafkaVersion=3.7.0 \
    --set replicaCount=3 \
    --set kafka.persistence.enabled=false \
    --set kafka.kafkaConfigOverrides=transaction.state.log.replication.factor=3 \
    --set kafka.kafkaConfigOverrides=transaction.state.log.min.isr=2 \
    --set kafka.kafkaConfigOverrides=default.replication.factor=3 \
    --set kafka.kafkaConfigOverrides=num.io.threads=8 \
    --set kafka.kafkaConfigOverrides=num.network.threads=3 \
    --set kafka.kafkaConfigOverrides=log.message.format.version=3.7 \
    --set kafka.kafkaConfigOverrides=inter.broker.protocol.version=3.7 \
    --set kafka.kafkaConfigOverrides=offsets.topic.replication.factor=3 \
    --set kafka.kafkaConfigOverrides=transaction.state.log.num.partitions=50 \
    --set-string labels.app.kubernetes.io/managed-by=Helm \
    --set-string labels.meta.helm.sh/release-name=kafka \
    --set-string labels.meta.helm.sh/release-namespace=pre-logging \
    --set broker.persistence.enabled=false \
    --set controller.persistence.enabled=false \
    --set broker.logPersistence.enabled=false \
    --set kraft.enabled=true \
    --set listeners.client.protocol=SASL_PLAINTEXT \
    --set listeners.controller.protocol=SASL_PLAINTEXT \
    --set listeners.interbroker.protocol=SASL_PLAINTEXT \
    --set listeners.external.protocol=SASL_PLAINTEXT \
    --set sasl.interbroker.user=inter_broker_user \
    --set sasl.interbroker.password=as123456
kubectl get pods -n pre-logging
NAME                 READY   STATUS    RESTARTS   AGE
kafka-controller-0   1/1     Running   0          57s
kafka-controller-1   1/1     Running   0          57s
kafka-controller-2   1/1     Running   0          57s
kubectl logs -n pre-logging kafka-controller-0 
Defaulted container "kafka" out of: kafka, kafka-init (init)
kafka 11:01:12.51 INFO  ==> 
kafka 11:01:12.51 INFO  ==> Welcome to the Bitnami kafka container
kafka 11:01:12.51 INFO  ==> Subscribe to project updates by watching https://github.com/bitnami/containers
kafka 11:01:12.52 INFO  ==> Submit issues and feature requests at https://github.com/bitnami/containers/issues
kafka 11:01:12.52 INFO  ==> Upgrade to Tanzu Application Catalog for production environments to access custom-configured and pre-packaged software components. Gain enhanced features, including Software Bill of Materials (SBOM), CVE scan result reports, and VEX documents. To learn more, visit https://bitnami.com/enterprise
kafka 11:01:12.52 INFO  ==> 
kafka 11:01:12.53 INFO  ==> ** Starting Kafka setup **
kafka 11:01:12.73 INFO  ==> Initializing KRaft storage metadata
kafka 11:01:12.73 INFO  ==> Adding KRaft SCRAM users at storage bootstrap
kafka 11:01:12.79 INFO  ==> Formatting storage directories to add metadata...
metaPropertiesEnsemble=MetaPropertiesEnsemble(metadataLogDir=Optional.empty, dirs={/bitnami/kafka/data: EMPTY})
Formatting /bitnami/kafka/data with metadata.version 3.7-IV4.
kafka 11:01:19.82 INFO  ==> ** Kafka setup finished! **

kafka 11:01:19.85 INFO  ==> ** Starting Kafka **
[2024-04-29 11:01:22,997] INFO Registered kafka:type=kafka.Log4jController MBean (kafka.utils.Log4jControllerRegistration$)
[2024-04-29 11:01:24,400] INFO Setting -D jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated TLS renegotiation (org.apache.zookeeper.common.X509Util)
[2024-04-29 11:01:25,391] INFO Registered signal handlers for TERM, INT, HUP (org.apache.kafka.common.utils.LoggingSignalHandler)
[2024-04-29 11:01:25,397] INFO [ControllerServer id=0] Starting controller (kafka.server.ControllerServer)
[2024-04-29 11:01:27,410] INFO Updated connection-accept-rate max connection creation rate to 2147483647 (kafka.network.ConnectionQuotas)
[2024-04-29 11:01:27,786] INFO Successfully logged in. (org.apache.kafka.common.security.authenticator.AbstractLogin)
[2024-04-29 11:01:27,883] INFO [SocketServer listenerType=CONTROLLER, nodeId=0] Created data-plane acceptor and processors for endpoint : ListenerName(CONTROLLER) (kafka.network.SocketServer)
[2024-04-29 11:01:27,889] INFO CONTROLLER: resolved wildcard host to kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local (org.apache.kafka.metadata.ListenerInfo)
[2024-04-29 11:01:27,901] INFO authorizerStart completed for endpoint CONTROLLER. Endpoint is now READY. (org.apache.kafka.server.network.EndpointReadyFutures)
[2024-04-29 11:01:27,902] INFO [SharedServer id=0] Starting SharedServer (kafka.server.SharedServer)
[2024-04-29 11:01:28,235] INFO [LogLoader partition=__cluster_metadata-0, dir=/bitnami/kafka/data] Loading producer state till offset 0 with message format version 2 (kafka.log.UnifiedLog$)
[2024-04-29 11:01:28,236] INFO [LogLoader partition=__cluster_metadata-0, dir=/bitnami/kafka/data] Reloading from producer snapshot and rebuilding producer state from offset 0 (kafka.log.UnifiedLog$)
[2024-04-29 11:01:28,236] INFO [LogLoader partition=__cluster_metadata-0, dir=/bitnami/kafka/data] Producer state recovery took 0ms for snapshot load and 0ms for segment recovery from offset 0 (kafka.log.UnifiedLog$)
[2024-04-29 11:01:28,416] INFO Initialized snapshots with IDs Set() from /bitnami/kafka/data/__cluster_metadata-0 (kafka.raft.KafkaMetadataLog$)
[2024-04-29 11:01:28,507] INFO [raft-expiration-reaper]: Starting (kafka.raft.TimingWheelExpirationService$ExpiredOperationReaper)
[2024-04-29 11:01:29,530] INFO [RaftManager id=0] Completed transition to Unattached(epoch=0, voters=[0, 1, 2], electionTimeoutMs=1296) from null (org.apache.kafka.raft.QuorumState)
[2024-04-29 11:01:29,586] INFO [kafka-0-raft-outbound-request-thread]: Starting (org.apache.kafka.raft.KafkaNetworkChannel$SendThread)
[2024-04-29 11:01:29,586] INFO [kafka-0-raft-io-thread]: Starting (kafka.raft.KafkaRaftManager$RaftIoThread)
[2024-04-29 11:01:29,612] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:29,614] INFO [ControllerServer id=0] Waiting for controller quorum voters future (kafka.server.ControllerServer)
[2024-04-29 11:01:29,615] INFO [ControllerServer id=0] Finished waiting for controller quorum voters future (kafka.server.ControllerServer)
[2024-04-29 11:01:29,615] INFO [RaftManager id=0] Registered the listener org.apache.kafka.image.loader.MetadataLoader@1906519282 (org.apache.kafka.raft.KafkaRaftClient)
[2024-04-29 11:01:29,712] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:29,805] INFO [QuorumController id=0] Creating new QuorumController with clusterId tGotg5jFmyb2BaeIMMqDmh. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:29,806] INFO [RaftManager id=0] Registered the listener org.apache.kafka.controller.QuorumController$QuorumMetaLogListener@447991081 (org.apache.kafka.raft.KafkaRaftClient)
[2024-04-29 11:01:29,813] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:29,816] INFO [controller-0-ThrottledChannelReaper-Fetch]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:29,817] INFO [controller-0-ThrottledChannelReaper-Produce]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:29,818] INFO [controller-0-ThrottledChannelReaper-Request]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:29,883] INFO [controller-0-ThrottledChannelReaper-ControllerMutation]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:29,913] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:29,923] INFO [ExpirationReaper-0-AlterAcls]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:29,933] INFO [RaftManager id=0] Completed transition to CandidateState(localId=0, epoch=1, retries=1, voteStates={0=GRANTED, 1=UNRECORDED, 2=UNRECORDED}, highWatermark=Optional.empty, electionTimeoutMs=1371) from Unattached(epoch=0, voters=[0, 1, 2], electionTimeoutMs=1296) (org.apache.kafka.raft.QuorumState)
[2024-04-29 11:01:29,936] INFO [QuorumController id=0] In the new epoch 1, the leader is (none). (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:30,081] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,086] INFO [ControllerServer id=0] Waiting for the controller metadata publishers to be installed (kafka.server.ControllerServer)
[2024-04-29 11:01:30,086] INFO [ControllerServer id=0] Finished waiting for the controller metadata publishers to be installed (kafka.server.ControllerServer)
[2024-04-29 11:01:30,086] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,087] INFO [SocketServer listenerType=CONTROLLER, nodeId=0] Enabling request processing. (kafka.network.SocketServer)
[2024-04-29 11:01:30,093] INFO Awaiting socket connections on 0.0.0.0:9093. (kafka.network.DataPlaneAcceptor)
[2024-04-29 11:01:30,187] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,287] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,291] INFO [controller-0-to-controller-registration-channel-manager]: Starting (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:30,292] INFO [ControllerServer id=0] Waiting for all of the authorizer futures to be completed (kafka.server.ControllerServer)
[2024-04-29 11:01:30,293] INFO [ControllerRegistrationManager id=0 incarnation=FsUDjHGWSlqvpAsMsesrtA] initialized channel manager. (kafka.server.ControllerRegistrationManager)
[2024-04-29 11:01:30,293] INFO [ControllerServer id=0] Finished waiting for all of the authorizer futures to be completed (kafka.server.ControllerServer)
[2024-04-29 11:01:30,293] INFO [ControllerServer id=0] Waiting for all of the SocketServer Acceptors to be started (kafka.server.ControllerServer)
[2024-04-29 11:01:30,293] INFO [ControllerServer id=0] Finished waiting for all of the SocketServer Acceptors to be started (kafka.server.ControllerServer)
[2024-04-29 11:01:30,294] INFO [ControllerRegistrationManager id=0 incarnation=FsUDjHGWSlqvpAsMsesrtA] maybeSendControllerRegistration: cannot register yet because the metadata version is still 3.0-IV1, which does not support KIP-919 controller registration. (kafka.server.ControllerRegistrationManager)
[2024-04-29 11:01:30,295] INFO [BrokerServer id=0] Transition from SHUTDOWN to STARTING (kafka.server.BrokerServer)
[2024-04-29 11:01:30,297] INFO [BrokerServer id=0] Starting broker (kafka.server.BrokerServer)
[2024-04-29 11:01:30,388] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,390] INFO [broker-0-ThrottledChannelReaper-Fetch]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:30,391] INFO [broker-0-ThrottledChannelReaper-Produce]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:30,391] INFO [broker-0-ThrottledChannelReaper-Request]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:30,392] INFO [broker-0-ThrottledChannelReaper-ControllerMutation]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:30,488] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,589] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,591] INFO [BrokerServer id=0] Waiting for controller quorum voters future (kafka.server.BrokerServer)
[2024-04-29 11:01:30,591] INFO [BrokerServer id=0] Finished waiting for controller quorum voters future (kafka.server.BrokerServer)
[2024-04-29 11:01:30,595] INFO [broker-0-to-controller-forwarding-channel-manager]: Starting (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:30,689] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,790] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,890] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,991] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,095] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,213] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,280] INFO [RaftManager id=0] Election has timed out, backing off for 0ms before becoming a candidate again (org.apache.kafka.raft.KafkaRaftClient)
[2024-04-29 11:01:31,280] INFO [RaftManager id=0] Re-elect as candidate after election backoff has completed (org.apache.kafka.raft.KafkaRaftClient)
[2024-04-29 11:01:31,286] INFO Updated connection-accept-rate max connection creation rate to 2147483647 (kafka.network.ConnectionQuotas)
[2024-04-29 11:01:31,292] INFO Successfully logged in. (org.apache.kafka.common.security.authenticator.AbstractLogin)
[2024-04-29 11:01:31,295] INFO [RaftManager id=0] Completed transition to CandidateState(localId=0, epoch=2, retries=2, voteStates={0=GRANTED, 1=UNRECORDED, 2=UNRECORDED}, highWatermark=Optional.empty, electionTimeoutMs=1557) from CandidateState(localId=0, epoch=1, retries=1, voteStates={0=GRANTED, 1=REJECTED, 2=UNRECORDED}, highWatermark=Optional.empty, electionTimeoutMs=1371) (org.apache.kafka.raft.QuorumState)
[2024-04-29 11:01:31,295] INFO [QuorumController id=0] In the new epoch 2, the leader is (none). (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:31,296] INFO Successfully logged in. (org.apache.kafka.common.security.authenticator.AbstractLogin)
[2024-04-29 11:01:31,381] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,382] INFO [SocketServer listenerType=BROKER, nodeId=0] Created data-plane acceptor and processors for endpoint : ListenerName(CLIENT) (kafka.network.SocketServer)
[2024-04-29 11:01:31,384] INFO Updated connection-accept-rate max connection creation rate to 2147483647 (kafka.network.ConnectionQuotas)
[2024-04-29 11:01:31,388] INFO Successfully logged in. (org.apache.kafka.common.security.authenticator.AbstractLogin)
[2024-04-29 11:01:31,388] INFO Successfully logged in. (org.apache.kafka.common.security.authenticator.AbstractLogin)
[2024-04-29 11:01:31,481] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,487] INFO [SocketServer listenerType=BROKER, nodeId=0] Created data-plane acceptor and processors for endpoint : ListenerName(INTERNAL) (kafka.network.SocketServer)
[2024-04-29 11:01:31,581] INFO [RaftManager id=0] Completed transition to Leader(localId=0, epoch=2, epochStartOffset=0, highWatermark=Optional.empty, voterStates={0=ReplicaState(nodeId=0, endOffset=Optional.empty, lastFetchTimestamp=-1, lastCaughtUpTimestamp=-1, hasAcknowledgedLeader=true), 1=ReplicaState(nodeId=1, endOffset=Optional.empty, lastFetchTimestamp=-1, lastCaughtUpTimestamp=-1, hasAcknowledgedLeader=false), 2=ReplicaState(nodeId=2, endOffset=Optional.empty, lastFetchTimestamp=-1, lastCaughtUpTimestamp=-1, hasAcknowledgedLeader=false)}) from CandidateState(localId=0, epoch=2, retries=2, voteStates={0=GRANTED, 1=GRANTED, 2=UNRECORDED}, highWatermark=Optional.empty, electionTimeoutMs=1557) (org.apache.kafka.raft.QuorumState)
[2024-04-29 11:01:31,582] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,583] INFO [broker-0-to-controller-forwarding-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:31,584] INFO [broker-0-to-controller-alter-partition-channel-manager]: Starting (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:31,585] INFO [broker-0-to-controller-alter-partition-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:31,601] INFO [broker-0-to-controller-directory-assignments-channel-manager]: Starting (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:31,602] INFO [broker-0-to-controller-directory-assignments-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:31,615] INFO [controller-0-to-controller-registration-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:31,682] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,783] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,799] INFO [ExpirationReaper-0-Produce]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:31,801] INFO [ExpirationReaper-0-Fetch]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:31,881] INFO [ExpirationReaper-0-DeleteRecords]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:31,883] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,883] INFO [ExpirationReaper-0-ElectLeader]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:31,886] INFO [ExpirationReaper-0-RemoteFetch]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:31,984] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,001] INFO [ExpirationReaper-0-Heartbeat]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:32,002] INFO [ExpirationReaper-0-Rebalance]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:32,084] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,185] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,285] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,295] INFO [QuorumController id=0] registerBroker: event failed with NotControllerException in 657 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,386] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,391] INFO Unable to read the broker epoch in /bitnami/kafka/data. (kafka.log.LogManager)
[2024-04-29 11:01:32,393] INFO [broker-0-to-controller-heartbeat-channel-manager]: Starting (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:32,394] INFO [broker-0-to-controller-heartbeat-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:32,399] INFO [QuorumController id=0] registerBroker: event failed with NotControllerException in 117 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,401] INFO [BrokerLifecycleManager id=0] Incarnation IiE1Pz-wSVKvIDICKRcQsQ of broker 0 in cluster tGotg5jFmyb2BaeIMMqDmh is now STARTING. (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:32,486] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,492] INFO [QuorumController id=0] registerBroker: event failed with NotControllerException in 102 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,494] INFO [QuorumController id=0] registerBroker: event failed with NotControllerException in 81 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,496] INFO [NodeToControllerChannelManager id=0 name=heartbeat] Client requested disconnect from node 0 (org.apache.kafka.clients.NetworkClient)
[2024-04-29 11:01:32,581] INFO [broker-0-to-controller-heartbeat-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:32,585] INFO [RaftManager id=0] High watermark set to LogOffsetMetadata(offset=1, metadata=Optional[(segmentBaseOffset=0,relativePositionInSegment=106)]) for the first time for epoch 2 based on indexOfHw 1 and voters [ReplicaState(nodeId=0, endOffset=Optional[LogOffsetMetadata(offset=1, metadata=Optional[(segmentBaseOffset=0,relativePositionInSegment=106)])], lastFetchTimestamp=-1, lastCaughtUpTimestamp=-1, hasAcknowledgedLeader=true), ReplicaState(nodeId=1, endOffset=Optional[LogOffsetMetadata(offset=1, metadata=Optional[(segmentBaseOffset=0,relativePositionInSegment=106)])], lastFetchTimestamp=1714388492582, lastCaughtUpTimestamp=1714388492582, hasAcknowledgedLeader=true), ReplicaState(nodeId=2, endOffset=Optional[LogOffsetMetadata(offset=0, metadata=Optional[(segmentBaseOffset=0,relativePositionInSegment=0)])], lastFetchTimestamp=1714388492181, lastCaughtUpTimestamp=-1, hasAcknowledgedLeader=true)] (org.apache.kafka.raft.LeaderState)
[2024-04-29 11:01:32,705] INFO [MetadataLoader id=0] initializeNewPublishers: The loader is still catching up because we have loaded up to offset -1, but the high water mark is 1 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,785] INFO [QuorumController id=0] registerBroker: event failed with NotControllerException in 126 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,786] INFO [QuorumController id=0] registerBroker: event failed with NotControllerException in 100 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,881] INFO [MetadataLoader id=0] initializeNewPublishers: The loader is still catching up because we have loaded up to offset -1, but the high water mark is 1 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,881] INFO [QuorumController id=0] registerBroker: event failed with NotControllerException in 153 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,881] INFO [ExpirationReaper-0-AlterAcls]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:32,882] INFO [NodeToControllerChannelManager id=0 name=heartbeat] Client requested disconnect from node 0 (org.apache.kafka.clients.NetworkClient)
[2024-04-29 11:01:32,882] INFO [broker-0-to-controller-heartbeat-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:32,887] INFO [QuorumController id=0] Becoming the active controller at epoch 2, next write offset 1. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,888] INFO [MetadataLoader id=0] maybePublishMetadata(LOG_DELTA): The loader is still catching up because we have not loaded a controller record as of offset 0 and high water mark is 1 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,981] INFO [broker-0-to-controller-heartbeat-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:32,981] INFO [MetadataLoader id=0] initializeNewPublishers: The loader finished catching up to the current high water mark of 1 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,992] WARN [QuorumController id=0] Performing controller activation. The metadata log appears to be empty. Appending 3 bootstrap record(s) in metadata transaction at metadata.version 3.7-IV4 from bootstrap source 'the binary bootstrap metadata file: /bitnami/kafka/data/bootstrap.checkpoint'. Setting the ZK migration state to NONE since this is a de-novo KRaft cluster. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,996] INFO [QuorumController id=0] Replayed BeginTransactionRecord(name='Bootstrap records') at offset 1. (org.apache.kafka.controller.OffsetControlManager)
[2024-04-29 11:01:33,081] INFO [QuorumController id=0] Replayed a FeatureLevelRecord setting metadata version to 3.7-IV4 (org.apache.kafka.controller.FeatureControlManager)
[2024-04-29 11:01:33,085] INFO [QuorumController id=0] Replayed UserScramCredentialRecord creating new entry for user1 with mechanism SCRAM_SHA_256. (org.apache.kafka.controller.ScramControlManager)
[2024-04-29 11:01:33,085] INFO [QuorumController id=0] Replayed UserScramCredentialRecord creating new entry for user1 with mechanism SCRAM_SHA_512. (org.apache.kafka.controller.ScramControlManager)
[2024-04-29 11:01:33,086] INFO [QuorumController id=0] Replayed EndTransactionRecord() at offset 6. (org.apache.kafka.controller.OffsetControlManager)
[2024-04-29 11:01:33,185] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing SnapshotGenerator with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,186] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing KRaftMetadataCachePublisher with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,186] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing FeaturesPublisher with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,186] INFO [ControllerServer id=0] Loaded new metadata Features(version=3.0-IV1, finalizedFeatures={metadata.version=1}, finalizedFeaturesEpoch=0). (org.apache.kafka.metadata.publisher.FeaturesPublisher)
[2024-04-29 11:01:33,186] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing ControllerRegistrationsPublisher with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,186] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing ControllerRegistrationManager with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,187] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing DynamicConfigPublisher controller id=0 with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,187] INFO [ControllerRegistrationManager id=0 incarnation=FsUDjHGWSlqvpAsMsesrtA] maybeSendControllerRegistration: cannot register yet because the metadata version is still 3.0-IV1, which does not support KIP-919 controller registration. (kafka.server.ControllerRegistrationManager)
[2024-04-29 11:01:33,189] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing DynamicClientQuotaPublisher controller id=0 with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,190] INFO [BrokerServer id=0] Waiting for the broker metadata publishers to be installed (kafka.server.BrokerServer)
[2024-04-29 11:01:33,190] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing ScramPublisher controller id=0 with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,191] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing DelegationTokenPublisher controller id=0 with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,194] INFO [QuorumController id=0] Replayed initial RegisterBrokerRecord for broker 2: RegisterBrokerRecord(brokerId=2, isMigratingZkBroker=false, incarnationId=WIFeiDIzSAaoIg5oOBq6-g, brokerEpoch=7, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-2.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-2.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[KsIvMjIYpSOqz-7M94ssLg]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:33,195] INFO [QuorumController id=0] Replayed initial RegisterBrokerRecord for broker 0: RegisterBrokerRecord(brokerId=0, isMigratingZkBroker=false, incarnationId=IiE1Pz-wSVKvIDICKRcQsQ, brokerEpoch=8, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[d9lo71YK9ZzacyhfbVljZQ]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:33,196] INFO [QuorumController id=0] Replayed initial RegisterBrokerRecord for broker 1: RegisterBrokerRecord(brokerId=1, isMigratingZkBroker=false, incarnationId=i7We8oJuQ5OXmi8K1v5jwA, brokerEpoch=9, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[3nW2dIcb9Z7elmqyAx1_PQ]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:33,282] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing ControllerMetadataMetricsPublisher with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,283] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing AclPublisher controller id=0 with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,284] INFO [BrokerServer id=0] Finished waiting for the broker metadata publishers to be installed (kafka.server.BrokerServer)
[2024-04-29 11:01:33,284] INFO [BrokerServer id=0] Waiting for the controller to acknowledge that we are caught up (kafka.server.BrokerServer)
[2024-04-29 11:01:33,284] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing BrokerMetadataPublisher with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,285] INFO [BrokerMetadataPublisher id=0] Publishing initial metadata at offset OffsetAndEpoch(offset=0, epoch=2) with metadata.version 3.0-IV1. (kafka.server.metadata.BrokerMetadataPublisher)
[2024-04-29 11:01:33,286] INFO Loading logs from log dirs ArrayBuffer(/bitnami/kafka/data) (kafka.log.LogManager)
[2024-04-29 11:01:33,292] INFO No logs found to be loaded in /bitnami/kafka/data (kafka.log.LogManager)
[2024-04-29 11:01:33,388] INFO [BrokerLifecycleManager id=0] Successfully registered broker 0 with broker epoch 8 (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:33,389] INFO Loaded 0 logs in 101ms (kafka.log.LogManager)
[2024-04-29 11:01:33,389] INFO Starting log cleanup with a period of 300000 ms. (kafka.log.LogManager)
[2024-04-29 11:01:33,392] INFO Starting log flusher with a default period of 9223372036854775807 ms. (kafka.log.LogManager)
[2024-04-29 11:01:33,501] INFO Starting the log cleaner (kafka.log.LogCleaner)
[2024-04-29 11:01:34,095] INFO [kafka-log-cleaner-thread-0]: Starting (kafka.log.LogCleaner$CleanerThread)
[2024-04-29 11:01:34,183] INFO [LogDirFailureHandler]: Starting (kafka.server.ReplicaManager$LogDirFailureHandler)
[2024-04-29 11:01:34,186] INFO [GroupCoordinator 0]: Starting up. (kafka.coordinator.group.GroupCoordinator)
[2024-04-29 11:01:34,186] INFO [AddPartitionsToTxnSenderThread-0]: Starting (kafka.server.AddPartitionsToTxnManager)
[2024-04-29 11:01:34,190] INFO [GroupCoordinator 0]: Startup complete. (kafka.coordinator.group.GroupCoordinator)
[2024-04-29 11:01:34,191] INFO [TransactionCoordinator id=0] Starting up. (kafka.coordinator.transaction.TransactionCoordinator)
[2024-04-29 11:01:34,194] INFO [TxnMarkerSenderThread-0]: Starting (kafka.coordinator.transaction.TransactionMarkerChannelManager)
[2024-04-29 11:01:34,195] INFO [TransactionCoordinator id=0] Startup complete. (kafka.coordinator.transaction.TransactionCoordinator)
[2024-04-29 11:01:34,288] INFO [QuorumController id=0] Replayed RegisterControllerRecord contaning ControllerRegistration(id=1, incarnationId=kOm2CgsKQVC-euvbsFphJQ, zkMigrationReady=false, listeners=[Endpoint(listenerName='CONTROLLER', securityProtocol=SASL_PLAINTEXT, host='kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local', port=9093)], supportedFeatures={metadata.version: 1-19}). (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,293] INFO [QuorumController id=0] Replayed RegisterBrokerRecord modifying the registration for broker 1: RegisterBrokerRecord(brokerId=1, isMigratingZkBroker=false, incarnationId=i7We8oJuQ5OXmi8K1v5jwA, brokerEpoch=13, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[3nW2dIcb9Z7elmqyAx1_PQ]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,382] INFO [ControllerServer id=0] Loaded new metadata Features(version=3.7-IV4, finalizedFeatures={metadata.version=19}, finalizedFeaturesEpoch=6). (org.apache.kafka.metadata.publisher.FeaturesPublisher)
[2024-04-29 11:01:34,382] INFO [QuorumController id=0] Replayed RegisterBrokerRecord modifying the registration for broker 2: RegisterBrokerRecord(brokerId=2, isMigratingZkBroker=false, incarnationId=WIFeiDIzSAaoIg5oOBq6-g, brokerEpoch=14, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-2.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-2.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[KsIvMjIYpSOqz-7M94ssLg]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,385] INFO [ControllerRegistrationManager id=0 incarnation=FsUDjHGWSlqvpAsMsesrtA] sendControllerRegistration: attempting to send ControllerRegistrationRequestData(controllerId=0, incarnationId=FsUDjHGWSlqvpAsMsesrtA, zkMigrationReady=false, listeners=[Listener(name='CONTROLLER', host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9093, securityProtocol=2)], features=[Feature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)]) (kafka.server.ControllerRegistrationManager)
[2024-04-29 11:01:34,385] INFO [BrokerMetadataPublisher id=0] Updating metadata.version to 19 at offset OffsetAndEpoch(offset=6, epoch=2). (kafka.server.metadata.BrokerMetadataPublisher)
[2024-04-29 11:01:34,389] INFO [QuorumController id=0] Replayed RegisterControllerRecord contaning ControllerRegistration(id=2, incarnationId=7Jz23xKrS5yUjMfx7mXyGg, zkMigrationReady=false, listeners=[Endpoint(listenerName='CONTROLLER', securityProtocol=SASL_PLAINTEXT, host='kafka-controller-2.kafka-controller-headless.pre-logging.svc.cluster.local', port=9093)], supportedFeatures={metadata.version: 1-19}). (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,481] INFO [BrokerMetadataPublisher id=0] Resending BrokerRegistration with existing incarnation-id to inform the controller about log directories in the broker following metadata update: previousMetadataVersion: 3.0-IV1 newMetadataVersion: 3.7-IV4 (kafka.server.metadata.BrokerMetadataPublisher)
[2024-04-29 11:01:34,482] INFO [QuorumController id=0] Replayed RegisterControllerRecord contaning ControllerRegistration(id=0, incarnationId=FsUDjHGWSlqvpAsMsesrtA, zkMigrationReady=false, listeners=[Endpoint(listenerName='CONTROLLER', securityProtocol=SASL_PLAINTEXT, host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9093)], supportedFeatures={metadata.version: 1-19}). (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,496] INFO [QuorumController id=0] Replayed RegisterBrokerRecord modifying the registration for broker 1: RegisterBrokerRecord(brokerId=1, isMigratingZkBroker=false, incarnationId=i7We8oJuQ5OXmi8K1v5jwA, brokerEpoch=17, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[3nW2dIcb9Z7elmqyAx1_PQ]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,582] INFO [QuorumController id=0] Replayed RegisterBrokerRecord modifying the registration for broker 0: RegisterBrokerRecord(brokerId=0, isMigratingZkBroker=false, incarnationId=IiE1Pz-wSVKvIDICKRcQsQ, brokerEpoch=18, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[d9lo71YK9ZzacyhfbVljZQ]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,601] INFO [ControllerRegistrationManager id=0 incarnation=FsUDjHGWSlqvpAsMsesrtA] Our registration has been persisted to the metadata log. (kafka.server.ControllerRegistrationManager)
[2024-04-29 11:01:34,601] INFO [ControllerRegistrationManager id=0 incarnation=FsUDjHGWSlqvpAsMsesrtA] RegistrationResponseHandler: controller acknowledged ControllerRegistrationRequest. (kafka.server.ControllerRegistrationManager)
[2024-04-29 11:01:34,602] INFO [QuorumController id=0] processBrokerHeartbeat: event failed with StaleBrokerEpochException in 136 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:34,683] INFO [BrokerLifecycleManager id=0] Successfully registered broker 0 with broker epoch 18 (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:34,685] INFO [QuorumController id=0] Replayed RegisterBrokerRecord modifying the registration for broker 0: RegisterBrokerRecord(brokerId=0, isMigratingZkBroker=false, incarnationId=IiE1Pz-wSVKvIDICKRcQsQ, brokerEpoch=20, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[d9lo71YK9ZzacyhfbVljZQ]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,730] INFO [BrokerLifecycleManager id=0] Successfully registered broker 0 with broker epoch 20 (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:34,731] INFO [QuorumController id=0] processBrokerHeartbeat: event failed with StaleBrokerEpochException in 70 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:34,733] WARN [BrokerLifecycleManager id=0] Broker 0 sent a heartbeat request but received error STALE_BROKER_EPOCH. (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:34,735] INFO [BrokerLifecycleManager id=0] The broker has caught up. Transitioning from STARTING to RECOVERY. (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:34,735] INFO [BrokerServer id=0] Finished waiting for the controller to acknowledge that we are caught up (kafka.server.BrokerServer)
[2024-04-29 11:01:34,736] INFO [BrokerServer id=0] Waiting for the initial broker metadata update to be published (kafka.server.BrokerServer)
[2024-04-29 11:01:34,736] INFO [BrokerServer id=0] Finished waiting for the initial broker metadata update to be published (kafka.server.BrokerServer)
[2024-04-29 11:01:34,738] INFO KafkaConfig values: 
        advertised.listeners = CLIENT://kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9092,INTERNAL://kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9094
        alter.config.policy.class.name = null
        alter.log.dirs.replication.quota.window.num = 11
        alter.log.dirs.replication.quota.window.size.seconds = 1
        authorizer.class.name = 
        auto.create.topics.enable = true
        auto.include.jmx.reporter = true
        auto.leader.rebalance.enable = true
        background.threads = 10
        broker.heartbeat.interval.ms = 2000
        broker.id = 0
        broker.id.generation.enable = true
        broker.rack = null
        broker.session.timeout.ms = 9000
        client.quota.callback.class = null
        compression.type = producer
        connection.failed.authentication.delay.ms = 100
        connections.max.idle.ms = 600000
        connections.max.reauth.ms = 0
        control.plane.listener.name = null
        controlled.shutdown.enable = true
        controlled.shutdown.max.retries = 3
        controlled.shutdown.retry.backoff.ms = 5000
        controller.listener.names = CONTROLLER
        controller.quorum.append.linger.ms = 25
        controller.quorum.election.backoff.max.ms = 1000
        controller.quorum.election.timeout.ms = 1000
        controller.quorum.fetch.timeout.ms = 2000
        controller.quorum.request.timeout.ms = 2000
        controller.quorum.retry.backoff.ms = 20
        controller.quorum.voters = [0@kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093, 1@kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local:9093, 2@kafka-controller-2.kafka-controller-headless.pre-logging.svc.cluster.local:9093]
        controller.quota.window.num = 11
        controller.quota.window.size.seconds = 1
        controller.socket.timeout.ms = 30000
        create.topic.policy.class.name = null
        default.replication.factor = 1
        delegation.token.expiry.check.interval.ms = 3600000
        delegation.token.expiry.time.ms = 86400000
        delegation.token.master.key = null
        delegation.token.max.lifetime.ms = 604800000
        delegation.token.secret.key = null
        delete.records.purgatory.purge.interval.requests = 1
        delete.topic.enable = true
        early.start.listeners = null
        eligible.leader.replicas.enable = false
        fetch.max.bytes = 57671680
        fetch.purgatory.purge.interval.requests = 1000
        group.consumer.assignors = [org.apache.kafka.coordinator.group.assignor.UniformAssignor, org.apache.kafka.coordinator.group.assignor.RangeAssignor]
        group.consumer.heartbeat.interval.ms = 5000
        group.consumer.max.heartbeat.interval.ms = 15000
        group.consumer.max.session.timeout.ms = 60000
        group.consumer.max.size = 2147483647
        group.consumer.min.heartbeat.interval.ms = 5000
        group.consumer.min.session.timeout.ms = 45000
        group.consumer.session.timeout.ms = 45000
        group.coordinator.new.enable = false
        group.coordinator.rebalance.protocols = [classic]
        group.coordinator.threads = 1
        group.initial.rebalance.delay.ms = 3000
        group.max.session.timeout.ms = 1800000
        group.max.size = 2147483647
        group.min.session.timeout.ms = 6000
        initial.broker.registration.timeout.ms = 60000
        inter.broker.listener.name = INTERNAL
        inter.broker.protocol.version = 3.7-IV4
        kafka.metrics.polling.interval.secs = 10
        kafka.metrics.reporters = []
        leader.imbalance.check.interval.seconds = 300
        leader.imbalance.per.broker.percentage = 10
        listener.security.protocol.map = CLIENT:SASL_PLAINTEXT,INTERNAL:SASL_PLAINTEXT,CONTROLLER:SASL_PLAINTEXT
        listeners = CLIENT://:9092,INTERNAL://:9094,CONTROLLER://:9093
        log.cleaner.backoff.ms = 15000
        log.cleaner.dedupe.buffer.size = 134217728
        log.cleaner.delete.retention.ms = 86400000
        log.cleaner.enable = true
        log.cleaner.io.buffer.load.factor = 0.9
        log.cleaner.io.buffer.size = 524288
        log.cleaner.io.max.bytes.per.second = 1.7976931348623157E308
        log.cleaner.max.compaction.lag.ms = 9223372036854775807
        log.cleaner.min.cleanable.ratio = 0.5
        log.cleaner.min.compaction.lag.ms = 0
        log.cleaner.threads = 1
        log.cleanup.policy = [delete]
        log.dir = /bitnami/kafka/data
        log.dirs = null
        log.flush.interval.messages = 9223372036854775807
        log.flush.interval.ms = null
        log.flush.offset.checkpoint.interval.ms = 60000
        log.flush.scheduler.interval.ms = 9223372036854775807
        log.flush.start.offset.checkpoint.interval.ms = 60000
        log.index.interval.bytes = 4096
        log.index.size.max.bytes = 10485760
        log.local.retention.bytes = -2
        log.local.retention.ms = -2
        log.message.downconversion.enable = true
        log.message.format.version = 3.0-IV1
        log.message.timestamp.after.max.ms = 9223372036854775807
        log.message.timestamp.before.max.ms = 9223372036854775807
        log.message.timestamp.difference.max.ms = 9223372036854775807
        log.message.timestamp.type = CreateTime
        log.preallocate = false
        log.retention.bytes = -1
        log.retention.check.interval.ms = 300000
        log.retention.hours = 168
        log.retention.minutes = null
        log.retention.ms = null
        log.roll.hours = 168
        log.roll.jitter.hours = 0
        log.roll.jitter.ms = null
        log.roll.ms = null
        log.segment.bytes = 1073741824
        log.segment.delete.delay.ms = 60000
        max.connection.creation.rate = 2147483647
        max.connections = 2147483647
        max.connections.per.ip = 2147483647
        max.connections.per.ip.overrides = 
        max.incremental.fetch.session.cache.slots = 1000
        message.max.bytes = 1048588
        metadata.log.dir = null
        metadata.log.max.record.bytes.between.snapshots = 20971520
        metadata.log.max.snapshot.interval.ms = 3600000
        metadata.log.segment.bytes = 1073741824
        metadata.log.segment.min.bytes = 8388608
        metadata.log.segment.ms = 604800000
        metadata.max.idle.interval.ms = 500
        metadata.max.retention.bytes = 104857600
        metadata.max.retention.ms = 604800000
        metric.reporters = []
        metrics.num.samples = 2
        metrics.recording.level = INFO
        metrics.sample.window.ms = 30000
        min.insync.replicas = 1
        node.id = 0
        num.io.threads = 8
        num.network.threads = 3
        num.partitions = 1
        num.recovery.threads.per.data.dir = 1
        num.replica.alter.log.dirs.threads = null
        num.replica.fetchers = 1
        offset.metadata.max.bytes = 4096
        offsets.commit.required.acks = -1
        offsets.commit.timeout.ms = 5000
        offsets.load.buffer.size = 5242880
        offsets.retention.check.interval.ms = 600000
        offsets.retention.minutes = 10080
        offsets.topic.compression.codec = 0
        offsets.topic.num.partitions = 50
        offsets.topic.replication.factor = 3
        offsets.topic.segment.bytes = 104857600
        password.encoder.cipher.algorithm = AES/CBC/PKCS5Padding
        password.encoder.iterations = 4096
        password.encoder.key.length = 128
        password.encoder.keyfactory.algorithm = null
        password.encoder.old.secret = null
        password.encoder.secret = null
        principal.builder.class = class org.apache.kafka.common.security.authenticator.DefaultKafkaPrincipalBuilder
        process.roles = [controller, broker]
        producer.id.expiration.check.interval.ms = 600000
        producer.id.expiration.ms = 86400000
        producer.purgatory.purge.interval.requests = 1000
        queued.max.request.bytes = -1
        queued.max.requests = 500
        quota.window.num = 11
        quota.window.size.seconds = 1
        remote.log.index.file.cache.total.size.bytes = 1073741824
        remote.log.manager.task.interval.ms = 30000
        remote.log.manager.task.retry.backoff.max.ms = 30000
        remote.log.manager.task.retry.backoff.ms = 500
        remote.log.manager.task.retry.jitter = 0.2
        remote.log.manager.thread.pool.size = 10
        remote.log.metadata.custom.metadata.max.bytes = 128
        remote.log.metadata.manager.class.name = org.apache.kafka.server.log.remote.metadata.storage.TopicBasedRemoteLogMetadataManager
        remote.log.metadata.manager.class.path = null
        remote.log.metadata.manager.impl.prefix = rlmm.config.
        remote.log.metadata.manager.listener.name = null
        remote.log.reader.max.pending.tasks = 100
        remote.log.reader.threads = 10
        remote.log.storage.manager.class.name = null
        remote.log.storage.manager.class.path = null
        remote.log.storage.manager.impl.prefix = rsm.config.
        remote.log.storage.system.enable = false
        replica.fetch.backoff.ms = 1000
        replica.fetch.max.bytes = 1048576
        replica.fetch.min.bytes = 1
        replica.fetch.response.max.bytes = 10485760
        replica.fetch.wait.max.ms = 500
        replica.high.watermark.checkpoint.interval.ms = 5000
        replica.lag.time.max.ms = 30000
        replica.selector.class = null
        replica.socket.receive.buffer.bytes = 65536
        replica.socket.timeout.ms = 30000
        replication.quota.window.num = 11
        replication.quota.window.size.seconds = 1
        request.timeout.ms = 30000
        reserved.broker.max.id = 1000
        sasl.client.callback.handler.class = null
        sasl.enabled.mechanisms = [PLAIN, SCRAM-SHA-256, SCRAM-SHA-512]
        sasl.jaas.config = null
        sasl.kerberos.kinit.cmd = /usr/bin/kinit
        sasl.kerberos.min.time.before.relogin = 60000
        sasl.kerberos.principal.to.local.rules = [DEFAULT]
        sasl.kerberos.service.name = null
        sasl.kerberos.ticket.renew.jitter = 0.05
        sasl.kerberos.ticket.renew.window.factor = 0.8
        sasl.login.callback.handler.class = null
        sasl.login.class = null
        sasl.login.connect.timeout.ms = null
        sasl.login.read.timeout.ms = null
        sasl.login.refresh.buffer.seconds = 300
        sasl.login.refresh.min.period.seconds = 60
        sasl.login.refresh.window.factor = 0.8
        sasl.login.refresh.window.jitter = 0.05
        sasl.login.retry.backoff.max.ms = 10000
        sasl.login.retry.backoff.ms = 100
        sasl.mechanism.controller.protocol = PLAIN
        sasl.mechanism.inter.broker.protocol = PLAIN
        sasl.oauthbearer.clock.skew.seconds = 30
        sasl.oauthbearer.expected.audience = null
        sasl.oauthbearer.expected.issuer = null
        sasl.oauthbearer.jwks.endpoint.refresh.ms = 3600000
        sasl.oauthbearer.jwks.endpoint.retry.backoff.max.ms = 10000
        sasl.oauthbearer.jwks.endpoint.retry.backoff.ms = 100
        sasl.oauthbearer.jwks.endpoint.url = null
        sasl.oauthbearer.scope.claim.name = scope
        sasl.oauthbearer.sub.claim.name = sub
        sasl.oauthbearer.token.endpoint.url = null
        sasl.server.callback.handler.class = null
        sasl.server.max.receive.size = 524288
        security.inter.broker.protocol = PLAINTEXT
        security.providers = null
        server.max.startup.time.ms = 9223372036854775807
        socket.connection.setup.timeout.max.ms = 30000
        socket.connection.setup.timeout.ms = 10000
        socket.listen.backlog.size = 50
        socket.receive.buffer.bytes = 102400
        socket.request.max.bytes = 104857600
        socket.send.buffer.bytes = 102400
        ssl.allow.dn.changes = false
        ssl.allow.san.changes = false
        ssl.cipher.suites = []
        ssl.client.auth = none
        ssl.enabled.protocols = [TLSv1.2, TLSv1.3]
        ssl.endpoint.identification.algorithm = https
        ssl.engine.factory.class = null
        ssl.key.password = null
        ssl.keymanager.algorithm = SunX509
        ssl.keystore.certificate.chain = null
        ssl.keystore.key = null
        ssl.keystore.location = null
        ssl.keystore.password = null
        ssl.keystore.type = JKS
        ssl.principal.mapping.rules = DEFAULT
        ssl.protocol = TLSv1.3
        ssl.provider = null
        ssl.secure.random.implementation = null
        ssl.trustmanager.algorithm = PKIX
        ssl.truststore.certificates = null
        ssl.truststore.location = null
        ssl.truststore.password = null
        ssl.truststore.type = JKS
        telemetry.max.bytes = 1048576
        transaction.abort.timed.out.transaction.cleanup.interval.ms = 10000
        transaction.max.timeout.ms = 900000
        transaction.partition.verification.enable = true
        transaction.remove.expired.transaction.cleanup.interval.ms = 3600000
        transaction.state.log.load.buffer.size = 5242880
        transaction.state.log.min.isr = 2
        transaction.state.log.num.partitions = 50
        transaction.state.log.replication.factor = 3
        transaction.state.log.segment.bytes = 104857600
        transactional.id.expiration.ms = 604800000
        unclean.leader.election.enable = false
        unstable.api.versions.enable = false
        unstable.metadata.versions.enable = false
        zookeeper.clientCnxnSocket = null
        zookeeper.connect = null
        zookeeper.connection.timeout.ms = null
        zookeeper.max.in.flight.requests = 10
        zookeeper.metadata.migration.enable = false
        zookeeper.metadata.migration.min.batch.size = 200
        zookeeper.session.timeout.ms = 18000
        zookeeper.set.acl = false
        zookeeper.ssl.cipher.suites = null
        zookeeper.ssl.client.enable = false
        zookeeper.ssl.crl.enable = false
        zookeeper.ssl.enabled.protocols = null
        zookeeper.ssl.endpoint.identification.algorithm = HTTPS
        zookeeper.ssl.keystore.location = null
        zookeeper.ssl.keystore.password = null
        zookeeper.ssl.keystore.type = null
        zookeeper.ssl.ocsp.enable = false
        zookeeper.ssl.protocol = TLSv1.2
        zookeeper.ssl.truststore.location = null
        zookeeper.ssl.truststore.password = null
        zookeeper.ssl.truststore.type = null
 (kafka.server.KafkaConfig)
[2024-04-29 11:01:34,782] INFO [BrokerLifecycleManager id=0] The broker is in RECOVERY. (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:34,783] INFO [QuorumController id=0] The request from broker 1 to unfence has been granted because it has caught up with the offset of its register broker record 17. (org.apache.kafka.controller.BrokerHeartbeatManager)
[2024-04-29 11:01:34,788] INFO [BrokerServer id=0] Waiting for the broker to be unfenced (kafka.server.BrokerServer)
[2024-04-29 11:01:34,796] INFO [QuorumController id=0] Replayed BrokerRegistrationChangeRecord modifying the registration for broker 1: BrokerRegistrationChangeRecord(brokerId=1, brokerEpoch=17, fenced=-1, inControlledShutdown=0, logDirs=[]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,796] INFO [QuorumController id=0] The request from broker 0 to unfence has been granted because it has caught up with the offset of its register broker record 20. (org.apache.kafka.controller.BrokerHeartbeatManager)
[2024-04-29 11:01:34,797] INFO [QuorumController id=0] Replayed BrokerRegistrationChangeRecord modifying the registration for broker 0: BrokerRegistrationChangeRecord(brokerId=0, brokerEpoch=20, fenced=-1, inControlledShutdown=0, logDirs=[]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,918] INFO [BrokerLifecycleManager id=0] The broker has been unfenced. Transitioning from RECOVERY to RUNNING. (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:34,981] INFO [BrokerServer id=0] Finished waiting for the broker to be unfenced (kafka.server.BrokerServer)
[2024-04-29 11:01:34,981] INFO [QuorumController id=0] The request from broker 2 to unfence has been granted because it has caught up with the offset of its register broker record 14. (org.apache.kafka.controller.BrokerHeartbeatManager)
[2024-04-29 11:01:34,981] INFO [QuorumController id=0] Replayed BrokerRegistrationChangeRecord modifying the registration for broker 2: BrokerRegistrationChangeRecord(brokerId=2, brokerEpoch=14, fenced=-1, inControlledShutdown=0, logDirs=[]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,982] INFO authorizerStart completed for endpoint INTERNAL. Endpoint is now READY. (org.apache.kafka.server.network.EndpointReadyFutures)
[2024-04-29 11:01:34,982] INFO authorizerStart completed for endpoint CLIENT. Endpoint is now READY. (org.apache.kafka.server.network.EndpointReadyFutures)
[2024-04-29 11:01:34,982] INFO [SocketServer listenerType=BROKER, nodeId=0] Enabling request processing. (kafka.network.SocketServer)
[2024-04-29 11:01:34,983] INFO Awaiting socket connections on 0.0.0.0:9092. (kafka.network.DataPlaneAcceptor)
[2024-04-29 11:01:34,984] INFO Awaiting socket connections on 0.0.0.0:9094. (kafka.network.DataPlaneAcceptor)
[2024-04-29 11:01:34,987] INFO [BrokerServer id=0] Waiting for all of the authorizer futures to be completed (kafka.server.BrokerServer)
[2024-04-29 11:01:34,987] INFO [BrokerServer id=0] Finished waiting for all of the authorizer futures to be completed (kafka.server.BrokerServer)
[2024-04-29 11:01:34,987] INFO [BrokerServer id=0] Waiting for all of the SocketServer Acceptors to be started (kafka.server.BrokerServer)
[2024-04-29 11:01:34,987] INFO [BrokerServer id=0] Finished waiting for all of the SocketServer Acceptors to be started (kafka.server.BrokerServer)
[2024-04-29 11:01:34,987] INFO [BrokerServer id=0] Transition from STARTING to STARTED (kafka.server.BrokerServer)
[2024-04-29 11:01:34,988] INFO Kafka version: 3.7.0 (org.apache.kafka.common.utils.AppInfoParser)
[2024-04-29 11:01:34,988] INFO Kafka commitId: 2ae524ed625438c5 (org.apache.kafka.common.utils.AppInfoParser)
[2024-04-29 11:01:34,988] INFO Kafka startTimeMs: 1714388494987 (org.apache.kafka.common.utils.AppInfoParser)
[2024-04-29 11:01:34,990] INFO [KafkaRaftServer nodeId=0] Kafka Server started (kafka.server.KafkaRaftServer)

And I not getting the Failed authentication .... message.

from charts.

zjf88865 avatar zjf88865 commented on May 25, 2024

Hi, This is what I used:

$ helm version
version.BuildInfo{Version:"v3.14.0", GitCommit:"3fc9f4b2638e76f26739cd77c7017139be81d0ea", GitTreeState:"clean", GoVersion:"go1.21.5"}
$ kubectl version --short
Flag --short has been deprecated, and will be removed in the future. The --short output will become the default.
Client Version: v1.27.1
Kustomize Version: v5.0.1
Server Version: v1.28.3
$ helm repo list
NAME            URL                                                                          
bitnami         https://charts.bitnami.com/bitnami                                           
$ helm repo update
Hang tight while we grab the latest from your chart repositories...
...Successfully got an update from the "bitnami" chart repository
Update Complete. ⎈Happy Helming!⎈
$ helm search repo bitnami/kafka
NAME            CHART VERSION   APP VERSION     DESCRIPTION
bitnami/kafka   28.0.4          3.7.0           Apache Kafka is a distributed streaming platfor...
helm install kafka bitnami/kafka --namespace pre-logging \
    --set kafkaVersion=3.7.0 \
    --set replicaCount=3 \
    --set kafka.persistence.enabled=false \
    --set kafka.kafkaConfigOverrides=transaction.state.log.replication.factor=3 \
    --set kafka.kafkaConfigOverrides=transaction.state.log.min.isr=2 \
    --set kafka.kafkaConfigOverrides=default.replication.factor=3 \
    --set kafka.kafkaConfigOverrides=num.io.threads=8 \
    --set kafka.kafkaConfigOverrides=num.network.threads=3 \
    --set kafka.kafkaConfigOverrides=log.message.format.version=3.7 \
    --set kafka.kafkaConfigOverrides=inter.broker.protocol.version=3.7 \
    --set kafka.kafkaConfigOverrides=offsets.topic.replication.factor=3 \
    --set kafka.kafkaConfigOverrides=transaction.state.log.num.partitions=50 \
    --set-string labels.app.kubernetes.io/managed-by=Helm \
    --set-string labels.meta.helm.sh/release-name=kafka \
    --set-string labels.meta.helm.sh/release-namespace=pre-logging \
    --set broker.persistence.enabled=false \
    --set controller.persistence.enabled=false \
    --set broker.logPersistence.enabled=false \
    --set kraft.enabled=true \
    --set listeners.client.protocol=SASL_PLAINTEXT \
    --set listeners.controller.protocol=SASL_PLAINTEXT \
    --set listeners.interbroker.protocol=SASL_PLAINTEXT \
    --set listeners.external.protocol=SASL_PLAINTEXT \
    --set sasl.interbroker.user=inter_broker_user \
    --set sasl.interbroker.password=as123456
kubectl get pods -n pre-logging
NAME                 READY   STATUS    RESTARTS   AGE
kafka-controller-0   1/1     Running   0          57s
kafka-controller-1   1/1     Running   0          57s
kafka-controller-2   1/1     Running   0          57s
kubectl logs -n pre-logging kafka-controller-0 
Defaulted container "kafka" out of: kafka, kafka-init (init)
kafka 11:01:12.51 INFO  ==> 
kafka 11:01:12.51 INFO  ==> Welcome to the Bitnami kafka container
kafka 11:01:12.51 INFO  ==> Subscribe to project updates by watching https://github.com/bitnami/containers
kafka 11:01:12.52 INFO  ==> Submit issues and feature requests at https://github.com/bitnami/containers/issues
kafka 11:01:12.52 INFO  ==> Upgrade to Tanzu Application Catalog for production environments to access custom-configured and pre-packaged software components. Gain enhanced features, including Software Bill of Materials (SBOM), CVE scan result reports, and VEX documents. To learn more, visit https://bitnami.com/enterprise
kafka 11:01:12.52 INFO  ==> 
kafka 11:01:12.53 INFO  ==> ** Starting Kafka setup **
kafka 11:01:12.73 INFO  ==> Initializing KRaft storage metadata
kafka 11:01:12.73 INFO  ==> Adding KRaft SCRAM users at storage bootstrap
kafka 11:01:12.79 INFO  ==> Formatting storage directories to add metadata...
metaPropertiesEnsemble=MetaPropertiesEnsemble(metadataLogDir=Optional.empty, dirs={/bitnami/kafka/data: EMPTY})
Formatting /bitnami/kafka/data with metadata.version 3.7-IV4.
kafka 11:01:19.82 INFO  ==> ** Kafka setup finished! **

kafka 11:01:19.85 INFO  ==> ** Starting Kafka **
[2024-04-29 11:01:22,997] INFO Registered kafka:type=kafka.Log4jController MBean (kafka.utils.Log4jControllerRegistration$)
[2024-04-29 11:01:24,400] INFO Setting -D jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated TLS renegotiation (org.apache.zookeeper.common.X509Util)
[2024-04-29 11:01:25,391] INFO Registered signal handlers for TERM, INT, HUP (org.apache.kafka.common.utils.LoggingSignalHandler)
[2024-04-29 11:01:25,397] INFO [ControllerServer id=0] Starting controller (kafka.server.ControllerServer)
[2024-04-29 11:01:27,410] INFO Updated connection-accept-rate max connection creation rate to 2147483647 (kafka.network.ConnectionQuotas)
[2024-04-29 11:01:27,786] INFO Successfully logged in. (org.apache.kafka.common.security.authenticator.AbstractLogin)
[2024-04-29 11:01:27,883] INFO [SocketServer listenerType=CONTROLLER, nodeId=0] Created data-plane acceptor and processors for endpoint : ListenerName(CONTROLLER) (kafka.network.SocketServer)
[2024-04-29 11:01:27,889] INFO CONTROLLER: resolved wildcard host to kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local (org.apache.kafka.metadata.ListenerInfo)
[2024-04-29 11:01:27,901] INFO authorizerStart completed for endpoint CONTROLLER. Endpoint is now READY. (org.apache.kafka.server.network.EndpointReadyFutures)
[2024-04-29 11:01:27,902] INFO [SharedServer id=0] Starting SharedServer (kafka.server.SharedServer)
[2024-04-29 11:01:28,235] INFO [LogLoader partition=__cluster_metadata-0, dir=/bitnami/kafka/data] Loading producer state till offset 0 with message format version 2 (kafka.log.UnifiedLog$)
[2024-04-29 11:01:28,236] INFO [LogLoader partition=__cluster_metadata-0, dir=/bitnami/kafka/data] Reloading from producer snapshot and rebuilding producer state from offset 0 (kafka.log.UnifiedLog$)
[2024-04-29 11:01:28,236] INFO [LogLoader partition=__cluster_metadata-0, dir=/bitnami/kafka/data] Producer state recovery took 0ms for snapshot load and 0ms for segment recovery from offset 0 (kafka.log.UnifiedLog$)
[2024-04-29 11:01:28,416] INFO Initialized snapshots with IDs Set() from /bitnami/kafka/data/__cluster_metadata-0 (kafka.raft.KafkaMetadataLog$)
[2024-04-29 11:01:28,507] INFO [raft-expiration-reaper]: Starting (kafka.raft.TimingWheelExpirationService$ExpiredOperationReaper)
[2024-04-29 11:01:29,530] INFO [RaftManager id=0] Completed transition to Unattached(epoch=0, voters=[0, 1, 2], electionTimeoutMs=1296) from null (org.apache.kafka.raft.QuorumState)
[2024-04-29 11:01:29,586] INFO [kafka-0-raft-outbound-request-thread]: Starting (org.apache.kafka.raft.KafkaNetworkChannel$SendThread)
[2024-04-29 11:01:29,586] INFO [kafka-0-raft-io-thread]: Starting (kafka.raft.KafkaRaftManager$RaftIoThread)
[2024-04-29 11:01:29,612] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:29,614] INFO [ControllerServer id=0] Waiting for controller quorum voters future (kafka.server.ControllerServer)
[2024-04-29 11:01:29,615] INFO [ControllerServer id=0] Finished waiting for controller quorum voters future (kafka.server.ControllerServer)
[2024-04-29 11:01:29,615] INFO [RaftManager id=0] Registered the listener org.apache.kafka.image.loader.MetadataLoader@1906519282 (org.apache.kafka.raft.KafkaRaftClient)
[2024-04-29 11:01:29,712] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:29,805] INFO [QuorumController id=0] Creating new QuorumController with clusterId tGotg5jFmyb2BaeIMMqDmh. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:29,806] INFO [RaftManager id=0] Registered the listener org.apache.kafka.controller.QuorumController$QuorumMetaLogListener@447991081 (org.apache.kafka.raft.KafkaRaftClient)
[2024-04-29 11:01:29,813] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:29,816] INFO [controller-0-ThrottledChannelReaper-Fetch]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:29,817] INFO [controller-0-ThrottledChannelReaper-Produce]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:29,818] INFO [controller-0-ThrottledChannelReaper-Request]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:29,883] INFO [controller-0-ThrottledChannelReaper-ControllerMutation]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:29,913] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:29,923] INFO [ExpirationReaper-0-AlterAcls]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:29,933] INFO [RaftManager id=0] Completed transition to CandidateState(localId=0, epoch=1, retries=1, voteStates={0=GRANTED, 1=UNRECORDED, 2=UNRECORDED}, highWatermark=Optional.empty, electionTimeoutMs=1371) from Unattached(epoch=0, voters=[0, 1, 2], electionTimeoutMs=1296) (org.apache.kafka.raft.QuorumState)
[2024-04-29 11:01:29,936] INFO [QuorumController id=0] In the new epoch 1, the leader is (none). (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:30,081] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,086] INFO [ControllerServer id=0] Waiting for the controller metadata publishers to be installed (kafka.server.ControllerServer)
[2024-04-29 11:01:30,086] INFO [ControllerServer id=0] Finished waiting for the controller metadata publishers to be installed (kafka.server.ControllerServer)
[2024-04-29 11:01:30,086] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,087] INFO [SocketServer listenerType=CONTROLLER, nodeId=0] Enabling request processing. (kafka.network.SocketServer)
[2024-04-29 11:01:30,093] INFO Awaiting socket connections on 0.0.0.0:9093. (kafka.network.DataPlaneAcceptor)
[2024-04-29 11:01:30,187] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,287] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,291] INFO [controller-0-to-controller-registration-channel-manager]: Starting (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:30,292] INFO [ControllerServer id=0] Waiting for all of the authorizer futures to be completed (kafka.server.ControllerServer)
[2024-04-29 11:01:30,293] INFO [ControllerRegistrationManager id=0 incarnation=FsUDjHGWSlqvpAsMsesrtA] initialized channel manager. (kafka.server.ControllerRegistrationManager)
[2024-04-29 11:01:30,293] INFO [ControllerServer id=0] Finished waiting for all of the authorizer futures to be completed (kafka.server.ControllerServer)
[2024-04-29 11:01:30,293] INFO [ControllerServer id=0] Waiting for all of the SocketServer Acceptors to be started (kafka.server.ControllerServer)
[2024-04-29 11:01:30,293] INFO [ControllerServer id=0] Finished waiting for all of the SocketServer Acceptors to be started (kafka.server.ControllerServer)
[2024-04-29 11:01:30,294] INFO [ControllerRegistrationManager id=0 incarnation=FsUDjHGWSlqvpAsMsesrtA] maybeSendControllerRegistration: cannot register yet because the metadata version is still 3.0-IV1, which does not support KIP-919 controller registration. (kafka.server.ControllerRegistrationManager)
[2024-04-29 11:01:30,295] INFO [BrokerServer id=0] Transition from SHUTDOWN to STARTING (kafka.server.BrokerServer)
[2024-04-29 11:01:30,297] INFO [BrokerServer id=0] Starting broker (kafka.server.BrokerServer)
[2024-04-29 11:01:30,388] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,390] INFO [broker-0-ThrottledChannelReaper-Fetch]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:30,391] INFO [broker-0-ThrottledChannelReaper-Produce]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:30,391] INFO [broker-0-ThrottledChannelReaper-Request]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:30,392] INFO [broker-0-ThrottledChannelReaper-ControllerMutation]: Starting (kafka.server.ClientQuotaManager$ThrottledChannelReaper)
[2024-04-29 11:01:30,488] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,589] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,591] INFO [BrokerServer id=0] Waiting for controller quorum voters future (kafka.server.BrokerServer)
[2024-04-29 11:01:30,591] INFO [BrokerServer id=0] Finished waiting for controller quorum voters future (kafka.server.BrokerServer)
[2024-04-29 11:01:30,595] INFO [broker-0-to-controller-forwarding-channel-manager]: Starting (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:30,689] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,790] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,890] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:30,991] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,095] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,213] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,280] INFO [RaftManager id=0] Election has timed out, backing off for 0ms before becoming a candidate again (org.apache.kafka.raft.KafkaRaftClient)
[2024-04-29 11:01:31,280] INFO [RaftManager id=0] Re-elect as candidate after election backoff has completed (org.apache.kafka.raft.KafkaRaftClient)
[2024-04-29 11:01:31,286] INFO Updated connection-accept-rate max connection creation rate to 2147483647 (kafka.network.ConnectionQuotas)
[2024-04-29 11:01:31,292] INFO Successfully logged in. (org.apache.kafka.common.security.authenticator.AbstractLogin)
[2024-04-29 11:01:31,295] INFO [RaftManager id=0] Completed transition to CandidateState(localId=0, epoch=2, retries=2, voteStates={0=GRANTED, 1=UNRECORDED, 2=UNRECORDED}, highWatermark=Optional.empty, electionTimeoutMs=1557) from CandidateState(localId=0, epoch=1, retries=1, voteStates={0=GRANTED, 1=REJECTED, 2=UNRECORDED}, highWatermark=Optional.empty, electionTimeoutMs=1371) (org.apache.kafka.raft.QuorumState)
[2024-04-29 11:01:31,295] INFO [QuorumController id=0] In the new epoch 2, the leader is (none). (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:31,296] INFO Successfully logged in. (org.apache.kafka.common.security.authenticator.AbstractLogin)
[2024-04-29 11:01:31,381] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,382] INFO [SocketServer listenerType=BROKER, nodeId=0] Created data-plane acceptor and processors for endpoint : ListenerName(CLIENT) (kafka.network.SocketServer)
[2024-04-29 11:01:31,384] INFO Updated connection-accept-rate max connection creation rate to 2147483647 (kafka.network.ConnectionQuotas)
[2024-04-29 11:01:31,388] INFO Successfully logged in. (org.apache.kafka.common.security.authenticator.AbstractLogin)
[2024-04-29 11:01:31,388] INFO Successfully logged in. (org.apache.kafka.common.security.authenticator.AbstractLogin)
[2024-04-29 11:01:31,481] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,487] INFO [SocketServer listenerType=BROKER, nodeId=0] Created data-plane acceptor and processors for endpoint : ListenerName(INTERNAL) (kafka.network.SocketServer)
[2024-04-29 11:01:31,581] INFO [RaftManager id=0] Completed transition to Leader(localId=0, epoch=2, epochStartOffset=0, highWatermark=Optional.empty, voterStates={0=ReplicaState(nodeId=0, endOffset=Optional.empty, lastFetchTimestamp=-1, lastCaughtUpTimestamp=-1, hasAcknowledgedLeader=true), 1=ReplicaState(nodeId=1, endOffset=Optional.empty, lastFetchTimestamp=-1, lastCaughtUpTimestamp=-1, hasAcknowledgedLeader=false), 2=ReplicaState(nodeId=2, endOffset=Optional.empty, lastFetchTimestamp=-1, lastCaughtUpTimestamp=-1, hasAcknowledgedLeader=false)}) from CandidateState(localId=0, epoch=2, retries=2, voteStates={0=GRANTED, 1=GRANTED, 2=UNRECORDED}, highWatermark=Optional.empty, electionTimeoutMs=1557) (org.apache.kafka.raft.QuorumState)
[2024-04-29 11:01:31,582] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,583] INFO [broker-0-to-controller-forwarding-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:31,584] INFO [broker-0-to-controller-alter-partition-channel-manager]: Starting (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:31,585] INFO [broker-0-to-controller-alter-partition-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:31,601] INFO [broker-0-to-controller-directory-assignments-channel-manager]: Starting (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:31,602] INFO [broker-0-to-controller-directory-assignments-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:31,615] INFO [controller-0-to-controller-registration-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:31,682] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,783] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,799] INFO [ExpirationReaper-0-Produce]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:31,801] INFO [ExpirationReaper-0-Fetch]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:31,881] INFO [ExpirationReaper-0-DeleteRecords]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:31,883] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:31,883] INFO [ExpirationReaper-0-ElectLeader]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:31,886] INFO [ExpirationReaper-0-RemoteFetch]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:31,984] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,001] INFO [ExpirationReaper-0-Heartbeat]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:32,002] INFO [ExpirationReaper-0-Rebalance]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:32,084] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,185] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,285] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,295] INFO [QuorumController id=0] registerBroker: event failed with NotControllerException in 657 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,386] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,391] INFO Unable to read the broker epoch in /bitnami/kafka/data. (kafka.log.LogManager)
[2024-04-29 11:01:32,393] INFO [broker-0-to-controller-heartbeat-channel-manager]: Starting (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:32,394] INFO [broker-0-to-controller-heartbeat-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:32,399] INFO [QuorumController id=0] registerBroker: event failed with NotControllerException in 117 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,401] INFO [BrokerLifecycleManager id=0] Incarnation IiE1Pz-wSVKvIDICKRcQsQ of broker 0 in cluster tGotg5jFmyb2BaeIMMqDmh is now STARTING. (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:32,486] INFO [MetadataLoader id=0] initializeNewPublishers: the loader is still catching up because we still don't know the high water mark yet. (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,492] INFO [QuorumController id=0] registerBroker: event failed with NotControllerException in 102 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,494] INFO [QuorumController id=0] registerBroker: event failed with NotControllerException in 81 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,496] INFO [NodeToControllerChannelManager id=0 name=heartbeat] Client requested disconnect from node 0 (org.apache.kafka.clients.NetworkClient)
[2024-04-29 11:01:32,581] INFO [broker-0-to-controller-heartbeat-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:32,585] INFO [RaftManager id=0] High watermark set to LogOffsetMetadata(offset=1, metadata=Optional[(segmentBaseOffset=0,relativePositionInSegment=106)]) for the first time for epoch 2 based on indexOfHw 1 and voters [ReplicaState(nodeId=0, endOffset=Optional[LogOffsetMetadata(offset=1, metadata=Optional[(segmentBaseOffset=0,relativePositionInSegment=106)])], lastFetchTimestamp=-1, lastCaughtUpTimestamp=-1, hasAcknowledgedLeader=true), ReplicaState(nodeId=1, endOffset=Optional[LogOffsetMetadata(offset=1, metadata=Optional[(segmentBaseOffset=0,relativePositionInSegment=106)])], lastFetchTimestamp=1714388492582, lastCaughtUpTimestamp=1714388492582, hasAcknowledgedLeader=true), ReplicaState(nodeId=2, endOffset=Optional[LogOffsetMetadata(offset=0, metadata=Optional[(segmentBaseOffset=0,relativePositionInSegment=0)])], lastFetchTimestamp=1714388492181, lastCaughtUpTimestamp=-1, hasAcknowledgedLeader=true)] (org.apache.kafka.raft.LeaderState)
[2024-04-29 11:01:32,705] INFO [MetadataLoader id=0] initializeNewPublishers: The loader is still catching up because we have loaded up to offset -1, but the high water mark is 1 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,785] INFO [QuorumController id=0] registerBroker: event failed with NotControllerException in 126 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,786] INFO [QuorumController id=0] registerBroker: event failed with NotControllerException in 100 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,881] INFO [MetadataLoader id=0] initializeNewPublishers: The loader is still catching up because we have loaded up to offset -1, but the high water mark is 1 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,881] INFO [QuorumController id=0] registerBroker: event failed with NotControllerException in 153 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,881] INFO [ExpirationReaper-0-AlterAcls]: Starting (kafka.server.DelayedOperationPurgatory$ExpiredOperationReaper)
[2024-04-29 11:01:32,882] INFO [NodeToControllerChannelManager id=0 name=heartbeat] Client requested disconnect from node 0 (org.apache.kafka.clients.NetworkClient)
[2024-04-29 11:01:32,882] INFO [broker-0-to-controller-heartbeat-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:32,887] INFO [QuorumController id=0] Becoming the active controller at epoch 2, next write offset 1. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,888] INFO [MetadataLoader id=0] maybePublishMetadata(LOG_DELTA): The loader is still catching up because we have not loaded a controller record as of offset 0 and high water mark is 1 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,981] INFO [broker-0-to-controller-heartbeat-channel-manager]: Recorded new controller, from now on will use node kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093 (id: 0 rack: null) (kafka.server.NodeToControllerRequestThread)
[2024-04-29 11:01:32,981] INFO [MetadataLoader id=0] initializeNewPublishers: The loader finished catching up to the current high water mark of 1 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:32,992] WARN [QuorumController id=0] Performing controller activation. The metadata log appears to be empty. Appending 3 bootstrap record(s) in metadata transaction at metadata.version 3.7-IV4 from bootstrap source 'the binary bootstrap metadata file: /bitnami/kafka/data/bootstrap.checkpoint'. Setting the ZK migration state to NONE since this is a de-novo KRaft cluster. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:32,996] INFO [QuorumController id=0] Replayed BeginTransactionRecord(name='Bootstrap records') at offset 1. (org.apache.kafka.controller.OffsetControlManager)
[2024-04-29 11:01:33,081] INFO [QuorumController id=0] Replayed a FeatureLevelRecord setting metadata version to 3.7-IV4 (org.apache.kafka.controller.FeatureControlManager)
[2024-04-29 11:01:33,085] INFO [QuorumController id=0] Replayed UserScramCredentialRecord creating new entry for user1 with mechanism SCRAM_SHA_256. (org.apache.kafka.controller.ScramControlManager)
[2024-04-29 11:01:33,085] INFO [QuorumController id=0] Replayed UserScramCredentialRecord creating new entry for user1 with mechanism SCRAM_SHA_512. (org.apache.kafka.controller.ScramControlManager)
[2024-04-29 11:01:33,086] INFO [QuorumController id=0] Replayed EndTransactionRecord() at offset 6. (org.apache.kafka.controller.OffsetControlManager)
[2024-04-29 11:01:33,185] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing SnapshotGenerator with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,186] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing KRaftMetadataCachePublisher with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,186] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing FeaturesPublisher with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,186] INFO [ControllerServer id=0] Loaded new metadata Features(version=3.0-IV1, finalizedFeatures={metadata.version=1}, finalizedFeaturesEpoch=0). (org.apache.kafka.metadata.publisher.FeaturesPublisher)
[2024-04-29 11:01:33,186] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing ControllerRegistrationsPublisher with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,186] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing ControllerRegistrationManager with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,187] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing DynamicConfigPublisher controller id=0 with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,187] INFO [ControllerRegistrationManager id=0 incarnation=FsUDjHGWSlqvpAsMsesrtA] maybeSendControllerRegistration: cannot register yet because the metadata version is still 3.0-IV1, which does not support KIP-919 controller registration. (kafka.server.ControllerRegistrationManager)
[2024-04-29 11:01:33,189] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing DynamicClientQuotaPublisher controller id=0 with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,190] INFO [BrokerServer id=0] Waiting for the broker metadata publishers to be installed (kafka.server.BrokerServer)
[2024-04-29 11:01:33,190] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing ScramPublisher controller id=0 with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,191] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing DelegationTokenPublisher controller id=0 with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,194] INFO [QuorumController id=0] Replayed initial RegisterBrokerRecord for broker 2: RegisterBrokerRecord(brokerId=2, isMigratingZkBroker=false, incarnationId=WIFeiDIzSAaoIg5oOBq6-g, brokerEpoch=7, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-2.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-2.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[KsIvMjIYpSOqz-7M94ssLg]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:33,195] INFO [QuorumController id=0] Replayed initial RegisterBrokerRecord for broker 0: RegisterBrokerRecord(brokerId=0, isMigratingZkBroker=false, incarnationId=IiE1Pz-wSVKvIDICKRcQsQ, brokerEpoch=8, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[d9lo71YK9ZzacyhfbVljZQ]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:33,196] INFO [QuorumController id=0] Replayed initial RegisterBrokerRecord for broker 1: RegisterBrokerRecord(brokerId=1, isMigratingZkBroker=false, incarnationId=i7We8oJuQ5OXmi8K1v5jwA, brokerEpoch=9, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[3nW2dIcb9Z7elmqyAx1_PQ]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:33,282] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing ControllerMetadataMetricsPublisher with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,283] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing AclPublisher controller id=0 with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,284] INFO [BrokerServer id=0] Finished waiting for the broker metadata publishers to be installed (kafka.server.BrokerServer)
[2024-04-29 11:01:33,284] INFO [BrokerServer id=0] Waiting for the controller to acknowledge that we are caught up (kafka.server.BrokerServer)
[2024-04-29 11:01:33,284] INFO [MetadataLoader id=0] InitializeNewPublishers: initializing BrokerMetadataPublisher with a snapshot at offset 0 (org.apache.kafka.image.loader.MetadataLoader)
[2024-04-29 11:01:33,285] INFO [BrokerMetadataPublisher id=0] Publishing initial metadata at offset OffsetAndEpoch(offset=0, epoch=2) with metadata.version 3.0-IV1. (kafka.server.metadata.BrokerMetadataPublisher)
[2024-04-29 11:01:33,286] INFO Loading logs from log dirs ArrayBuffer(/bitnami/kafka/data) (kafka.log.LogManager)
[2024-04-29 11:01:33,292] INFO No logs found to be loaded in /bitnami/kafka/data (kafka.log.LogManager)
[2024-04-29 11:01:33,388] INFO [BrokerLifecycleManager id=0] Successfully registered broker 0 with broker epoch 8 (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:33,389] INFO Loaded 0 logs in 101ms (kafka.log.LogManager)
[2024-04-29 11:01:33,389] INFO Starting log cleanup with a period of 300000 ms. (kafka.log.LogManager)
[2024-04-29 11:01:33,392] INFO Starting log flusher with a default period of 9223372036854775807 ms. (kafka.log.LogManager)
[2024-04-29 11:01:33,501] INFO Starting the log cleaner (kafka.log.LogCleaner)
[2024-04-29 11:01:34,095] INFO [kafka-log-cleaner-thread-0]: Starting (kafka.log.LogCleaner$CleanerThread)
[2024-04-29 11:01:34,183] INFO [LogDirFailureHandler]: Starting (kafka.server.ReplicaManager$LogDirFailureHandler)
[2024-04-29 11:01:34,186] INFO [GroupCoordinator 0]: Starting up. (kafka.coordinator.group.GroupCoordinator)
[2024-04-29 11:01:34,186] INFO [AddPartitionsToTxnSenderThread-0]: Starting (kafka.server.AddPartitionsToTxnManager)
[2024-04-29 11:01:34,190] INFO [GroupCoordinator 0]: Startup complete. (kafka.coordinator.group.GroupCoordinator)
[2024-04-29 11:01:34,191] INFO [TransactionCoordinator id=0] Starting up. (kafka.coordinator.transaction.TransactionCoordinator)
[2024-04-29 11:01:34,194] INFO [TxnMarkerSenderThread-0]: Starting (kafka.coordinator.transaction.TransactionMarkerChannelManager)
[2024-04-29 11:01:34,195] INFO [TransactionCoordinator id=0] Startup complete. (kafka.coordinator.transaction.TransactionCoordinator)
[2024-04-29 11:01:34,288] INFO [QuorumController id=0] Replayed RegisterControllerRecord contaning ControllerRegistration(id=1, incarnationId=kOm2CgsKQVC-euvbsFphJQ, zkMigrationReady=false, listeners=[Endpoint(listenerName='CONTROLLER', securityProtocol=SASL_PLAINTEXT, host='kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local', port=9093)], supportedFeatures={metadata.version: 1-19}). (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,293] INFO [QuorumController id=0] Replayed RegisterBrokerRecord modifying the registration for broker 1: RegisterBrokerRecord(brokerId=1, isMigratingZkBroker=false, incarnationId=i7We8oJuQ5OXmi8K1v5jwA, brokerEpoch=13, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[3nW2dIcb9Z7elmqyAx1_PQ]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,382] INFO [ControllerServer id=0] Loaded new metadata Features(version=3.7-IV4, finalizedFeatures={metadata.version=19}, finalizedFeaturesEpoch=6). (org.apache.kafka.metadata.publisher.FeaturesPublisher)
[2024-04-29 11:01:34,382] INFO [QuorumController id=0] Replayed RegisterBrokerRecord modifying the registration for broker 2: RegisterBrokerRecord(brokerId=2, isMigratingZkBroker=false, incarnationId=WIFeiDIzSAaoIg5oOBq6-g, brokerEpoch=14, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-2.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-2.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[KsIvMjIYpSOqz-7M94ssLg]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,385] INFO [ControllerRegistrationManager id=0 incarnation=FsUDjHGWSlqvpAsMsesrtA] sendControllerRegistration: attempting to send ControllerRegistrationRequestData(controllerId=0, incarnationId=FsUDjHGWSlqvpAsMsesrtA, zkMigrationReady=false, listeners=[Listener(name='CONTROLLER', host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9093, securityProtocol=2)], features=[Feature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)]) (kafka.server.ControllerRegistrationManager)
[2024-04-29 11:01:34,385] INFO [BrokerMetadataPublisher id=0] Updating metadata.version to 19 at offset OffsetAndEpoch(offset=6, epoch=2). (kafka.server.metadata.BrokerMetadataPublisher)
[2024-04-29 11:01:34,389] INFO [QuorumController id=0] Replayed RegisterControllerRecord contaning ControllerRegistration(id=2, incarnationId=7Jz23xKrS5yUjMfx7mXyGg, zkMigrationReady=false, listeners=[Endpoint(listenerName='CONTROLLER', securityProtocol=SASL_PLAINTEXT, host='kafka-controller-2.kafka-controller-headless.pre-logging.svc.cluster.local', port=9093)], supportedFeatures={metadata.version: 1-19}). (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,481] INFO [BrokerMetadataPublisher id=0] Resending BrokerRegistration with existing incarnation-id to inform the controller about log directories in the broker following metadata update: previousMetadataVersion: 3.0-IV1 newMetadataVersion: 3.7-IV4 (kafka.server.metadata.BrokerMetadataPublisher)
[2024-04-29 11:01:34,482] INFO [QuorumController id=0] Replayed RegisterControllerRecord contaning ControllerRegistration(id=0, incarnationId=FsUDjHGWSlqvpAsMsesrtA, zkMigrationReady=false, listeners=[Endpoint(listenerName='CONTROLLER', securityProtocol=SASL_PLAINTEXT, host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9093)], supportedFeatures={metadata.version: 1-19}). (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,496] INFO [QuorumController id=0] Replayed RegisterBrokerRecord modifying the registration for broker 1: RegisterBrokerRecord(brokerId=1, isMigratingZkBroker=false, incarnationId=i7We8oJuQ5OXmi8K1v5jwA, brokerEpoch=17, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[3nW2dIcb9Z7elmqyAx1_PQ]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,582] INFO [QuorumController id=0] Replayed RegisterBrokerRecord modifying the registration for broker 0: RegisterBrokerRecord(brokerId=0, isMigratingZkBroker=false, incarnationId=IiE1Pz-wSVKvIDICKRcQsQ, brokerEpoch=18, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[d9lo71YK9ZzacyhfbVljZQ]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,601] INFO [ControllerRegistrationManager id=0 incarnation=FsUDjHGWSlqvpAsMsesrtA] Our registration has been persisted to the metadata log. (kafka.server.ControllerRegistrationManager)
[2024-04-29 11:01:34,601] INFO [ControllerRegistrationManager id=0 incarnation=FsUDjHGWSlqvpAsMsesrtA] RegistrationResponseHandler: controller acknowledged ControllerRegistrationRequest. (kafka.server.ControllerRegistrationManager)
[2024-04-29 11:01:34,602] INFO [QuorumController id=0] processBrokerHeartbeat: event failed with StaleBrokerEpochException in 136 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:34,683] INFO [BrokerLifecycleManager id=0] Successfully registered broker 0 with broker epoch 18 (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:34,685] INFO [QuorumController id=0] Replayed RegisterBrokerRecord modifying the registration for broker 0: RegisterBrokerRecord(brokerId=0, isMigratingZkBroker=false, incarnationId=IiE1Pz-wSVKvIDICKRcQsQ, brokerEpoch=20, endPoints=[BrokerEndpoint(name='INTERNAL', host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9094, securityProtocol=2), BrokerEndpoint(name='CLIENT', host='kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local', port=9092, securityProtocol=2)], features=[BrokerFeature(name='metadata.version', minSupportedVersion=1, maxSupportedVersion=19)], rack=null, fenced=true, inControlledShutdown=false, logDirs=[d9lo71YK9ZzacyhfbVljZQ]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,730] INFO [BrokerLifecycleManager id=0] Successfully registered broker 0 with broker epoch 20 (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:34,731] INFO [QuorumController id=0] processBrokerHeartbeat: event failed with StaleBrokerEpochException in 70 microseconds. (org.apache.kafka.controller.QuorumController)
[2024-04-29 11:01:34,733] WARN [BrokerLifecycleManager id=0] Broker 0 sent a heartbeat request but received error STALE_BROKER_EPOCH. (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:34,735] INFO [BrokerLifecycleManager id=0] The broker has caught up. Transitioning from STARTING to RECOVERY. (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:34,735] INFO [BrokerServer id=0] Finished waiting for the controller to acknowledge that we are caught up (kafka.server.BrokerServer)
[2024-04-29 11:01:34,736] INFO [BrokerServer id=0] Waiting for the initial broker metadata update to be published (kafka.server.BrokerServer)
[2024-04-29 11:01:34,736] INFO [BrokerServer id=0] Finished waiting for the initial broker metadata update to be published (kafka.server.BrokerServer)
[2024-04-29 11:01:34,738] INFO KafkaConfig values: 
        advertised.listeners = CLIENT://kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9092,INTERNAL://kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9094
        alter.config.policy.class.name = null
        alter.log.dirs.replication.quota.window.num = 11
        alter.log.dirs.replication.quota.window.size.seconds = 1
        authorizer.class.name = 
        auto.create.topics.enable = true
        auto.include.jmx.reporter = true
        auto.leader.rebalance.enable = true
        background.threads = 10
        broker.heartbeat.interval.ms = 2000
        broker.id = 0
        broker.id.generation.enable = true
        broker.rack = null
        broker.session.timeout.ms = 9000
        client.quota.callback.class = null
        compression.type = producer
        connection.failed.authentication.delay.ms = 100
        connections.max.idle.ms = 600000
        connections.max.reauth.ms = 0
        control.plane.listener.name = null
        controlled.shutdown.enable = true
        controlled.shutdown.max.retries = 3
        controlled.shutdown.retry.backoff.ms = 5000
        controller.listener.names = CONTROLLER
        controller.quorum.append.linger.ms = 25
        controller.quorum.election.backoff.max.ms = 1000
        controller.quorum.election.timeout.ms = 1000
        controller.quorum.fetch.timeout.ms = 2000
        controller.quorum.request.timeout.ms = 2000
        controller.quorum.retry.backoff.ms = 20
        controller.quorum.voters = [0@kafka-controller-0.kafka-controller-headless.pre-logging.svc.cluster.local:9093, 1@kafka-controller-1.kafka-controller-headless.pre-logging.svc.cluster.local:9093, 2@kafka-controller-2.kafka-controller-headless.pre-logging.svc.cluster.local:9093]
        controller.quota.window.num = 11
        controller.quota.window.size.seconds = 1
        controller.socket.timeout.ms = 30000
        create.topic.policy.class.name = null
        default.replication.factor = 1
        delegation.token.expiry.check.interval.ms = 3600000
        delegation.token.expiry.time.ms = 86400000
        delegation.token.master.key = null
        delegation.token.max.lifetime.ms = 604800000
        delegation.token.secret.key = null
        delete.records.purgatory.purge.interval.requests = 1
        delete.topic.enable = true
        early.start.listeners = null
        eligible.leader.replicas.enable = false
        fetch.max.bytes = 57671680
        fetch.purgatory.purge.interval.requests = 1000
        group.consumer.assignors = [org.apache.kafka.coordinator.group.assignor.UniformAssignor, org.apache.kafka.coordinator.group.assignor.RangeAssignor]
        group.consumer.heartbeat.interval.ms = 5000
        group.consumer.max.heartbeat.interval.ms = 15000
        group.consumer.max.session.timeout.ms = 60000
        group.consumer.max.size = 2147483647
        group.consumer.min.heartbeat.interval.ms = 5000
        group.consumer.min.session.timeout.ms = 45000
        group.consumer.session.timeout.ms = 45000
        group.coordinator.new.enable = false
        group.coordinator.rebalance.protocols = [classic]
        group.coordinator.threads = 1
        group.initial.rebalance.delay.ms = 3000
        group.max.session.timeout.ms = 1800000
        group.max.size = 2147483647
        group.min.session.timeout.ms = 6000
        initial.broker.registration.timeout.ms = 60000
        inter.broker.listener.name = INTERNAL
        inter.broker.protocol.version = 3.7-IV4
        kafka.metrics.polling.interval.secs = 10
        kafka.metrics.reporters = []
        leader.imbalance.check.interval.seconds = 300
        leader.imbalance.per.broker.percentage = 10
        listener.security.protocol.map = CLIENT:SASL_PLAINTEXT,INTERNAL:SASL_PLAINTEXT,CONTROLLER:SASL_PLAINTEXT
        listeners = CLIENT://:9092,INTERNAL://:9094,CONTROLLER://:9093
        log.cleaner.backoff.ms = 15000
        log.cleaner.dedupe.buffer.size = 134217728
        log.cleaner.delete.retention.ms = 86400000
        log.cleaner.enable = true
        log.cleaner.io.buffer.load.factor = 0.9
        log.cleaner.io.buffer.size = 524288
        log.cleaner.io.max.bytes.per.second = 1.7976931348623157E308
        log.cleaner.max.compaction.lag.ms = 9223372036854775807
        log.cleaner.min.cleanable.ratio = 0.5
        log.cleaner.min.compaction.lag.ms = 0
        log.cleaner.threads = 1
        log.cleanup.policy = [delete]
        log.dir = /bitnami/kafka/data
        log.dirs = null
        log.flush.interval.messages = 9223372036854775807
        log.flush.interval.ms = null
        log.flush.offset.checkpoint.interval.ms = 60000
        log.flush.scheduler.interval.ms = 9223372036854775807
        log.flush.start.offset.checkpoint.interval.ms = 60000
        log.index.interval.bytes = 4096
        log.index.size.max.bytes = 10485760
        log.local.retention.bytes = -2
        log.local.retention.ms = -2
        log.message.downconversion.enable = true
        log.message.format.version = 3.0-IV1
        log.message.timestamp.after.max.ms = 9223372036854775807
        log.message.timestamp.before.max.ms = 9223372036854775807
        log.message.timestamp.difference.max.ms = 9223372036854775807
        log.message.timestamp.type = CreateTime
        log.preallocate = false
        log.retention.bytes = -1
        log.retention.check.interval.ms = 300000
        log.retention.hours = 168
        log.retention.minutes = null
        log.retention.ms = null
        log.roll.hours = 168
        log.roll.jitter.hours = 0
        log.roll.jitter.ms = null
        log.roll.ms = null
        log.segment.bytes = 1073741824
        log.segment.delete.delay.ms = 60000
        max.connection.creation.rate = 2147483647
        max.connections = 2147483647
        max.connections.per.ip = 2147483647
        max.connections.per.ip.overrides = 
        max.incremental.fetch.session.cache.slots = 1000
        message.max.bytes = 1048588
        metadata.log.dir = null
        metadata.log.max.record.bytes.between.snapshots = 20971520
        metadata.log.max.snapshot.interval.ms = 3600000
        metadata.log.segment.bytes = 1073741824
        metadata.log.segment.min.bytes = 8388608
        metadata.log.segment.ms = 604800000
        metadata.max.idle.interval.ms = 500
        metadata.max.retention.bytes = 104857600
        metadata.max.retention.ms = 604800000
        metric.reporters = []
        metrics.num.samples = 2
        metrics.recording.level = INFO
        metrics.sample.window.ms = 30000
        min.insync.replicas = 1
        node.id = 0
        num.io.threads = 8
        num.network.threads = 3
        num.partitions = 1
        num.recovery.threads.per.data.dir = 1
        num.replica.alter.log.dirs.threads = null
        num.replica.fetchers = 1
        offset.metadata.max.bytes = 4096
        offsets.commit.required.acks = -1
        offsets.commit.timeout.ms = 5000
        offsets.load.buffer.size = 5242880
        offsets.retention.check.interval.ms = 600000
        offsets.retention.minutes = 10080
        offsets.topic.compression.codec = 0
        offsets.topic.num.partitions = 50
        offsets.topic.replication.factor = 3
        offsets.topic.segment.bytes = 104857600
        password.encoder.cipher.algorithm = AES/CBC/PKCS5Padding
        password.encoder.iterations = 4096
        password.encoder.key.length = 128
        password.encoder.keyfactory.algorithm = null
        password.encoder.old.secret = null
        password.encoder.secret = null
        principal.builder.class = class org.apache.kafka.common.security.authenticator.DefaultKafkaPrincipalBuilder
        process.roles = [controller, broker]
        producer.id.expiration.check.interval.ms = 600000
        producer.id.expiration.ms = 86400000
        producer.purgatory.purge.interval.requests = 1000
        queued.max.request.bytes = -1
        queued.max.requests = 500
        quota.window.num = 11
        quota.window.size.seconds = 1
        remote.log.index.file.cache.total.size.bytes = 1073741824
        remote.log.manager.task.interval.ms = 30000
        remote.log.manager.task.retry.backoff.max.ms = 30000
        remote.log.manager.task.retry.backoff.ms = 500
        remote.log.manager.task.retry.jitter = 0.2
        remote.log.manager.thread.pool.size = 10
        remote.log.metadata.custom.metadata.max.bytes = 128
        remote.log.metadata.manager.class.name = org.apache.kafka.server.log.remote.metadata.storage.TopicBasedRemoteLogMetadataManager
        remote.log.metadata.manager.class.path = null
        remote.log.metadata.manager.impl.prefix = rlmm.config.
        remote.log.metadata.manager.listener.name = null
        remote.log.reader.max.pending.tasks = 100
        remote.log.reader.threads = 10
        remote.log.storage.manager.class.name = null
        remote.log.storage.manager.class.path = null
        remote.log.storage.manager.impl.prefix = rsm.config.
        remote.log.storage.system.enable = false
        replica.fetch.backoff.ms = 1000
        replica.fetch.max.bytes = 1048576
        replica.fetch.min.bytes = 1
        replica.fetch.response.max.bytes = 10485760
        replica.fetch.wait.max.ms = 500
        replica.high.watermark.checkpoint.interval.ms = 5000
        replica.lag.time.max.ms = 30000
        replica.selector.class = null
        replica.socket.receive.buffer.bytes = 65536
        replica.socket.timeout.ms = 30000
        replication.quota.window.num = 11
        replication.quota.window.size.seconds = 1
        request.timeout.ms = 30000
        reserved.broker.max.id = 1000
        sasl.client.callback.handler.class = null
        sasl.enabled.mechanisms = [PLAIN, SCRAM-SHA-256, SCRAM-SHA-512]
        sasl.jaas.config = null
        sasl.kerberos.kinit.cmd = /usr/bin/kinit
        sasl.kerberos.min.time.before.relogin = 60000
        sasl.kerberos.principal.to.local.rules = [DEFAULT]
        sasl.kerberos.service.name = null
        sasl.kerberos.ticket.renew.jitter = 0.05
        sasl.kerberos.ticket.renew.window.factor = 0.8
        sasl.login.callback.handler.class = null
        sasl.login.class = null
        sasl.login.connect.timeout.ms = null
        sasl.login.read.timeout.ms = null
        sasl.login.refresh.buffer.seconds = 300
        sasl.login.refresh.min.period.seconds = 60
        sasl.login.refresh.window.factor = 0.8
        sasl.login.refresh.window.jitter = 0.05
        sasl.login.retry.backoff.max.ms = 10000
        sasl.login.retry.backoff.ms = 100
        sasl.mechanism.controller.protocol = PLAIN
        sasl.mechanism.inter.broker.protocol = PLAIN
        sasl.oauthbearer.clock.skew.seconds = 30
        sasl.oauthbearer.expected.audience = null
        sasl.oauthbearer.expected.issuer = null
        sasl.oauthbearer.jwks.endpoint.refresh.ms = 3600000
        sasl.oauthbearer.jwks.endpoint.retry.backoff.max.ms = 10000
        sasl.oauthbearer.jwks.endpoint.retry.backoff.ms = 100
        sasl.oauthbearer.jwks.endpoint.url = null
        sasl.oauthbearer.scope.claim.name = scope
        sasl.oauthbearer.sub.claim.name = sub
        sasl.oauthbearer.token.endpoint.url = null
        sasl.server.callback.handler.class = null
        sasl.server.max.receive.size = 524288
        security.inter.broker.protocol = PLAINTEXT
        security.providers = null
        server.max.startup.time.ms = 9223372036854775807
        socket.connection.setup.timeout.max.ms = 30000
        socket.connection.setup.timeout.ms = 10000
        socket.listen.backlog.size = 50
        socket.receive.buffer.bytes = 102400
        socket.request.max.bytes = 104857600
        socket.send.buffer.bytes = 102400
        ssl.allow.dn.changes = false
        ssl.allow.san.changes = false
        ssl.cipher.suites = []
        ssl.client.auth = none
        ssl.enabled.protocols = [TLSv1.2, TLSv1.3]
        ssl.endpoint.identification.algorithm = https
        ssl.engine.factory.class = null
        ssl.key.password = null
        ssl.keymanager.algorithm = SunX509
        ssl.keystore.certificate.chain = null
        ssl.keystore.key = null
        ssl.keystore.location = null
        ssl.keystore.password = null
        ssl.keystore.type = JKS
        ssl.principal.mapping.rules = DEFAULT
        ssl.protocol = TLSv1.3
        ssl.provider = null
        ssl.secure.random.implementation = null
        ssl.trustmanager.algorithm = PKIX
        ssl.truststore.certificates = null
        ssl.truststore.location = null
        ssl.truststore.password = null
        ssl.truststore.type = JKS
        telemetry.max.bytes = 1048576
        transaction.abort.timed.out.transaction.cleanup.interval.ms = 10000
        transaction.max.timeout.ms = 900000
        transaction.partition.verification.enable = true
        transaction.remove.expired.transaction.cleanup.interval.ms = 3600000
        transaction.state.log.load.buffer.size = 5242880
        transaction.state.log.min.isr = 2
        transaction.state.log.num.partitions = 50
        transaction.state.log.replication.factor = 3
        transaction.state.log.segment.bytes = 104857600
        transactional.id.expiration.ms = 604800000
        unclean.leader.election.enable = false
        unstable.api.versions.enable = false
        unstable.metadata.versions.enable = false
        zookeeper.clientCnxnSocket = null
        zookeeper.connect = null
        zookeeper.connection.timeout.ms = null
        zookeeper.max.in.flight.requests = 10
        zookeeper.metadata.migration.enable = false
        zookeeper.metadata.migration.min.batch.size = 200
        zookeeper.session.timeout.ms = 18000
        zookeeper.set.acl = false
        zookeeper.ssl.cipher.suites = null
        zookeeper.ssl.client.enable = false
        zookeeper.ssl.crl.enable = false
        zookeeper.ssl.enabled.protocols = null
        zookeeper.ssl.endpoint.identification.algorithm = HTTPS
        zookeeper.ssl.keystore.location = null
        zookeeper.ssl.keystore.password = null
        zookeeper.ssl.keystore.type = null
        zookeeper.ssl.ocsp.enable = false
        zookeeper.ssl.protocol = TLSv1.2
        zookeeper.ssl.truststore.location = null
        zookeeper.ssl.truststore.password = null
        zookeeper.ssl.truststore.type = null
 (kafka.server.KafkaConfig)
[2024-04-29 11:01:34,782] INFO [BrokerLifecycleManager id=0] The broker is in RECOVERY. (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:34,783] INFO [QuorumController id=0] The request from broker 1 to unfence has been granted because it has caught up with the offset of its register broker record 17. (org.apache.kafka.controller.BrokerHeartbeatManager)
[2024-04-29 11:01:34,788] INFO [BrokerServer id=0] Waiting for the broker to be unfenced (kafka.server.BrokerServer)
[2024-04-29 11:01:34,796] INFO [QuorumController id=0] Replayed BrokerRegistrationChangeRecord modifying the registration for broker 1: BrokerRegistrationChangeRecord(brokerId=1, brokerEpoch=17, fenced=-1, inControlledShutdown=0, logDirs=[]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,796] INFO [QuorumController id=0] The request from broker 0 to unfence has been granted because it has caught up with the offset of its register broker record 20. (org.apache.kafka.controller.BrokerHeartbeatManager)
[2024-04-29 11:01:34,797] INFO [QuorumController id=0] Replayed BrokerRegistrationChangeRecord modifying the registration for broker 0: BrokerRegistrationChangeRecord(brokerId=0, brokerEpoch=20, fenced=-1, inControlledShutdown=0, logDirs=[]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,918] INFO [BrokerLifecycleManager id=0] The broker has been unfenced. Transitioning from RECOVERY to RUNNING. (kafka.server.BrokerLifecycleManager)
[2024-04-29 11:01:34,981] INFO [BrokerServer id=0] Finished waiting for the broker to be unfenced (kafka.server.BrokerServer)
[2024-04-29 11:01:34,981] INFO [QuorumController id=0] The request from broker 2 to unfence has been granted because it has caught up with the offset of its register broker record 14. (org.apache.kafka.controller.BrokerHeartbeatManager)
[2024-04-29 11:01:34,981] INFO [QuorumController id=0] Replayed BrokerRegistrationChangeRecord modifying the registration for broker 2: BrokerRegistrationChangeRecord(brokerId=2, brokerEpoch=14, fenced=-1, inControlledShutdown=0, logDirs=[]) (org.apache.kafka.controller.ClusterControlManager)
[2024-04-29 11:01:34,982] INFO authorizerStart completed for endpoint INTERNAL. Endpoint is now READY. (org.apache.kafka.server.network.EndpointReadyFutures)
[2024-04-29 11:01:34,982] INFO authorizerStart completed for endpoint CLIENT. Endpoint is now READY. (org.apache.kafka.server.network.EndpointReadyFutures)
[2024-04-29 11:01:34,982] INFO [SocketServer listenerType=BROKER, nodeId=0] Enabling request processing. (kafka.network.SocketServer)
[2024-04-29 11:01:34,983] INFO Awaiting socket connections on 0.0.0.0:9092. (kafka.network.DataPlaneAcceptor)
[2024-04-29 11:01:34,984] INFO Awaiting socket connections on 0.0.0.0:9094. (kafka.network.DataPlaneAcceptor)
[2024-04-29 11:01:34,987] INFO [BrokerServer id=0] Waiting for all of the authorizer futures to be completed (kafka.server.BrokerServer)
[2024-04-29 11:01:34,987] INFO [BrokerServer id=0] Finished waiting for all of the authorizer futures to be completed (kafka.server.BrokerServer)
[2024-04-29 11:01:34,987] INFO [BrokerServer id=0] Waiting for all of the SocketServer Acceptors to be started (kafka.server.BrokerServer)
[2024-04-29 11:01:34,987] INFO [BrokerServer id=0] Finished waiting for all of the SocketServer Acceptors to be started (kafka.server.BrokerServer)
[2024-04-29 11:01:34,987] INFO [BrokerServer id=0] Transition from STARTING to STARTED (kafka.server.BrokerServer)
[2024-04-29 11:01:34,988] INFO Kafka version: 3.7.0 (org.apache.kafka.common.utils.AppInfoParser)
[2024-04-29 11:01:34,988] INFO Kafka commitId: 2ae524ed625438c5 (org.apache.kafka.common.utils.AppInfoParser)
[2024-04-29 11:01:34,988] INFO Kafka startTimeMs: 1714388494987 (org.apache.kafka.common.utils.AppInfoParser)
[2024-04-29 11:01:34,990] INFO [KafkaRaftServer nodeId=0] Kafka Server started (kafka.server.KafkaRaftServer)

And I not getting the Failed authentication .... message.

You need to wait for more than 10 minutes before it will appear. It won't appear when it's just started

from charts.

rafariossaa avatar rafariossaa commented on May 25, 2024

I waited 40 minutes and no errors appeared:

$ kubectl get pods -n pre-logging 
NAME                 READY   STATUS    RESTARTS   AGE
kafka-controller-0   1/1     Running   0          39m
kafka-controller-1   1/1     Running   0          39m
kafka-controller-2   1/1     Running   0          39m


$ kubectl logs -n pre-logging kafka-controller-0
...
(kafka.server.KafkaConfig)
[2024-05-09 07:28:53,806] INFO [BrokerLifecycleManager id=0] The broker is in RECOVERY. (kafka.server.BrokerLifecycleManager)
[2024-05-09 07:28:53,806] INFO [BrokerServer id=0] Waiting for the broker to be unfenced (kafka.server.BrokerServer)
[2024-05-09 07:28:53,891] INFO [BrokerLifecycleManager id=0] The broker has been unfenced. Transitioning from RECOVERY to RUNNING. (kafka.server.BrokerLifecycleManager)
[2024-05-09 07:28:53,891] INFO [BrokerServer id=0] Finished waiting for the broker to be unfenced (kafka.server.BrokerServer)
[2024-05-09 07:28:53,892] INFO authorizerStart completed for endpoint INTERNAL. Endpoint is now READY. (org.apache.kafka.server.network.EndpointReadyFutures)
[2024-05-09 07:28:53,892] INFO authorizerStart completed for endpoint CLIENT. Endpoint is now READY. (org.apache.kafka.server.network.EndpointReadyFutures)
[2024-05-09 07:28:53,892] INFO [SocketServer listenerType=BROKER, nodeId=0] Enabling request processing. (kafka.network.SocketServer)
[2024-05-09 07:28:53,893] INFO Awaiting socket connections on 0.0.0.0:9092. (kafka.network.DataPlaneAcceptor)
[2024-05-09 07:28:53,894] INFO Awaiting socket connections on 0.0.0.0:9094. (kafka.network.DataPlaneAcceptor)
[2024-05-09 07:28:53,897] INFO [BrokerServer id=0] Waiting for all of the authorizer futures to be completed (kafka.server.BrokerServer)
[2024-05-09 07:28:53,897] INFO [BrokerServer id=0] Finished waiting for all of the authorizer futures to be completed (kafka.server.BrokerServer)
[2024-05-09 07:28:53,897] INFO [BrokerServer id=0] Waiting for all of the SocketServer Acceptors to be started (kafka.server.BrokerServer)
[2024-05-09 07:28:53,897] INFO [BrokerServer id=0] Finished waiting for all of the SocketServer Acceptors to be started (kafka.server.BrokerServer)
[2024-05-09 07:28:53,897] INFO [BrokerServer id=0] Transition from STARTING to STARTED (kafka.server.BrokerServer)
[2024-05-09 07:28:53,898] INFO Kafka version: 3.7.0 (org.apache.kafka.common.utils.AppInfoParser)
[2024-05-09 07:28:53,898] INFO Kafka commitId: 2ae524ed625438c5 (org.apache.kafka.common.utils.AppInfoParser)
[2024-05-09 07:28:53,898] INFO Kafka startTimeMs: 1715239733897 (org.apache.kafka.common.utils.AppInfoParser)
[2024-05-09 07:28:53,900] INFO [KafkaRaftServer nodeId=0] Kafka Server started (kafka.server.KafkaRaftServer)
[2024-05-09 07:28:53,905] INFO [QuorumController id=0] Replayed BrokerRegistrationChangeRecord modifying the registration for broker 0: BrokerRegistrationChangeRecord(brokerId=0, brokerEpoch=17, fenced=-1, inControlledShutdown=0, logDirs=[]) (org.apache.kafka.controller.ClusterControlManager)
[2024-05-09 07:28:54,240] INFO [QuorumController id=0] Replayed BrokerRegistrationChangeRecord modifying the registration for broker 1: BrokerRegistrationChangeRecord(brokerId=1, brokerEpoch=18, fenced=-1, inControlledShutdown=0, logDirs=[]) (org.apache.kafka.controller.ClusterControlManager)
[2024-05-09 07:38:51,290] INFO [RaftManager id=0] Node 1 disconnected. (org.apache.kafka.clients.NetworkClient)
[2024-05-09 07:38:53,682] INFO [NodeToControllerChannelManager id=0 name=registration] Node 2 disconnected. (org.apache.kafka.clients.NetworkClient)

from charts.

SanthappanavaraShruthi avatar SanthappanavaraShruthi commented on May 25, 2024

We also have the similar setup with 3 brokers.
I see exactly same error in one of the broker and other 2 seems to be fine.

[2024-05-09 10:27:14,590] INFO [SocketServer listenerType=BROKER, nodeId=2] Failed authentication with /xx.x.x.xxx (channelId=xx.x.x.xx:9094-xx.x.x.xxx:59288-261) (Unexpected Kafka request of type METADATA during SASL handshake.) (org.apache.kafka.common.network.Selector)
[2024-05-09 10:27:24,589] INFO [SocketServer listenerType=BROKER, nodeId=2] Failed authentication with /xx.x.x.xxx (channelId=xx.x.x.xx:9094-xx.x.x.xxx:51848-263) (Unexpected Kafka request of type METADATA during SASL handshake.) (org.apache.kafka.common.network.Selector)

from charts.

zjf88865 avatar zjf88865 commented on May 25, 2024

We also have the similar setup with 3 brokers. I see exactly same error in one of the broker and other 2 seems to be fine.

[2024-05-09 10:27:14,590] INFO [SocketServer listenerType=BROKER, nodeId=2] Failed authentication with /xx.x.x.xxx (channelId=xx.x.x.xx:9094-xx.x.x.xxx:59288-261) (Unexpected Kafka request of type METADATA during SASL handshake.) (org.apache.kafka.common.network.Selector) [2024-05-09 10:27:24,589] INFO [SocketServer listenerType=BROKER, nodeId=2] Failed authentication with /xx.x.x.xxx (channelId=xx.x.x.xx:9094-xx.x.x.xxx:51848-263) (Unexpected Kafka request of type METADATA during SASL handshake.) (org.apache.kafka.common.network.Selector)

Yes, I have raised this issue for a long time, but no one has dealt with it. If security is a concern, configurable parameters should be provided. However, this project has not been maintained, and upgrading the Helm repository version rashly will bring huge losses. The key issue has been raised for a long time but has not been resolved. My program is no longer able to link to my Kafka, but fortunately it is only in my testing environment, otherwise it will cause huge losses

from charts.

zjf88865 avatar zjf88865 commented on May 25, 2024

I waited 40 minutes and no errors appeared:

$ kubectl get pods -n pre-logging 
NAME                 READY   STATUS    RESTARTS   AGE
kafka-controller-0   1/1     Running   0          39m
kafka-controller-1   1/1     Running   0          39m
kafka-controller-2   1/1     Running   0          39m


$ kubectl logs -n pre-logging kafka-controller-0
...
(kafka.server.KafkaConfig)
[2024-05-09 07:28:53,806] INFO [BrokerLifecycleManager id=0] The broker is in RECOVERY. (kafka.server.BrokerLifecycleManager)
[2024-05-09 07:28:53,806] INFO [BrokerServer id=0] Waiting for the broker to be unfenced (kafka.server.BrokerServer)
[2024-05-09 07:28:53,891] INFO [BrokerLifecycleManager id=0] The broker has been unfenced. Transitioning from RECOVERY to RUNNING. (kafka.server.BrokerLifecycleManager)
[2024-05-09 07:28:53,891] INFO [BrokerServer id=0] Finished waiting for the broker to be unfenced (kafka.server.BrokerServer)
[2024-05-09 07:28:53,892] INFO authorizerStart completed for endpoint INTERNAL. Endpoint is now READY. (org.apache.kafka.server.network.EndpointReadyFutures)
[2024-05-09 07:28:53,892] INFO authorizerStart completed for endpoint CLIENT. Endpoint is now READY. (org.apache.kafka.server.network.EndpointReadyFutures)
[2024-05-09 07:28:53,892] INFO [SocketServer listenerType=BROKER, nodeId=0] Enabling request processing. (kafka.network.SocketServer)
[2024-05-09 07:28:53,893] INFO Awaiting socket connections on 0.0.0.0:9092. (kafka.network.DataPlaneAcceptor)
[2024-05-09 07:28:53,894] INFO Awaiting socket connections on 0.0.0.0:9094. (kafka.network.DataPlaneAcceptor)
[2024-05-09 07:28:53,897] INFO [BrokerServer id=0] Waiting for all of the authorizer futures to be completed (kafka.server.BrokerServer)
[2024-05-09 07:28:53,897] INFO [BrokerServer id=0] Finished waiting for all of the authorizer futures to be completed (kafka.server.BrokerServer)
[2024-05-09 07:28:53,897] INFO [BrokerServer id=0] Waiting for all of the SocketServer Acceptors to be started (kafka.server.BrokerServer)
[2024-05-09 07:28:53,897] INFO [BrokerServer id=0] Finished waiting for all of the SocketServer Acceptors to be started (kafka.server.BrokerServer)
[2024-05-09 07:28:53,897] INFO [BrokerServer id=0] Transition from STARTING to STARTED (kafka.server.BrokerServer)
[2024-05-09 07:28:53,898] INFO Kafka version: 3.7.0 (org.apache.kafka.common.utils.AppInfoParser)
[2024-05-09 07:28:53,898] INFO Kafka commitId: 2ae524ed625438c5 (org.apache.kafka.common.utils.AppInfoParser)
[2024-05-09 07:28:53,898] INFO Kafka startTimeMs: 1715239733897 (org.apache.kafka.common.utils.AppInfoParser)
[2024-05-09 07:28:53,900] INFO [KafkaRaftServer nodeId=0] Kafka Server started (kafka.server.KafkaRaftServer)
[2024-05-09 07:28:53,905] INFO [QuorumController id=0] Replayed BrokerRegistrationChangeRecord modifying the registration for broker 0: BrokerRegistrationChangeRecord(brokerId=0, brokerEpoch=17, fenced=-1, inControlledShutdown=0, logDirs=[]) (org.apache.kafka.controller.ClusterControlManager)
[2024-05-09 07:28:54,240] INFO [QuorumController id=0] Replayed BrokerRegistrationChangeRecord modifying the registration for broker 1: BrokerRegistrationChangeRecord(brokerId=1, brokerEpoch=18, fenced=-1, inControlledShutdown=0, logDirs=[]) (org.apache.kafka.controller.ClusterControlManager)
[2024-05-09 07:38:51,290] INFO [RaftManager id=0] Node 1 disconnected. (org.apache.kafka.clients.NetworkClient)
[2024-05-09 07:38:53,682] INFO [NodeToControllerChannelManager id=0 name=registration] Node 2 disconnected. (org.apache.kafka.clients.NetworkClient)

Many people have mentioned this serious bug in the comments section now. Please help to handle it, as it has caused us some friction losses

from charts.

Related Issues (20)

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.