Apicurio / apicurio-registry-schema-validation

Standalone schema validation library with Apicurio Registry integration.
Apache License 2.0
4 stars 2 forks source link

io.apicurio.schema.validation.json.JsonValidator gives unhelpful stack trace when it fails to connect to the registry. #64

Open k-wall opened 1 month ago

k-wall commented 1 month ago

Our application uses JsonValidator (io.apicurio:apicurio-registry-schema-validation-jsonschema:0.0.7) to validate that content matches a schema stored within the registry.

https://github.com/kroxylicious/kroxylicious/blob/b772484feb4ca558011932a6f3796c6e7108cacd/kroxylicious-filters/kroxylicious-record-validation/src/main/java/io/kroxylicious/proxy/filter/validation/validators/bytebuf/JsonSchemaBytebufValidator.java#L39

I had a situation where apicurio.registry.url was misconfigured. It was pointing a hostname with a typo, so the hostname was failed to resolve.

Actual Behaviour:

The stacktrace produced by Apicurio doesn't lead the user to the error. The validateByArtifactReference call returns a RestClientException with the message null. There's no linked exception. The full stack in below.

You need to crank up the logging to to DEBUG to find the root cause.

apicurio_debug.txt

Desired Behaviour

Operations folks (and developers) need an easy way to know from the stack trace that the host is down.

One way to achieve this would be to chain the java.net.ConnectException exception to the exception the caller receives.

2024-09-04 10:53:14 <epollEventLoopGroup-5-2> ERROR io.apicurio.registry.resolver.ERCache:213 - Failed to update cache value for key: 1
io.apicurio.registry.rest.client.exception.RestClientException: null
    at io.apicurio.registry.rest.client.impl.ErrorHandler.parseError(ErrorHandler.java:95) ~[apicurio-registry-client-2.6.2.Final.jar:?]
    at io.apicurio.rest.client.JdkHttpClient.sendRequest(JdkHttpClient.java:207) ~[apicurio-common-rest-client-jdk-0.1.18.Final.jar:?]
    at io.apicurio.registry.rest.client.impl.RegistryClientImpl.getContentByGlobalId(RegistryClientImpl.java:378) ~[apicurio-registry-client-2.6.2.Final.jar:?]
    at io.apicurio.registry.resolver.AbstractSchemaResolver.resolveSchemaWithReferences(AbstractSchemaResolver.java:213) ~[apicurio-registry-schema-resolver-2.6.2.Final.jar:?]
    at io.apicurio.registry.resolver.AbstractSchemaResolver.lambda$resolveSchemaByGlobalId$1(AbstractSchemaResolver.java:189) ~[apicurio-registry-schema-resolver-2.6.2.Final.jar:?]
    at io.apicurio.registry.resolver.ERCache.lambda$getValue$0(ERCache.java:201) ~[apicurio-registry-schema-resolver-2.6.2.Final.jar:?]
    at io.apicurio.registry.resolver.ERCache.retry(ERCache.java:254) ~[apicurio-registry-schema-resolver-2.6.2.Final.jar:?]
    at io.apicurio.registry.resolver.ERCache.getValue(ERCache.java:200) ~[apicurio-registry-schema-resolver-2.6.2.Final.jar:?]
    at io.apicurio.registry.resolver.ERCache.getByGlobalId(ERCache.java:170) ~[apicurio-registry-schema-resolver-2.6.2.Final.jar:?]
    at io.apicurio.registry.resolver.AbstractSchemaResolver.resolveSchemaByGlobalId(AbstractSchemaResolver.java:185) ~[apicurio-registry-schema-resolver-2.6.2.Final.jar:?]
    at io.apicurio.registry.resolver.DefaultSchemaResolver.resolveSchemaByArtifactReference(DefaultSchemaResolver.java:177) ~[apicurio-registry-schema-resolver-2.6.2.Final.jar:?]
    at io.apicurio.schema.validation.json.JsonValidator.validateByArtifactReference(JsonValidator.java:90) ~[apicurio-registry-schema-validation-jsonschema-0.0.7.jar:?]
    at io.kroxylicious.proxy.filter.validation.validators.bytebuf.JsonSchemaBytebufValidator.validate(JsonSchemaBytebufValidator.java:59) ~[kroxylicious-record-validation-0.8.0.jar:?]
    at io.kroxylicious.proxy.filter.validation.validators.bytebuf.ChainingByteBufferValidator.lambda$validate$0(ChainingByteBufferValidator.java:39) ~[kroxylicious-record-validation-0.8.0.jar:?]
    at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187) ~[?:?]
    at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309) ~[?:?]
    at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:144) ~[?:?]
    at io.kroxylicious.proxy.filter.validation.validators.bytebuf.ChainingByteBufferValidator.validate(ChainingByteBufferValidator.java:37) ~[kroxylicious-record-validation-0.8.0.jar:?]
    at io.kroxylicious.proxy.filter.validation.validators.bytebuf.NullEmptyBytebufValidator.validate(NullEmptyBytebufValidator.java:38) ~[kroxylicious-record-validation-0.8.0.jar:?]
    at io.kroxylicious.proxy.filter.validation.validators.record.KeyAndValueRecordValidator.validateValue(KeyAndValueRecordValidator.java:51) ~[kroxylicious-record-validation-0.8.0.jar:?]
    at io.kroxylicious.proxy.filter.validation.validators.record.KeyAndValueRecordValidator.lambda$validate$0(KeyAndValueRecordValidator.java:45) ~[kroxylicious-record-validation-0.8.0.jar:?]
    at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187) ~[?:?]
    at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309) ~[?:?]
    at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:144) ~[?:?]
    at io.kroxylicious.proxy.filter.validation.validators.record.KeyAndValueRecordValidator.validate(KeyAndValueRecordValidator.java:40) ~[kroxylicious-record-validation-0.8.0.jar:?]
    at io.kroxylicious.proxy.filter.validation.validators.topic.PerRecordTopicValidator.lambda$validateTopicPartition$4(PerRecordTopicValidator.java:56) ~[kroxylicious-record-validation-0.8.0.jar:?]
    at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1187) ~[?:?]
    at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2309) ~[?:?]
    at io.kroxylicious.proxy.filter.validation.validators.topic.PerRecordTopicValidator.validateTopicPartition(PerRecordTopicValidator.java:56) ~[kroxylicious-record-validation-0.8.0.jar:?]
    at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) ~[?:?]
    at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625) ~[?:?]
    at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
    at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
    at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:575) ~[?:?]
    at java.base/java.util.stream.AbstractPipeline.evaluateToArrayNode(AbstractPipeline.java:260) ~[?:?]
    at java.base/java.util.stream.ReferencePipeline.toArray(ReferencePipeline.java:616) ~[?:?]
    at io.kroxylicious.proxy.filter.validation.validators.topic.PerRecordTopicValidator.validateTopicData(PerRecordTopicValidator.java:39) ~[kroxylicious-record-validation-0.8.0.jar:?]
    at io.kroxylicious.proxy.filter.validation.validators.request.RoutingProduceRequestValidator.lambda$validateRequest$0(RoutingProduceRequestValidator.java:61) ~[kroxylicious-record-validation-0.8.0.jar:?]
    at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197) ~[?:?]
    at java.base/java.util.Iterator.forEachRemaining(Iterator.java:133) ~[?:?]
    at java.base/java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1845) ~[?:?]
    at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
    at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
    at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:575) ~[?:?]
    at java.base/java.util.stream.AbstractPipeline.evaluateToArrayNode(AbstractPipeline.java:260) ~[?:?]
    at java.base/java.util.stream.ReferencePipeline.toArray(ReferencePipeline.java:616) ~[?:?]
    at io.kroxylicious.proxy.filter.validation.validators.request.RoutingProduceRequestValidator.validateRequest(RoutingProduceRequestValidator.java:62) ~[kroxylicious-record-validation-0.8.0.jar:?]
    at io.kroxylicious.proxy.filter.validation.RecordValidationFilter.onProduceRequest(RecordValidationFilter.java:70) ~[kroxylicious-record-validation-0.8.0.jar:?]
    at io.kroxylicious.proxy.filter.ProduceRequestFilterInvoker.onRequest(ProduceRequestFilterInvoker.java:47) ~[kroxylicious-runtime-0.8.0.jar:?]
    at io.kroxylicious.proxy.filter.SpecificFilterArrayInvoker.onRequest(SpecificFilterArrayInvoker.java:651) ~[kroxylicious-runtime-0.8.0.jar:?]
    at io.kroxylicious.proxy.filter.SafeInvoker.onRequest(SafeInvoker.java:34) ~[kroxylicious-runtime-0.8.0.jar:?]
    at io.kroxylicious.proxy.internal.FilterHandler.dispatchDecodedRequest(FilterHandler.java:219) ~[kroxylicious-runtime-0.8.0.jar:?]
    at io.kroxylicious.proxy.internal.FilterHandler.writeDecodedRequest(FilterHandler.java:200) ~[kroxylicious-runtime-0.8.0.jar:?]
    at io.kroxylicious.proxy.internal.FilterHandler.write(FilterHandler.java:138) ~[kroxylicious-runtime-0.8.0.jar:?]
    at io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:891) ~[netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeWrite(AbstractChannelHandlerContext.java:875) ~[netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:984) ~[netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:868) ~[netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.kroxylicious.proxy.internal.FilterHandler.forwardRequest(FilterHandler.java:336) ~[kroxylicious-runtime-0.8.0.jar:?]
    at io.kroxylicious.proxy.internal.FilterHandler.handleRequestFilterResult(FilterHandler.java:266) ~[kroxylicious-runtime-0.8.0.jar:?]
    at io.kroxylicious.proxy.internal.FilterHandler.lambda$configureRequestFilterChain$12(FilterHandler.java:228) ~[kroxylicious-runtime-0.8.0.jar:?]
    at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:684) [?:?]
    at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:662) [?:?]
    at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2168) [?:?]
    at io.kroxylicious.proxy.internal.FilterHandler.configureRequestFilterChain(FilterHandler.java:228) [kroxylicious-runtime-0.8.0.jar:?]
    at io.kroxylicious.proxy.internal.FilterHandler.writeDecodedRequest(FilterHandler.java:208) [kroxylicious-runtime-0.8.0.jar:?]
    at io.kroxylicious.proxy.internal.FilterHandler.write(FilterHandler.java:138) [kroxylicious-runtime-0.8.0.jar:?]
    at io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:891) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeWrite(AbstractChannelHandlerContext.java:875) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:984) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:868) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.DefaultChannelPipeline.write(DefaultChannelPipeline.java:1014) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannel.write(AbstractChannel.java:300) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.kroxylicious.proxy.internal.KafkaProxyFrontendHandler.forwardOutbound(KafkaProxyFrontendHandler.java:364) [kroxylicious-runtime-0.8.0.jar:?]
    at io.kroxylicious.proxy.internal.KafkaProxyFrontendHandler.channelRead(KafkaProxyFrontendHandler.java:191) [kroxylicious-runtime-0.8.0.jar:?]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:93) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.kroxylicious.proxy.internal.ResponseOrderer.channelRead(ResponseOrderer.java:56) [kroxylicious-runtime-0.8.0.jar:?]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346) [netty-codec-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318) [netty-codec-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918) [netty-transport-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:799) [netty-transport-classes-epoll-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:501) [netty-transport-classes-epoll-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:399) [netty-transport-classes-epoll-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994) [netty-common-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.112.Final.jar:4.1.112.Final]
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.112.Final.jar:4.1.112.Final]
    at java.base/java.lang.Thread.run(Thread.java:840) [?:?]
carlesarnal commented 3 weeks ago

I think this no longer happens in 3.x, but I'll see what I can do for 2.x.