[Bug]: Kafka operator keeps restarting kafka pods often with log entry "logging needs to be reconfigured."

[tkorrapati1]

Bug Description

Kafka operator keeps restarting kafka pods often with log entry "logging needs to be reconfigured." this is causing NotLeaderOrFollowerException in clients connecting to kafka.

I have no overrides in my kafka CR for logging.

ERROR In client:

org.apache.kafka.common.errors.NotLeaderOrFollowerException: For requests intended only for the leader, this error indicates that the broker is not the current leader. For requests intended for any replica, this error indicates that the broker is not a replica of the topic partition.. Going to request metadata update now

ERROR In operator logs:

2023-07-05 19:53:01 DEBUG KafkaRoller:506 - Reconciliation #8726(timer) Kafka(test-dev/test-cluster): Pod {test-cluster-kafka-2} logging needs to be reconfigured.

K8s resources CR and CM

apiVersion: kafka.strimzi.io/v1beta2
kind: Kafka
metadata:
  annotations:
    meta.helm.sh/release-name: kafka-testapp-operator
    meta.helm.sh/release-namespace: aodapn-kafka-testapp-dev
  creationTimestamp: "2023-03-01T23:17:49Z"
  generation: 4
  labels:
    app.kubernetes.io/managed-by: Helm
    manged-by: fournines
  name: testapp-cluster
  namespace: aodapn-kafka-testapp-dev
  resourceVersion: "353938583"
  uid: fb7c7497-c47b-484a-9424-eef365d2f6b4
spec:
  clientsCa:
    generateCertificateAuthority: true
  clusterCa:
    generateCertificateAuthority: true
  entityOperator:
    template:
      pod:
        affinity:
          nodeAffinity:
            requiredDuringSchedulingIgnoredDuringExecution:
              nodeSelectorTerms:
              - matchExpressions:
                - key: node_pool
                  operator: In
                  values:
                  - aodapn-pool-blue
          podAntiAffinity:
            requiredDuringSchedulingIgnoredDuringExecution:
            - labelSelector:
                matchExpressions:
                - key: strimzi.io/name
                  operator: In
                  values:
                  - testapp-cluster-kafka
              topologyKey: kubernetes.io/hostname
        tolerations:
        - effect: NoSchedule
          key: dedicated
          operator: Equal
          value: appneta
    topicOperator: {}
    userOperator: {}
  kafka:
    authorization:
      type: simple
    config:
      default.replication.factor: 3
      inter.broker.protocol.version: "3.2"
      log.message.format.version: "3.2"
    listeners:
    - name: plain
      port: 9092
      tls: false
      type: internal
    - authentication:
        type: scram-sha-512
      configuration:
        bootstrap:
          alternativeNames:
          - kafka-testapp.sl.saasdev.example.net
          annotations:
            external-dns.alpha.kubernetes.io/hostname: kafka-testapp.sl.saasdev.example.net.
            external-dns.alpha.kubernetes.io/ttl: "60"
        brokerCertChainAndKey:
          certificate: tls.crt
          key: tls.key
          secretName: manual-sm-certificate-sl-saasdev-example-net
        brokers:
        - advertisedHost: kafka-testapp-0.sl.saasdev.example.net
          annotations:
            external-dns.alpha.kubernetes.io/hostname: kafka-testapp-0.sl.saasdev.example.net.
            external-dns.alpha.kubernetes.io/ttl: "60"
          broker: 0
        - advertisedHost: kafka-testapp-1.sl.saasdev.example.net
          annotations:
            external-dns.alpha.kubernetes.io/hostname: kafka-testapp-1.sl.saasdev.example.net.
            external-dns.alpha.kubernetes.io/ttl: "60"
          broker: 1
        - advertisedHost: kafka-testapp-2.sl.saasdev.example.net
          annotations:
            external-dns.alpha.kubernetes.io/hostname: kafka-testapp-2.sl.saasdev.example.net.
            external-dns.alpha.kubernetes.io/ttl: "60"
          broker: 2
      name: external
      port: 9094
      tls: true
      type: loadbalancer
    replicas: 3
    storage:
      class: standard
      deleteClaim: false
      size: 3Gi
      type: persistent-claim
    template:
      externalBootstrapService:
        metadata:
          annotations:
            cloud.google.com/load-balancer-type: Internal
      perPodService:
        metadata:
          annotations:
            cloud.google.com/load-balancer-type: Internal
      pod:
        affinity:
          nodeAffinity:
            requiredDuringSchedulingIgnoredDuringExecution:
              nodeSelectorTerms:
              - matchExpressions:
                - key: node_pool
                  operator: In
                  values:
                  - aodapn-pool-blue
          podAntiAffinity:
            requiredDuringSchedulingIgnoredDuringExecution:
            - labelSelector:
                matchExpressions:
                - key: strimzi.io/name
                  operator: In
                  values:
                  - testapp-cluster-kafka
              topologyKey: kubernetes.io/hostname
        tolerations:
        - effect: NoSchedule
          key: dedicated
          operator: Equal
          value: appneta
      podDisruptionBudget:
        maxUnavailable: 1
    version: 3.2.3
  zookeeper:
    replicas: 3
    storage:
      class: standard
      deleteClaim: false
      size: 5Gi
      type: persistent-claim
    template:
      pod:
        affinity:
          nodeAffinity:
            requiredDuringSchedulingIgnoredDuringExecution:
              nodeSelectorTerms:
              - matchExpressions:
                - key: node_pool
                  operator: In
                  values:
                  - aodapn-pool-blue
          podAntiAffinity:
            requiredDuringSchedulingIgnoredDuringExecution:
            - labelSelector:
                matchExpressions:
                - key: strimzi.io/name
                  operator: In
                  values:
                  - testapp-cluster-kafka
              topologyKey: kubernetes.io/hostname
        tolerations:
        - effect: NoSchedule
          key: dedicated
          operator: Equal
          value: appneta
      podDisruptionBudget:
        maxUnavailable: 1

$ k get cm  -n aodapn-kafka-testapp-dev  testapp-cluster-kafka-config -o yaml
apiVersion: v1
data:
  advertised-hostnames.config: EXTERNAL_9094_0://kafka-testapp-0.sl.saasdev.example.net
    PLAIN_9092_0://testapp-cluster-kafka-0.testapp-cluster-kafka-brokers.aodapn-kafka-testapp-dev.svc
    EXTERNAL_9094_1://kafka-testapp-1.sl.saasdev.example.net PLAIN_9092_1://testapp-cluster-kafka-1.testapp-cluster-kafka-brokers.aodapn-kafka-testapp-dev.svc
    EXTERNAL_9094_2://kafka-testapp-2.sl.saasdev.example.net PLAIN_9092_2://testapp-cluster-kafka-2.testapp-cluster-kafka-brokers.aodapn-kafka-testapp-dev.svc
  advertised-ports.config: EXTERNAL_9094_0://9094 PLAIN_9092_0://9092 EXTERNAL_9094_1://9094
    PLAIN_9092_1://9092 EXTERNAL_9094_2://9094 PLAIN_9092_2://9092
  listeners.config: PLAIN_9092 EXTERNAL_9094
  log4j.properties: |
    # Do not change this generated file. Logging can be configured in the corresponding Kubernetes resource.
    log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender
    log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout
    log4j.appender.CONSOLE.layout.ConversionPattern=%d{ISO8601} %p %m (%c) [%t]%n
    kafka.root.logger.level=INFO
    log4j.rootLogger=${kafka.root.logger.level}, CONSOLE
    log4j.logger.org.I0Itec.zkclient.ZkClient=INFO
    log4j.logger.org.apache.zookeeper=INFO
    log4j.logger.kafka=INFO
    log4j.logger.org.apache.kafka=INFO
    log4j.logger.kafka.request.logger=WARN, CONSOLE
    log4j.logger.kafka.network.Processor=OFF
    log4j.logger.kafka.server.KafkaApis=OFF
    log4j.logger.kafka.network.RequestChannel$=WARN
    log4j.logger.kafka.controller=TRACE
    log4j.logger.kafka.log.LogCleaner=INFO
    log4j.logger.state.change.logger=TRACE
    log4j.logger.kafka.authorizer.logger=INFO
  server.config: |-
    ##############################
    ##############################
    # This file is automatically generated by the Strimzi Cluster Operator
    # Any changes to this file will be ignored and overwritten!
    ##############################
    ##############################

    ##########
    # Broker ID
    ##########
    broker.id=${STRIMZI_BROKER_ID}
    node.id=${STRIMZI_BROKER_ID}

    ##########
    # Zookeeper
    ##########
    zookeeper.connect=testapp-cluster-zookeeper-client:2181
    zookeeper.clientCnxnSocket=org.apache.zookeeper.ClientCnxnSocketNetty
    zookeeper.ssl.client.enable=true
    zookeeper.ssl.keystore.location=/tmp/kafka/cluster.keystore.p12
    zookeeper.ssl.keystore.password=${CERTS_STORE_PASSWORD}
    zookeeper.ssl.keystore.type=PKCS12
    zookeeper.ssl.truststore.location=/tmp/kafka/cluster.truststore.p12
    zookeeper.ssl.truststore.password=${CERTS_STORE_PASSWORD}
    zookeeper.ssl.truststore.type=PKCS12

    ##########
    # Kafka message logs configuration
    ##########
    log.dirs=/var/lib/kafka/data/kafka-log${STRIMZI_BROKER_ID}

    ##########
    # Control Plane listener
    ##########
    listener.name.controlplane-9090.ssl.keystore.location=/tmp/kafka/cluster.keystore.p12
    listener.name.controlplane-9090.ssl.keystore.password=${CERTS_STORE_PASSWORD}
    listener.name.controlplane-9090.ssl.keystore.type=PKCS12
    listener.name.controlplane-9090.ssl.truststore.location=/tmp/kafka/cluster.truststore.p12
    listener.name.controlplane-9090.ssl.truststore.password=${CERTS_STORE_PASSWORD}
    listener.name.controlplane-9090.ssl.truststore.type=PKCS12
    listener.name.controlplane-9090.ssl.client.auth=required

    ##########
    # Replication listener
    ##########
    listener.name.replication-9091.ssl.keystore.location=/tmp/kafka/cluster.keystore.p12
    listener.name.replication-9091.ssl.keystore.password=${CERTS_STORE_PASSWORD}
    listener.name.replication-9091.ssl.keystore.type=PKCS12
    listener.name.replication-9091.ssl.truststore.location=/tmp/kafka/cluster.truststore.p12
    listener.name.replication-9091.ssl.truststore.password=${CERTS_STORE_PASSWORD}
    listener.name.replication-9091.ssl.truststore.type=PKCS12
    listener.name.replication-9091.ssl.client.auth=required

    ##########
    # Listener configuration: PLAIN-9092
    ##########

    ##########
    # Listener configuration: EXTERNAL-9094
    ##########
    listener.name.external-9094.scram-sha-512.sasl.jaas.config=org.apache.kafka.common.security.scram.ScramLoginModule required;
    listener.name.external-9094.sasl.enabled.mechanisms=SCRAM-SHA-512

    listener.name.external-9094.ssl.keystore.location=/tmp/kafka/custom-external-9094.keystore.p12
    listener.name.external-9094.ssl.keystore.password=${CERTS_STORE_PASSWORD}
    listener.name.external-9094.ssl.keystore.type=PKCS12


    ##########
    # Common listener configuration
    ##########
    listeners=CONTROLPLANE-9090://0.0.0.0:9090,REPLICATION-9091://0.0.0.0:9091,PLAIN-9092://0.0.0.0:9092,EXTERNAL-9094://0.0.0.0:9094
    advertised.listeners=CONTROLPLANE-9090://testapp-cluster-kafka-${STRIMZI_BROKER_ID}.testapp-cluster-kafka-brokers.aodapn-kafka-testapp-dev.svc:9090,REPLICATION-9091://testapp-cluster-kafka-${STRIMZI_BROKER_ID}.testapp-cluster-kafka-brokers.aodapn-kafka-testapp-dev.svc:9091,PLAIN-9092://${STRIMZI_PLAIN_9092_ADVERTISED_HOSTNAME}:${STRIMZI_PLAIN_9092_ADVERTISED_PORT},EXTERNAL-9094://${STRIMZI_EXTERNAL_9094_ADVERTISED_HOSTNAME}:${STRIMZI_EXTERNAL_9094_ADVERTISED_PORT}
    listener.security.protocol.map=CONTROLPLANE-9090:SSL,REPLICATION-9091:SSL,PLAIN-9092:PLAINTEXT,EXTERNAL-9094:SASL_SSL
    control.plane.listener.name=CONTROLPLANE-9090
    inter.broker.listener.name=REPLICATION-9091
    sasl.enabled.mechanisms=
    ssl.secure.random.implementation=SHA1PRNG
    ssl.endpoint.identification.algorithm=HTTPS

    ##########
    # Authorization
    ##########
    authorizer.class.name=kafka.security.authorizer.AclAuthorizer
    super.users=User:CN=testapp-cluster-kafka,O=io.strimzi;User:CN=testapp-cluster-entity-topic-operator,O=io.strimzi;User:CN=testapp-cluster-entity-user-operator,O=io.strimzi;User:CN=testapp-cluster-kafka-exporter,O=io.strimzi;User:CN=testapp-cluster-cruise-control,O=io.strimzi;User:CN=cluster-operator,O=io.strimzi

    ##########
    # User provided configuration
    ##########
    default.replication.factor=3
    inter.broker.protocol.version=3.2
    log.message.format.version=3.2
kind: ConfigMap
metadata:
  creationTimestamp: "2023-03-01T23:22:13Z"
  labels:
    app.kubernetes.io/instance: testapp-cluster
    app.kubernetes.io/managed-by: strimzi-cluster-operator
    app.kubernetes.io/name: kafka
    app.kubernetes.io/part-of: strimzi-testapp-cluster
    manged-by: fournines
    strimzi.io/cluster: testapp-cluster
    strimzi.io/kind: Kafka
    strimzi.io/name: testapp-cluster-kafka
  name: testapp-cluster-kafka-config
  namespace: aodapn-kafka-testapp-dev
  ownerReferences:
  - apiVersion: kafka.strimzi.io/v1beta2
    blockOwnerDeletion: false
    controller: false
    kind: Kafka
    name: testapp-cluster
    uid: fb7c7497-c47b-484a-9424-eef365d2f6b4
  resourceVersion: "347117329"
  uid: 41a33def-72d9-4dda-9853-5d9015754a1c

---

Steps to reproduce

No response

Expected behavior

Don't want operator to restart kafka broker pods

Strimzi version

0.31.1

Kubernetes version

v1.24.13-gke.2500

Installation method

No response

Infrastructure

No response

Configuration files and logs

kafka-operator-logs.txt

Additional context

No response

[scholzj]

I think you will need to share the full logs from the operator and full configurations (the custom resources and any related config maps). Copy-pasting a single line is not helpful and neither are screenshots where it is absolutely unclear what do they show.

[tkorrapati1]

@scholzj screenshots just show that operator restarting pods with msg line "logging needs to be reconfigured" error. sorry for not providing adequate information.

I have updated the description now with kafka custom resource, and kafka config map + operator logs for a full reconciliation run where pods were restarted, I hope updated info helps. thx.

[scholzj]

I do not see any full logs or CRs in the description :-/.

[tkorrapati1]

I do not see any full logs or CRs in the description :-/.

Not sure what happened, but updated now.

[scholzj]

Ok, I see it now. But I do not see it rolling any pods / restarting brokers. All this message means is that it will connect to the broker to see if the logging configuration is up to date and if not, it will try to updated it dynamically if possible. So I think this has nothing to do with NotLeaderOrFollowerException. Do you actually see your brokers restarting? If yes, what do the broker logs and Kubernetes events say as the reason for the restart?

[scholzj]

Triaged on 13.7.2023: Seems more like an issue of a particular environment rather than a general bug. Should be converted to discussion.