Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ClassCastException for AVRO generated sources when running in dev mode #18776

Closed
maxhov opened this issue Jul 17, 2021 · 14 comments · Fixed by #19043
Closed

ClassCastException for AVRO generated sources when running in dev mode #18776

maxhov opened this issue Jul 17, 2021 · 14 comments · Fixed by #19043
Labels
Milestone

Comments

@maxhov
Copy link

maxhov commented Jul 17, 2021

Describe the bug

I am trying out Quarkus and following the guide Quarkus - Using Apache Kafka with Schema Registry and Avro .

When the application is first started in dev mode everything works as expected. The created Movie resources are sent to Kafka and consequently available via the consumer. However, when a change is made and the livereload kicks in, the class are no longer available in the QuarkusClassLoader and the following stack trace is observed:

java.lang.ClassCastException: class org.acme.kafka.quarkus.Movie cannot be cast to class org.acme.kafka.quarkus.Movie (org.acme.kafka.quarkus.Movie is in unnamed module of loader io.quarkus.bootstrap.classloading.QuarkusClassLoader @77e80a5e; org.acme.kafka.quarkus.Movie is in unnamed module of loader io.quarkus.bootstrap.classloading.QuarkusClassLoader @6d36a933)
        at io.smallrye.context.impl.wrappers.SlowContextualFunction.apply(SlowContextualFunction.java:21)
        at io.smallrye.mutiny.operators.multi.MultiMapOp$MapProcessor.onItem(MultiMapOp.java:42)
        at io.smallrye.mutiny.subscription.MultiSubscriber.onNext(MultiSubscriber.java:61)
        at io.smallrye.mutiny.operators.multi.multicast.MultiPublishOp$PublishSubscriber.drain(MultiPublishOp.java:475)
        at io.smallrye.mutiny.operators.multi.multicast.MultiPublishOp$PublishSubscriber.onItem(MultiPublishOp.java:182)
        at io.smallrye.mutiny.operators.multi.MultiMapOp$MapProcessor.onItem(MultiMapOp.java:50)
        at io.smallrye.mutiny.subscription.MultiSubscriber.onNext(MultiSubscriber.java:61)
        at io.smallrye.mutiny.operators.multi.MultiFlatMapOp$FlatMapMainSubscriber.tryEmit(MultiFlatMapOp.java:228)
        at io.smallrye.mutiny.operators.multi.MultiFlatMapOp$FlatMapInner.onItem(MultiFlatMapOp.java:595)
        at io.smallrye.mutiny.subscription.MultiSubscriber.onNext(MultiSubscriber.java:61)
        at io.smallrye.mutiny.converters.uni.UniToMultiPublisher$UniToMultiSubscription.onItem(UniToMultiPublisher.java:77)
        at io.smallrye.mutiny.operators.uni.UniOnItemOrFailureFlatMap$UniOnItemOrFailureFlatMapProcessor.onItem(UniOnItemOrFailureFlatMap.java:56)
        at io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem$KnownItemSubscription.forward(UniCreateFromKnownItem.java:38)
        at io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem$KnownItemSubscription.access$100(UniCreateFromKnownItem.java:26)
        at io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem.subscribe(UniCreateFromKnownItem.java:23)
        at io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
        at io.smallrye.mutiny.operators.uni.UniOnItemOrFailureFlatMap$UniOnItemOrFailureFlatMapProcessor.performInnerSubscription(UniOnItemOrFailureFlatMap.java:99)
        at io.smallrye.mutiny.operators.uni.UniOnItemOrFailureFlatMap$UniOnItemOrFailureFlatMapProcessor.onItem(UniOnItemOrFailureFlatMap.java:54)
        at io.smallrye.mutiny.operators.uni.builders.UniCreateFromCompletionStage$CompletionStageUniSubscription.forwardResult(UniCreateFromCompletionStage.java:63)
        at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859)
        at java.base/java.util.concurrent.CompletableFuture.uniWhenCompleteStage(CompletableFuture.java:883)
        at java.base/java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:2321)
        at java.base/java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:143)
        at io.smallrye.mutiny.operators.uni.builders.UniCreateFromCompletionStage$CompletionStageUniSubscription.forward(UniCreateFromCompletionStage.java:51)
        at io.smallrye.mutiny.operators.uni.builders.UniCreateFromCompletionStage.subscribe(UniCreateFromCompletionStage.java:35)
        at io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
        at io.smallrye.mutiny.operators.uni.UniOnItemOrFailureFlatMap.subscribe(UniOnItemOrFailureFlatMap.java:27)
        at io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
        at io.smallrye.mutiny.converters.uni.UniToMultiPublisher$UniToMultiSubscription.request(UniToMultiPublisher.java:61)
        at io.smallrye.mutiny.operators.multi.MultiFlatMapOp$FlatMapInner.onSubscribe(MultiFlatMapOp.java:589)
        at io.smallrye.mutiny.converters.uni.UniToMultiPublisher.subscribe(UniToMultiPublisher.java:26)
        at io.smallrye.mutiny.groups.MultiCreate$1.subscribe(MultiCreate.java:156)
        at io.smallrye.mutiny.operators.multi.MultiFlatMapOp$FlatMapMainSubscriber.onItem(MultiFlatMapOp.java:191)
        at io.smallrye.mutiny.subscription.MultiSubscriber.onNext(MultiSubscriber.java:61)
        at io.smallrye.mutiny.subscription.SafeSubscriber.onNext(SafeSubscriber.java:98)
        at io.smallrye.mutiny.helpers.HalfSerializer.onNext(HalfSerializer.java:31)
        at io.smallrye.mutiny.helpers.StrictMultiSubscriber.onItem(StrictMultiSubscriber.java:83)
        at io.smallrye.mutiny.subscription.MultiSubscriber.onNext(MultiSubscriber.java:61)
        at io.smallrye.mutiny.subscription.SafeSubscriber.onNext(SafeSubscriber.java:98)
        at io.smallrye.mutiny.helpers.HalfSerializer.onNext(HalfSerializer.java:31)
        at io.smallrye.mutiny.helpers.StrictMultiSubscriber.onItem(StrictMultiSubscriber.java:83)
        at io.smallrye.mutiny.subscription.MultiSubscriber.onNext(MultiSubscriber.java:61)
        at io.smallrye.mutiny.operators.multi.MultiFlatMapOp$FlatMapMainSubscriber.tryEmit(MultiFlatMapOp.java:228)
        at io.smallrye.mutiny.operators.multi.MultiFlatMapOp$FlatMapInner.onItem(MultiFlatMapOp.java:595)
        at io.smallrye.mutiny.subscription.MultiSubscriber.onNext(MultiSubscriber.java:61)
        at io.smallrye.mutiny.converters.uni.UniToMultiPublisher$UniToMultiSubscription.onItem(UniToMultiPublisher.java:77)
        at io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.onItem(UniOnItemTransformToUni.java:60)
        at io.smallrye.mutiny.operators.uni.builders.DefaultUniEmitter.complete(DefaultUniEmitter.java:36)
        at io.smallrye.mutiny.groups.UniOnNull.lambda$failWith$1(UniOnNull.java:43)
        at io.smallrye.context.impl.wrappers.SlowContextualBiConsumer.accept(SlowContextualBiConsumer.java:21)
        at io.smallrye.mutiny.groups.UniOnItem.lambda$transformToUni$4(UniOnItem.java:169)
        at io.smallrye.context.impl.wrappers.SlowContextualConsumer.accept(SlowContextualConsumer.java:21)
        at io.smallrye.mutiny.operators.uni.builders.UniCreateWithEmitter.subscribe(UniCreateWithEmitter.java:22)
        at io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
        at io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.performInnerSubscription(UniOnItemTransformToUni.java:81)
        at io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.onItem(UniOnItemTransformToUni.java:57)
        at io.smallrye.mutiny.operators.uni.builders.UniCreateFromCompletionStage$CompletionStageUniSubscription.forwardResult(UniCreateFromCompletionStage.java:63)
        at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859)
        at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
        at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2143)
        at io.quarkus.smallrye.reactivemessaging.runtime.devmode.DevModeSupportConnectorFactoryInterceptor.lambda$intercept$0(DevModeSupportConnectorFactoryInterceptor.java:42)
        at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859)
        at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
        at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2143)
        at io.quarkus.smallrye.reactivemessaging.runtime.devmode.ReactiveMessagingHotReplacementSetup$OnMessage$1.run(ReactiveMessagingHotReplacementSetup.java:44)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
        at java.base/java.lang.Thread.run(Thread.java:831)

Observing the issue when runnning from the command line with mvn quarkus:dev as well as running from IntelliJ 2021.1.3.

Expected behavior

AVRO generated classes are available after livereload.

Actual behavior

Not sure, but my initial thoughts are that AVRO generated classes are no longer available on the classpath due to ClassLoader switching?

How to Reproduce?

Reproduce:

  1. Follow the guide Quarkus - Using Apache Kafka with Schema Registry and Avro
  2. Start the application in dev mode
  3. Observe that the application works as expected
  4. Make a change in the source code with the consumer curl request still open curl -N http://localhost:8080/consumed-movies
  5. Create a new resouce and observe that there are no new events being sent from the consumer
  6. Restart the consumer curl and observe the stack trace

Output of uname -a or ver

Darwin Macbook 20.5.0 Darwin Kernel Version 20.5.0: Sat May 8 05:10:33 PDT 2021; root:xnu-7195.121.3~9/RELEASE_X86_64 x86_64

Output of java -version

Tried Java 11, 15 and 16

GraalVM version (if different from Java)

No response

Quarkus version or git rev

No response

Build tool (ie. output of mvnw --version or gradlew --version)

Apache Maven 3.8.1 (05c21c65bdfed0f71a2f2ada8b84da59348c4c5d)

Additional information

No response

@maxhov maxhov added the kind/bug Something isn't working label Jul 17, 2021
@gsmet
Copy link
Member

gsmet commented Jul 21, 2021

@michalszynkiewicz @ozangunalp @cescoffier could one of you investigate this one? There's a good chance we might need Stuart here but let's at least investigate a bit what's going on and if it's still an issue with current main.

@ozangunalp
Copy link
Contributor

I can reproduce this with the current main on Java 11.

@michalszynkiewicz
Copy link
Member

I'm a bit surprised the SSE endpoint stays alive (and stuck) on reload...

@michalszynkiewicz
Copy link
Member

I see the SSE endpoint, after restart, still uses the old classloader.
The endpoint to feed movies uses the new classloader.

I think that's the issue. I will try to dig into it a bit further.

@michalszynkiewicz
Copy link
Member

I see this behavior (keeping the old/pre-reload classloaders on SSE endpoints if the call is in progress when the app is reloaded) also without kafka. I don't know enough about the server part of RestEasy Reactive to fix it quickly, I think.

@cescoffier
Copy link
Member

A workaround could be to turn off the hot reload using instrumentation.

But during the hot reload, it should cut the SSE connection. It's up to the client side to reconnect.

@ozangunalp
Copy link
Contributor

I think it is off by default, and when I activate it using quarkus.live-reload.instrumentation=true I don't have the issue anymore.

@michalszynkiewicz
Copy link
Member

A workaround could be to turn off the hot reload using instrumentation.

But during the hot reload, it should cut the SSE connection. It's up to the client side to reconnect.

Yes, that's what we do with gRPC streams.

@geoand @FroMage @stuartwdouglas can one of you give some pointers on implementing this or take a look at it himself?

@geoand
Copy link
Contributor

geoand commented Jul 22, 2021

Pointers for which part exactly?

@michalszynkiewicz
Copy link
Member

good question :D It seems we miss closing an SSE connection on the app reload.
I don't know how it's implemented but we may need some way to gather such connections when in dev mode

@geoand
Copy link
Contributor

geoand commented Jul 22, 2021

That's one for @FroMage

@FroMage
Copy link
Member

FroMage commented Jul 27, 2021

So we have to keep track of all the open connections when in DEV mode? This sort of thing doesn't appear to be limited to SSE though: it can happen with any REST call that is streaming.

What is the producer of the SSE feed? Is it Reactive Messaging? Shouldn't it be responsible for cutting the emission? Or is it the case that it can keep the Multi open when hot-reloading and it's only the SSE consumer that's having issues?

@michalszynkiewicz can you point me to where you keep track of gRPC streams in DEV mode for that, please?

@michalszynkiewicz
Copy link
Member

In gRPC the calls that are made with our stubs (we don't close streams for grpc-java stubs yet) are handled thorugh https://github.com/quarkusio/quarkus/blob/master/extensions/grpc/stubs/src/main/java/io/quarkus/grpc/runtime/ServerCalls.java
There, the streaming calls are added to a StreamCollector, which in prod mode is no-op, and in dev mode is https://github.com/quarkusio/quarkus/blob/main/extensions/grpc/runtime/src/main/java/io/quarkus/grpc/runtime/devmode/DevModeStreamsCollector.java

Then, on restart, shutdown on this collector is called: https://github.com/quarkusio/quarkus/blob/main/extensions/grpc/runtime/src/main/java/io/quarkus/grpc/runtime/devmode/GrpcServerReloader.java#L55

This logic is invoked from a ShutdownTask registered in a ShutdownContext.

stuartwdouglas added a commit to stuartwdouglas/quarkus that referenced this issue Jul 28, 2021
This will prevent old persistent connections hanging onto the old
shutdown application.

Fixes quarkusio#18776
stuartwdouglas added a commit to stuartwdouglas/quarkus that referenced this issue Jul 28, 2021
stuartwdouglas added a commit to stuartwdouglas/quarkus that referenced this issue Jul 28, 2021
This will prevent old persistent connections hanging onto the old
shutdown application.

Fixes quarkusio#18776
stuartwdouglas added a commit to stuartwdouglas/quarkus that referenced this issue Jul 28, 2021
stuartwdouglas added a commit to stuartwdouglas/quarkus that referenced this issue Jul 28, 2021
This will prevent old persistent connections hanging onto the old
shutdown application.

Fixes quarkusio#18776
stuartwdouglas added a commit to stuartwdouglas/quarkus that referenced this issue Jul 28, 2021
@stuartwdouglas
Copy link
Member

The linked PR should fix both issues

stuartwdouglas added a commit to stuartwdouglas/quarkus that referenced this issue Jul 28, 2021
This will prevent old persistent connections hanging onto the old
shutdown application.

Fixes quarkusio#18776
stuartwdouglas added a commit to stuartwdouglas/quarkus that referenced this issue Jul 28, 2021
@quarkus-bot quarkus-bot bot added this to the 2.2 - main milestone Jul 28, 2021
@gsmet gsmet modified the milestones: 2.2 - main, 2.1.1.Final Aug 3, 2021
gsmet pushed a commit to gsmet/quarkus that referenced this issue Aug 3, 2021
This will prevent old persistent connections hanging onto the old
shutdown application.

Fixes quarkusio#18776

(cherry picked from commit 8394756)
gsmet pushed a commit to gsmet/quarkus that referenced this issue Aug 3, 2021
Fixes quarkusio#18776

(cherry picked from commit e5ac1e2)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

8 participants