Issue with Kafkasql persistence and TLS security

[MilanMasek]

Greetings community,
I'm trying to deploy Apicurio registry in OCP and I don't understand why it is not able to read correctly secrets with provided keystore and truststore certificates and keys. Could you please give me some hints?

versions: Apicurio Registry Operator 1.0.0-v2.0.0.final provided by Apicurio in OCP 4.11.47. When deploying with CRD below, it is downloading the image quay.io/apicurio/apicurio-registry-kafkasql:2.0.0.Final

CRD I use

apiVersion: registry.apicur.io/v1
kind: ApicurioRegistry
metadata:
  name: akafka-apicurioregistry
spec:
  configuration:
    persistence: "kafkasql"
    #logLevel: DEBUG
    kafkasql:
      bootstrapServers: "akafka-kafka-bootstrap.mw-cz.svc:9093"
      security:
        tls:
          keystoreSecretName: "akafka-admin"
          truststoreSecretName: "akafka-cluster-ca-cert"

Both secrets contain key-value pairs as described at https://access.redhat.com/documentation/en-us/red_hat_build_of_apicurio_registry/2.0/html/installing_and_deploying_apicurio_registry_on_openshift/installing-registry-streams-storage#registry-persistence-kafkasql-tls
Secrets are created by Strimzi Operator during Kafka deployment, they are base64 encoded.
I verified p12 keystore and truststore can be opened by a password stored in both secrets (of course - after decoding by base64).

During Apicurio start, however, I'm getting error pointing at the problem accessing keystore/truststore.
What can be the problem or what am I doing wrong?
Thank you in advance for helping.

exec java -Dquarkus.http.host=0.0.0.0 -Djava.util.logging.manager=org.jboss.logmanager.LogManager -javaagent:/opt/agent-bond/agent-bond.jar=jmx_exporter{{9779:/opt/agent-bond/jmx_exporter_config.yml}} -XX:+ExitOnOutOfMemoryError -cp . -jar /deployments/apicurio-registry-storage-kafkasql-2.0.0.Final-runner.jar
__  ____  __  _____   ___  __ ____  ______ 
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/ 
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \   
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/   
2023-09-13 12:38:27,745 WARN  [io.qua.config] (main) Unrecognized configuration key "quarkus.oidc.client-secret" was provided; it will be ignored; verify that the dependency extension for this configuration is set or you did not make a typo
2023-09-13 12:38:29,934 INFO  [org.apa.kaf.con.jso.JsonConverterConfig] (main) JsonConverterConfig values: 
	converter.type = key
	decimal.format = BASE64
	schemas.cache.size = 0
	schemas.enable = true

2023-09-13 12:38:32,156 INFO  [io.api.reg.sto.imp.kaf.KafkaSqlRegistryStorage] (main) Using Kafka-SQL artifactStore.
2023-09-13 12:38:32,247 INFO  [org.apa.kaf.cli.adm.AdminClientConfig] (main) AdminClientConfig values: 
	bootstrap.servers = [akafka-kafka-bootstrap.mw-cz.svc:9093]
	client.dns.lookup = default
	client.id = 
	connections.max.idle.ms = 300000
	default.api.timeout.ms = 60000
	metadata.max.age.ms = 300000
	metric.reporters = []
	metrics.num.samples = 2
	metrics.recording.level = INFO
	metrics.sample.window.ms = 30000
	receive.buffer.bytes = 65536
	reconnect.backoff.max.ms = 1000
	reconnect.backoff.ms = 50
	request.timeout.ms = 30000
	retries = 2147483647
	retry.backoff.ms = 100
	sasl.client.callback.handler.class = null
	sasl.jaas.config = null
	sasl.kerberos.kinit.cmd = /usr/bin/kinit
	sasl.kerberos.min.time.before.relogin = 60000
	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.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.mechanism = GSSAPI
	security.protocol = SSL
	security.providers = null
	send.buffer.bytes = 131072
	ssl.cipher.suites = null
	ssl.enabled.protocols = [TLSv1.2]
	ssl.endpoint.identification.algorithm = https
	ssl.key.password = null
	ssl.keymanager.algorithm = SunX509
	ssl.keystore.location = /etc/registry-kafkasql-tls-keystore/user.p12
	ssl.keystore.password = [hidden]
	ssl.keystore.type = PKCS12
	ssl.protocol = TLSv1.2
	ssl.provider = null
	ssl.secure.random.implementation = null
	ssl.trustmanager.algorithm = PKIX
	ssl.truststore.location = /etc/registry-kafkasql-tls-truststore/ca.p12
	ssl.truststore.password = [hidden]
	ssl.truststore.type = PKCS12

2023-09-13 12:38:32,861 WARN  [io.api.reg.met.PersistenceExceptionLivenessCheck] (main) Liveness problem suspected in PersistenceExceptionLivenessCheck because of an exception: : org.apache.kafka.common.KafkaException: Failed to create new KafkaAdminClient
	at org.apache.kafka.clients.admin.KafkaAdminClient.createInternal(KafkaAdminClient.java:479)
	at org.apache.kafka.clients.admin.Admin.create(Admin.java:61)
	at io.apicurio.registry.utils.kafka.KafkaUtil.createTopics(KafkaUtil.java:68)
	at io.apicurio.registry.storage.impl.kafkasql.KafkaSqlRegistryStorage.autoCreateTopics(KafkaSqlRegistryStorage.java:228)
	at io.apicurio.registry.storage.impl.kafkasql.KafkaSqlRegistryStorage.onConstruct(KafkaSqlRegistryStorage.java:171)
	at io.apicurio.registry.storage.impl.kafkasql.KafkaSqlRegistryStorage_Subclass.onConstruct$$superaccessor38(KafkaSqlRegistryStorage_Subclass.zig:8202)
	at io.apicurio.registry.storage.impl.kafkasql.KafkaSqlRegistryStorage_Subclass$$function$$38.apply(KafkaSqlRegistryStorage_Subclass$$function$$38.zig:33)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:54)
	at io.smallrye.metrics.interceptors.CountedInterceptor.countedCallable(CountedInterceptor.java:95)
	at io.smallrye.metrics.interceptors.CountedInterceptor.countedMethod(CountedInterceptor.java:70)
	at io.smallrye.metrics.interceptors.CountedInterceptor_Bean.intercept(CountedInterceptor_Bean.zig:366)
	at io.quarkus.arc.impl.InitializedInterceptor.intercept(InitializedInterceptor.java:79)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:50)
	at io.smallrye.metrics.interceptors.TimedInterceptor.timedCallable(TimedInterceptor.java:95)
	at io.smallrye.metrics.interceptors.TimedInterceptor.timedMethod(TimedInterceptor.java:70)
	at io.smallrye.metrics.interceptors.TimedInterceptor_Bean.intercept(TimedInterceptor_Bean.zig:366)
	at io.quarkus.arc.impl.InitializedInterceptor.intercept(InitializedInterceptor.java:79)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:50)
	at io.smallrye.metrics.interceptors.ConcurrentGaugeInterceptor.concurrentCallable(ConcurrentGaugeInterceptor.java:96)
	at io.smallrye.metrics.interceptors.ConcurrentGaugeInterceptor.countedMethod(ConcurrentGaugeInterceptor.java:69)
	at io.smallrye.metrics.interceptors.ConcurrentGaugeInterceptor_Bean.intercept(ConcurrentGaugeInterceptor_Bean.zig:366)
	at io.quarkus.arc.impl.InitializedInterceptor.intercept(InitializedInterceptor.java:79)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:50)
	at io.apicurio.registry.metrics.PersistenceExceptionLivenessInterceptor.intercept(PersistenceExceptionLivenessInterceptor.java:25)
	at io.apicurio.registry.metrics.PersistenceExceptionLivenessInterceptor_Bean.intercept(PersistenceExceptionLivenessInterceptor_Bean.zig:378)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:50)
	at io.apicurio.registry.metrics.PersistenceTimeoutReadinessInterceptor.intercept(PersistenceTimeoutReadinessInterceptor.java:27)
	at io.apicurio.registry.metrics.PersistenceTimeoutReadinessInterceptor_Bean.intercept(PersistenceTimeoutReadinessInterceptor_Bean.zig:327)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:50)
	at io.apicurio.registry.logging.LoggingInterceptor.logMethodEntry(LoggingInterceptor.java:55)
	at io.apicurio.registry.logging.LoggingInterceptor_Bean.intercept(LoggingInterceptor_Bean.zig:275)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41)
	at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32)
	at io.apicurio.registry.storage.impl.kafkasql.KafkaSqlRegistryStorage_Subclass.onConstruct(KafkaSqlRegistryStorage_Subclass.zig:8159)
	at io.apicurio.registry.storage.impl.kafkasql.KafkaSqlRegistryStorage_Observer_onConstruct_79d9ecdc6d6c86e30787a866068cd6fdf0383153.notify(KafkaSqlRegistryStorage_Observer_onConstruct_79d9ecdc6d6c86e30787a866068cd6fdf0383153.zig:147)
	at io.quarkus.arc.impl.EventImpl$Notifier.notifyObservers(EventImpl.java:282)
	at io.quarkus.arc.impl.EventImpl$Notifier.notify(EventImpl.java:267)
	at io.quarkus.arc.impl.EventImpl.fire(EventImpl.java:69)
	at io.quarkus.arc.runtime.LifecycleEventRunner.fireStartupEvent(LifecycleEventRunner.java:23)
	at io.quarkus.arc.runtime.ArcRecorder.handleLifecycleEvents(ArcRecorder.java:60)
	at io.quarkus.deployment.steps.LifecycleEventsBuildStep$startupEvent-858218658.deploy_0(LifecycleEventsBuildStep$startupEvent-858218658.zig:81)
	at io.quarkus.deployment.steps.LifecycleEventsBuildStep$startupEvent-858218658.deploy(LifecycleEventsBuildStep$startupEvent-858218658.zig:40)
	at io.quarkus.runner.ApplicationImpl.doStart(ApplicationImpl.zig:730)
	at io.quarkus.runtime.Application.start(Application.java:90)
	at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:100)
	at io.quarkus.runtime.Quarkus.run(Quarkus.java:66)
	at io.quarkus.runtime.Quarkus.run(Quarkus.java:42)
	at io.quarkus.runtime.Quarkus.run(Quarkus.java:119)
	at io.quarkus.runner.GeneratedMain.main(GeneratedMain.zig:29)
Caused by: org.apache.kafka.common.KafkaException: org.apache.kafka.common.KafkaException: org.apache.kafka.common.KafkaException: Failed to load SSL keystore /etc/registry-kafkasql-tls-keystore/user.p12 of type PKCS12
	at org.apache.kafka.common.network.SslChannelBuilder.configure(SslChannelBuilder.java:74)
	at org.apache.kafka.common.network.ChannelBuilders.create(ChannelBuilders.java:157)
	at org.apache.kafka.common.network.ChannelBuilders.clientChannelBuilder(ChannelBuilders.java:73)
	at org.apache.kafka.clients.ClientUtils.createChannelBuilder(ClientUtils.java:105)
	at org.apache.kafka.clients.admin.KafkaAdminClient.createInternal(KafkaAdminClient.java:454)
	... 54 more
Caused by: org.apache.kafka.common.KafkaException: org.apache.kafka.common.KafkaException: Failed to load SSL keystore /etc/registry-kafkasql-tls-keystore/user.p12 of type PKCS12
	at org.apache.kafka.common.security.ssl.SslEngineBuilder.createSSLContext(SslEngineBuilder.java:163)
	at org.apache.kafka.common.security.ssl.SslEngineBuilder.<init>(SslEngineBuilder.java:104)
	at org.apache.kafka.common.security.ssl.SslFactory.configure(SslFactory.java:95)
	at org.apache.kafka.common.network.SslChannelBuilder.configure(SslChannelBuilder.java:72)
	... 58 more
Caused by: org.apache.kafka.common.KafkaException: Failed to load SSL keystore /etc/registry-kafkasql-tls-keystore/user.p12 of type PKCS12
	at org.apache.kafka.common.security.ssl.SslEngineBuilder$SecurityStore.load(SslEngineBuilder.java:292)
	at org.apache.kafka.common.security.ssl.SslEngineBuilder.createSSLContext(SslEngineBuilder.java:144)
	... 61 more
Caused by: java.io.IOException: keystore password was incorrect
	at java.base/sun.security.pkcs12.PKCS12KeyStore.engineLoad(PKCS12KeyStore.java:2108)
	at java.base/sun.security.util.KeyStoreDelegator.engineLoad(KeyStoreDelegator.java:222)
	at java.base/java.security.KeyStore.load(KeyStore.java:1479)
	at org.apache.kafka.common.security.ssl.SslEngineBuilder$SecurityStore.load(SslEngineBuilder.java:289)
	... 62 more
Caused by: java.security.UnrecoverableKeyException: failed to decrypt safe contents entry: javax.crypto.BadPaddingException: Given final block not properly padded. Such issues can arise if a bad key is used during decryption.
	... 66 more

2023-09-13 12:38:32,922 INFO  [io.api.reg.met.PersistenceExceptionLivenessCheck] (main) After this event, the error counter is 1 (out of the maximum 5 allowed).
2023-09-13 12:38:33,041 ERROR [io.qua.run.Application] (main) Failed to start application (with profile prod): java.security.UnrecoverableKeyException: failed to decrypt safe contents entry: javax.crypto.BadPaddingException: Given final block not properly padded. Such issues can arise if a bad key is used during decryption.
	at java.base/sun.security.pkcs12.PKCS12KeyStore.engineLoad(PKCS12KeyStore.java:2108)
	at java.base/sun.security.util.KeyStoreDelegator.engineLoad(KeyStoreDelegator.java:222)

[andreaTP]

Hi @MilanMasek !
Thanks for opening this issue and sorry for the incredibly long delay.
From your report, I do suspect that the container doesn't have the correct permissions to access the /etc folder when running on OCP (the user 1001 is enforced there, and /etc is instead owned by root).

Let's see if @jsenko can help here 🙏

[MilanMasek]

Hi Andrea, as suggested by Jakub, update to the latest solves the problem.
Thank you for your support!

[jsenko]

hi, can you first try to upgrade to the latest 1.1.0-v2.4.12.final Registry Operator version? Also please let me know which Strimzi version are you using.

[MilanMasek]

Thank you Jakub! The upgrade to the latest Apicurio Registry Opetrator 1.1.0-v2.4.12.final solved the issue. It was not available at the moment I was creating this thread as far as I remember. In any case, it seems to be happy now.
For the record, Strimzi is 0.37.0 (latest).
Thank you again and greetings to Brno city.