Kafka SSL handshake failed

[ThorbenJ]

Hi.

While this might be a continuation of my own adventure here: #6111 (6111) - I didn't want to pollute that discussion with something new.

Now deployed on GKE Standard (1.21.5-gke.1302) everything is "running" and appears to work:

$ kc exec -n kafka elsec-feeds-kafka-0 -- bin/kafka-topics.sh --bootstrap-server elsec-feeds-kafka-bootstrap:9092 --list
__consumer_offsets
__strimzi-topic-operator-kstreams-topic-store-changelog
__strimzi_store_topic
tj-test

However all the kafka pods are generating a constant stream of the the follow logs:

...
2022-01-07 10:24:13,923 INFO [SocketServer listenerType=ZK_BROKER, nodeId=1] Failed authentication with /10.36.2.8 (SSL handshake failed) (org.apache.kafka.common.network.Selector) [data-plane-kafka-network-thread-1-ListenerName(REPLICATION-9091)-SSL-1]
2022-01-07 10:24:14,097 INFO [SocketServer listenerType=ZK_BROKER, nodeId=1] Failed authentication with /10.36.2.8 (SSL handshake failed) (org.apache.kafka.common.network.Selector) [data-plane-kafka-network-thread-1-ListenerName(REPLICATION-9091)-SSL-2]
2022-01-07 10:24:15,315 INFO [SocketServer listenerType=ZK_BROKER, nodeId=1] Failed authentication with /10.36.2.8 (SSL handshake failed) (org.apache.kafka.common.network.Selector) [data-plane-kafka-network-thread-1-ListenerName(REPLICATION-9091)-SSL-3]
2022-01-07 10:24:15,487 INFO [SocketServer listenerType=ZK_BROKER, nodeId=1] Failed authentication with /10.36.2.8 (SSL handshake failed) (org.apache.kafka.common.network.Selector) [data-plane-kafka-network-thread-1-ListenerName(REPLICATION-9091)-SSL-1]
2022-01-07 10:24:16,525 INFO [SocketServer listenerType=ZK_BROKER, nodeId=1] Failed authentication with /10.36.2.8 (SSL handshake failed) (org.apache.kafka.common.network.Selector) [data-plane-kafka-network-thread-1-ListenerName(REPLICATION-9091)-SSL-2]
2022-01-07 10:24:17,329 INFO [SocketServer listenerType=ZK_BROKER, nodeId=1] Failed authentication with /10.36.2.8 (SSL handshake failed) (org.apache.kafka.common.network.Selector) [data-plane-kafka-network-thread-1-ListenerName(REPLICATION-9091)-SSL-3]
2022-01-07 10:24:17,589 INFO [SocketServer listenerType=ZK_BROKER, nodeId=1] Failed authentication with /10.36.2.8 (SSL handshake failed) (org.apache.kafka.common.network.Selector) [data-plane-kafka-network-thread-1-ListenerName(REPLICATION-9091)-SSL-1]
2022-01-07 10:24:18,128 INFO [SocketServer listenerType=ZK_BROKER, nodeId=1] Failed authentication with /10.36.2.8 (SSL handshake failed) (org.apache.kafka.common.network.Selector) [data-plane-kafka-network-thread-1-ListenerName(REPLICATION-9091)-SSL-2]
...

If the kafka nodes weren't able to connect to zookeeper, how could I have able to create and interact with topics?
The logs appear harmless but are very noisy. The Zookeeper logs look normal and happy, I could not see anything interesting - and as I said the kafka cluster appears to be otherwise ok.

I've not changed anything to what I tried to deploy to GKE Autopilot in the previous discussion (6111) and I did not have this issue on that cluster. At least on this GKE Standard cluster everything got deployed and is running. The zookeeper logs look ok, but the kafka nodes apparently are having some issue in regards connecting to zookeeper..

To recap my config:

apiVersion: kafka.strimzi.io/v1beta2
kind: Kafka
metadata:
  name: elsec-feeds
spec:
  kafka:
    version: 3.0.0
    replicas: 3
    listeners:
      - name: plain
        port: 9092
        type: internal
        tls: false
      - name: tls
        port: 9093
        type: internal
        tls: true
    config:
      offsets.topic.replication.factor: 3
      transaction.state.log.replication.factor: 3
#      transaction.state.log.min.isr: 2
#      log.message.format.version: "3.0"
      inter.broker.protocol.version: "3.0"
    storage:
      type: jbod
      volumes:
      - id: 0
        type: persistent-claim
        size: 100Gi
        deleteClaim: false
#      - id: 1
#        type: persistent-claim
#        size: 100Gi
#        deleteClaim: false
    template:
      kafkaContainer:
        securityContext:
          capabilities: {"drop":["NET_RAW"]}
          seccompProfile: {"type":"RuntimeDefault"}
  zookeeper:
    replicas: 3
    storage:
      type: persistent-claim
      size: 10Gi
      deleteClaim: false
    template:
      zookeeperContainer:
        securityContext:
          capabilities: {"drop":["NET_RAW"]}
          seccompProfile: {"type":"RuntimeDefault"}
  entityOperator: 
    topicOperator: {}
    userOperator: {}
    tlsSidecar: {}
    template:
      topicOperatorContainer:
        securityContext:
          capabilities: {"drop":["NET_RAW"]}
          seccompProfile: {"type":"RuntimeDefault"}
      userOperatorContainer:
        securityContext:
          capabilities: {"drop":["NET_RAW"]}
          seccompProfile: {"type":"RuntimeDefault"}
      tlsSidecarContainer:
        securityContext:
          capabilities: {"drop":["NET_RAW"]}
          seccompProfile: {"type":"RuntimeDefault"}

Resulted in:

$ kc get pods -n kafka
NAME                                           READY   STATUS    RESTARTS   AGE
elsec-feeds-entity-operator-565d8f9d79-lgshh   3/3     Running   0          71m
elsec-feeds-kafka-0                            1/1     Running   0          35m
elsec-feeds-kafka-1                            1/1     Running   0          65m
elsec-feeds-kafka-2                            1/1     Running   0          69m
elsec-feeds-zookeeper-0                        1/1     Running   0          33m
elsec-feeds-zookeeper-1                        1/1     Running   0          31m
elsec-feeds-zookeeper-2                        1/1     Running   1          8m23s

$ kc get pods -n strimzi
NAME                                        READY   STATUS    RESTARTS   AGE
strimzi-cluster-operator-786cfd8fb8-hgsvs   1/1     Running   0          79m

[scholzj]

This:

2022-01-07 10:24:17,589 INFO [SocketServer listenerType=ZK_BROKER, nodeId=1] Failed authentication with /10.36.2.8 (SSL handshake failed) (org.apache.kafka.common.network.Selector) [data-plane-kafka-network-thread-1-ListenerName(REPLICATION-9091)-SSL-1]

has nothing to do with connections to ZooKeeper. It suggests something is trying to connect to the port 9091 and failing the TLS handshake. The port 9091 is used internally for replication and communication between operator and Kafka. So it could be one of the operators, other Kafka broker or something else what for some reason tries to talk with 9091. I guess finding out what has the IP address 10.36.2.8 might tell you more about who that is.

[ThorbenJ]

Thank you for the hint.
So kafka node 0 was complaining about an IP that I could not find in k8s; and kafka node 1 was complaining about the IP of 0; node 2 appeared happy. I deleted (restart) kafka node 0 and I am now waiting to see if the same message appears again, so far nothing. Based on the message I had assumed it was something to do with Zookeeper.
I guess kafka node 0 somehow got out of sync regarding the IP of node 1.

[scholzj]

Yeah, the listenerType=ZK_BROKER is misleading. But I think it just suggests the Kafka cluster still uses ZooKeeper.