New cluster cannot get past ZooKeep quorum creation

[leopaul36]

Describe the bug
A newly created cluster cannot get past ZooKeeper quorum creation:

NAME                     READY   STATUS             RESTARTS     AGE
my-cluster-zookeeper-0   0/1     Running            0            31s
my-cluster-zookeeper-1   0/1     CrashLoopBackOff   2 (9s ago)   31s
my-cluster-zookeeper-2   0/1     CrashLoopBackOff   2 (4s ago)   31s

Looking at the logs, the first ZooKeeper my-cluster-zookeeper-0 is able to prepare its truststore:

Detected Zookeeper ID 1
Preparing truststore
Adding /opt/kafka/cluster-ca-certs/ca.crt to truststore /tmp/zookeeper/cluster.truststore.p12 with alias ca
Certificate was added to keystore
Preparing truststore is complete
Looking for the right CA
Found the right CA: /opt/kafka/cluster-ca-certs/ca.crt
Preparing keystore for client and quorum listeners
Preparing keystore for client and quorum listeners is complete
Starting Zookeeper with configuration:
# The directory where the snapshot is stored.
dataDir=/var/lib/zookeeper/data
[...]

While the other pods my-cluster-zookeeper-1 and my-cluster-zookeeper-2 are in CrashLoopBackOff after:

Detected Zookeeper ID 2
Preparing truststore
Adding /opt/kafka/cluster-ca-certs/ca.crt to truststore /tmp/zookeeper/cluster.truststore.p12 with alias ca
Certificate was added to keystore
Preparing truststore is complete
Looking for the right CA
No CA found. Thus exiting.

To Reproduce
Steps to reproduce the behavior:

oc apply -f cluster.yml

cluster.yml is:

apiVersion: kafka.strimzi.io/v1beta2
kind: Kafka
metadata:
  name: my-cluster
  namespace: kafka-openshift
spec:
  kafka:
    version: 3.2.0
    replicas: 1
    listeners:
      - name: plain
        port: 9092
        type: internal
        tls: false
      - name: tls
        port: 9093
        type: internal
        tls: true
    config:
      offsets.topic.replication.factor: 1
      transaction.state.log.replication.factor: 1
      transaction.state.log.min.isr: 1
      default.replication.factor: 1
      min.insync.replicas: 1
      inter.broker.protocol.version: "3.2"
    storage:
      type: ephemeral
  zookeeper:
    replicas: 3
    storage:
      type: ephemeral
  entityOperator:
    topicOperator: {}
    userOperator: {}

All the cluster secrets are created properly:

oc get secrets -n kafka-openshift

NAME                                   TYPE                                  DATA   AGE
[...]
my-cluster-clients-ca                  Opaque                                1      9m27s
my-cluster-clients-ca-cert             Opaque                                3      9m27s
my-cluster-cluster-ca                  Opaque                                1      9m27s
my-cluster-cluster-ca-cert             Opaque                                3      9m27s
my-cluster-cluster-operator-certs      Opaque                                4      9m27s
my-cluster-zookeeper-dockercfg-96dh8   kubernetes.io/dockercfg               1      9m27s
my-cluster-zookeeper-nodes             Opaque                                12     9m26s
my-cluster-zookeeper-token-zmgcr       kubernetes.io/service-account-token   4      9m27s
my-cluster-zookeeper-token-znd64       kubernetes.io/service-account-token   4      9m27s

Expected behavior
The Kafka cluster should be up and running.

Environment (please complete the following information):

• Strimzi version: 0.30.0
• Installation method: YAML files
• Kubernetes cluster: OpenShift 4.10.25
• Infrastructure: Bare Metal

YAML files and logs

The cluster YAML is above. The Operator was created with all the default values except for the STRIMZI_NAMESPACE which has been set to kafka-openshift according to the namespace in which I want to create the cluster.

I attached the logs from the operator though I can not find anything relevant in those:

strimzi_operator.txt

Additional context
Looks a lot like #5362. I am also running Strimzi in an OpenShift cluster.

Thanks for your help!

[scholzj]

That suggests there is something wrong with your certificates. It might be best to delete everything and start from scratch.

[leopaul36]

Hi @scholzj,

I did try to reinstall everything from scratch a couple times with no luck.

After some more investigation and using debug pods I think I can pinpoint the issue:

It seems the error is occuring at the openssl verify step of the find_ca function called from zookeeper_tls_prepare_certificates.sh.

I tried to run this command in a debug pod of the my-cluster-zookeeper-0 pod:

openssl verify -CAfile /opt/kafka/cluster-ca-certs/ca.crt /opt/kafka/zookeeper-node-certs/my-cluster-zookeeper-0.crt
/opt/kafka/zookeeper-node-certs/my-cluster-zookeeper-0.crt: OK

The same command fails from a debug pod of the my-cluster-zookeeper-1 pod:

openssl verify -CAfile /opt/kafka/cluster-ca-certs/ca.crt /opt/kafka/zookeeper-node-certs/my-cluster-zookeeper-1.crt
O = io.strimzi, CN = cluster-ca v0
error 9 at 1 depth lookup: certificate is not yet valid
error /opt/kafka/zookeeper-node-certs/my-cluster-zookeeper-1.crt: verification failed

The weird thing is that it also fails with my-cluster-zookeeper-0.crt from the debug pod of my-cluster-zookeeper-1:

openssl verify -CAfile /opt/kafka/cluster-ca-certs/ca.crt /opt/kafka/zookeeper-node-certs/my-cluster-zookeeper-0.crt
O = io.strimzi, CN = cluster-ca v0
error 9 at 1 depth lookup: certificate is not yet valid
error /opt/kafka/zookeeper-node-certs/my-cluster-zookeeper-0.crt: verification failed

Both /opt/kafka/cluster-ca-certs/ca.crt and /opt/kafka/zookeeper-node-certs/my-cluster-zookeeper-0.crt have the same sha512sum in each debug pod which seems logical as these files are mounted from the same secrets.

I still have to figure out why openssl is behaving differently in the two pods.

[scholzj]

I guess the certificate is not yet valid is important. Possibly you have time out of sync on your worker nodes? You should check what times do you have on the different pods / nodes.

[leopaul36]

Yes that was actually the issue: https://programmerah.com/error-9-at-1-depth-lookupcertificate-is-not-yet-valid-error-9440/

One of my node was in CEST timezone and the others in UTC, I will fix this which will certainly fix the issue. Thanks for your help.