Still seeing "RuntimeSqlException: SQL error: Expected only one result row but got none" after 2.1.4.Final uptake

[pschmid]

Hi, I have a question regarding an issue that has been fixed recently (#1873).
We were seeing this issue intermittently in release 2.1.0.RC1 and updated to 2.1.4.Final to get the fix, but after updating, the issue still happens. I'm not sure why but after some time the issue disappears which makes it hard to reproduce. Here are the stack trace I got from logs that might help.

apicurio schema registry stack trace:

(executor-thread-33) io.apicurio.registry.storage.impl.sql.jdb.RuntimeSqlException: SQL error: Expected only one result row but got none.: io.apicurio.registry.storage.RegistryStorageException: io.apicurio.registry.storage.impl.sql.jdb.RuntimeSqlException: SQL error: Expected only one result row but got none.
at io.apicurio.registry.storage.impl.sql.HandleFactory.withHandleNoException(HandleFactory.java:56)
at io.apicurio.registry.storage.impl.sql.HandleFactory_ClientProxy.withHandleNoException(HandleFactory_ClientProxy.zig:190)
at io.apicurio.registry.storage.impl.kafkasql.sql.KafkaSqlStore.contentIdFromHash(KafkaSqlStore.java:164)
at io.apicurio.registry.storage.impl.kafkasql.sql.KafkaSqlStore.createArtifactWithMetadata(KafkaSqlStore.java:131)
at io.apicurio.registry.storage.impl.kafkasql.sql.KafkaSqlStore_Subclass.createArtifactWithMetadata$$superforward1(KafkaSqlStore_Subclass.zig:7875)
at io.apicurio.registry.storage.impl.kafkasql.sql.KafkaSqlStore_Subclass$$function$$25.apply(KafkaSqlStore_Subclass$$function$$25.zig:83)
at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:54)
at io.apicurio.registry.logging.LoggingInterceptor.logMethodEntry(LoggingInterceptor.java:55)
at io.apicurio.registry.logging.LoggingInterceptor_Bean.intercept(LoggingInterceptor_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.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:127)
at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:100)
at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.doIntercept(TransactionalInterceptorRequired.java:32)
at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:53)
at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.intercept(TransactionalInterceptorRequired.java:26)
at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired_Bean.intercept(TransactionalInterceptorRequired_Bean.zig:340)
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.sql.KafkaSqlStore_Subclass.createArtifactWithMetadata(KafkaSqlStore_Subclass.zig:13874)
at io.apicurio.registry.storage.impl.kafkasql.sql.KafkaSqlStore_ClientProxy.createArtifactWithMetadata(KafkaSqlStore_ClientProxy.zig:1388)
at io.apicurio.registry.storage.impl.kafkasql.sql.KafkaSqlSink.processArtifactMessage(KafkaSqlSink.java:255)
at io.apicurio.registry.storage.impl.kafkasql.sql.KafkaSqlSink.doProcessMessage(KafkaSqlSink.java:152)
at io.apicurio.registry.storage.impl.kafkasql.sql.KafkaSqlSink.processMessage(KafkaSqlSink.java:104)
at io.apicurio.registry.storage.impl.kafkasql.sql.KafkaSqlSink_Subclass.processMessage$$superforward1(KafkaSqlSink_Subclass.zig:768)
at io.apicurio.registry.storage.impl.kafkasql.sql.KafkaSqlSink_Subclass$$function$$15.apply(KafkaSqlSink_Subclass$$function$$15.zig:33)
at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:54)
at io.apicurio.registry.logging.LoggingInterceptor.logMethodEntry(LoggingInterceptor.java:55)
at io.apicurio.registry.logging.LoggingInterceptor_Bean.intercept(LoggingInterceptor_Bean.zig:327)
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.sql.KafkaSqlSink_Subclass.processMessage(KafkaSqlSink_Subclass.zig:2189)
at io.apicurio.registry.storage.impl.kafkasql.sql.KafkaSqlSink_ClientProxy.processMessage(KafkaSqlSink_ClientProxy.zig:128)
at io.apicurio.registry.storage.impl.kafkasql.KafkaSqlRegistryStorage.lambda$startConsumerThread$1(KafkaSqlRegistryStorage.java:282)
at java.base/java.lang.Iterable.forEach(Iterable.java:75)
at io.apicurio.registry.storage.impl.kafkasql.KafkaSqlRegistryStorage.lambda$startConsumerThread$2(KafkaSqlRegistryStorage.java:256)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: io.apicurio.registry.storage.impl.sql.jdb.RuntimeSqlException: SQL error: Expected only one result row but got none.
at io.apicurio.registry.storage.impl.sql.jdb.MappedQueryImpl.one(MappedQueryImpl.java:66)
at io.apicurio.registry.storage.impl.kafkasql.sql.KafkaSqlStore.lambda$contentIdFromHash$7(KafkaSqlStore.java:169)
at io.apicurio.registry.storage.impl.sql.HandleFactory.withHandle(HandleFactory.java:44)
at io.apicurio.registry.storage.impl.sql.HandleFactory.withHandleNoException(HandleFactory.java:52)
... 38 more

And this is how we are trying to publish the event in our service:

io.apicurio.registry.rest.client.exception.RestClientException: io.apicurio.registry.storage.impl.sql.jdb.RuntimeSqlException: SQL error: Expected only one result row but got none.\n\t
at io.apicurio.registry.rest.client.impl.ErrorHandler.handleErrorResponse(ErrorHandler.java:64)\n\t
at io.apicurio.rest.client.handler.BodyHandler.lambda$toSupplierOfType$1(BodyHandler.java:46)\n\t
at io.apicurio.rest.client.JdkHttpClient.sendRequest(JdkHttpClient.java:189)\n\t
at io.apicurio.registry.rest.client.impl.RegistryClientImpl.createArtifact(RegistryClientImpl.java:235)\n\t
at io.apicurio.registry.rest.client.RegistryClient.createArtifact(RegistryClient.java:118)\n\t
at io.apicurio.registry.serde.DefaultSchemaResolver.lambda$handleAutoCreateArtifact$3(DefaultSchemaResolver.java:214)\n\t
at java.base/java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1705)\n\t
at io.apicurio.registry.serde.DefaultSchemaResolver.handleAutoCreateArtifact(DefaultSchemaResolver.java:213)\n\t
at io.apicurio.registry.serde.DefaultSchemaResolver.resolveSchema(DefaultSchemaResolver.java:89)\n\t
at io.apicurio.registry.serde.AbstractKafkaSerializer.serialize(AbstractKafkaSerializer.java:92)\n\t
at org.apache.kafka.clients.producer.KafkaProducer.doSend(KafkaProducer.java:910)\n\t
at org.apache.kafka.clients.producer.KafkaProducer.send(KafkaProducer.java:870)\n\t
at org.springframework.kafka.core.DefaultKafkaProducerFactory$CloseSafeProducer.send(DefaultKafkaProducerFactory.java:864)\n\t
at org.springframework.kafka.core.KafkaTemplate.doSend(KafkaTemplate.java:563)\n\t
at org.springframework.kafka.core.KafkaTemplate.send(KafkaTemplate.java:369)\n\t
at org.springframework.kafka.core.KafkaTemplate.sendDefault(KafkaTemplate.java:347)\n\t
at 

I'm not sure if this can be related to how we are configuring the schema registry, but adding the config properties we are using.
Also we are using Avro for the schema definitions.

for Producer:

        REGISTRY_URL to KafkaProperties.properties.getValue(APICURIO_REGISTRY_PROP),
        ARTIFACT_RESOLVER_STRATEGY to RecordIdStrategy::class.java,
        USE_ID to IdOption.contentId.name,
        AUTO_REGISTER_ARTIFACT to true

for Consumer:

            USE_SPECIFIC_AVRO_READER to true,
            USE_ID to IdOption.contentId.name,
            REGISTRY_URL to KafkaProperties.properties.getValue(APICURIO_REGISTRY_PROP)

Ideally we would like to have the issue fixed without having to remove the schemas from the kafka persistency.

[pschmid]

Something else to add that might help is that we are running 2 instances of the schema registry.

[EricWittmann]

It's likely because you still have a corrupted stream of events in the kafka topic that registry is using for persistence. The bug is fixed in 2.1.4.Final such that the stream will not get corrupted again in the future, but due to log compaction plus our bug, your topic simply has some messages that are gone and will never come back. :( The good news is that if this is the problem, we can fix it!

See this blog post: https://www.apicur.io/blog/2021/12/09/kafkasql-storage-and-security

In particular, scroll down to the part of that blog post that reads However, this configuration change does not fix the existing corrupted data in the database. That will explain what you can do to "repair" the topic.

[pschmid]

Thank you very much for the quick response. We will try it out as soon as we get the failure again.

[pschmid]

Issue is fixed and work around was applied successfully.

[EricWittmann]

Thank you for the followup! Very happy it's working. I will go have a celebratory adult beverage now.