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

dev mode crashes when adding and removing scope producer #35381

Closed
Postremus opened this issue Aug 16, 2023 · 8 comments · Fixed by #35399
Closed

dev mode crashes when adding and removing scope producer #35381

Postremus opened this issue Aug 16, 2023 · 8 comments · Fixed by #35399
Assignees
Labels
area/devmode kind/bug Something isn't working
Milestone

Comments

@Postremus
Copy link
Member

Describe the bug

I ran into following situation just a few minutes ago.

An internal lib of ours requires that I produce an instance of a configuration bean in my project. no problems here.

I added following producer:

import jakarta.enterprise.context.ApplicationScoped;
import jakarta.ws.rs.Produces;

@ApplicationScoped
public class SomeBeanProducer {

    @Produces
    SomeBean produce() {
        SomeBean bean = new SomeBean("value");

        return bean;
    }
}

I forced a a restart (by pressing "s"). Again "warning Unsatisfied dependency".
Strange.. I thought this was enough in quarkus. Lets add an @ApplicationScoped to be sure.
Again restart.
No warning anymore.

Okay, just to be sure, why did this not work? Lets remove the scope again.
Again restart

And now my quarkus just crashed. I now have to start quarkus again using mvn quarkus:dev. not ideal.
Remember, the injects are normally folded in my idea configuration.

I see 2 problems here:

  • first of all, hard crashes should never happen in a perfect world.
  • Also, I often have these problems with ws.rs.Produces vs jakarta.inject.Produces. Can quarkus maybe log a warning If the wrong annotation is used?

Expected behavior

Crashes are not cool

Actual behavior

MNP@NANBCHL9NG3 MINGW64 /c/workspaces/toryu/cdi-crash-scope
$ mvn clean compile quarkus:dev
[INFO] Scanning for projects...
[INFO] 
[INFO] ----------------------< org.acme:cdi-crash-scope >----------------------
[INFO] Building cdi-crash-scope 1.0.0-SNAPSHOT
[INFO] --------------------------------[ jar ]---------------------------------
[INFO] 
[INFO] --- maven-clean-plugin:2.5:clean (default-clean) @ cdi-crash-scope ---
[INFO] Deleting C:\workspaces\toryu\cdi-crash-scope\target
[INFO] 
[INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ cdi-crash-scope ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] Copying 2 resources
[INFO] 
[INFO] --- quarkus-maven-plugin:3.2.4.Final:generate-code (default) @ cdi-crash-scope ---
[INFO] 
[INFO] --- maven-compiler-plugin:3.11.0:compile (default-compile) @ cdi-crash-scope ---
[INFO] Changes detected - recompiling the module! :source
[INFO] Compiling 3 source files with javac [debug release 17] to target\classes
[INFO] 
[INFO] --- quarkus-maven-plugin:3.2.4.Final:dev (default-cli) @ cdi-crash-scope ---
[INFO] Invoking resources:2.6:testResources (default-testResources) @ cdi-crash-scope
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] skip non existing resourceDirectory C:\workspaces\toryu\cdi-crash-scope\src\test\resources
[INFO] Invoking quarkus:3.2.4.Final:generate-code-tests (default) @ cdi-crash-scope
[INFO] Invoking compiler:3.11.0:testCompile (default-testCompile) @ cdi-crash-scope
[INFO] Changes detected - recompiling the module! :dependency
[INFO] Compiling 2 source files with javac [debug release 17] to target\test-classes
Listening for transport dt_socket at address: 5005
2023-08-16 17:08:22,295 INFO  [io.qua.dep.dev.IsolatedDevModeMain] (main) Attempting to start live reload endpoint to recover from previous Quarkus startup failure
2023-08-16 17:08:22,783 ERROR [io.qua.dep.dev.IsolatedDevModeMain] (main) Failed to start quarkus: java.lang.RuntimeException: io.quarkus.builder.BuildException: Build failure: Build failed due to errors
        [error]: Build step io.quarkus.arc.deployment.ArcProcessor#validate threw an exception: jakarta.enterprise.inject.spi.DeploymentException: jakarta.enterprise.inject.UnsatisfiedResolutionException: Unsatisfied dependency for type org.acme.SomeBean and qualifiers [@Defau
lt]
        - java member: org.acme.GreetingResource#bean
        - declared on CLASS bean [types=[org.acme.GreetingResource, java.lang.Object], qualifiers=[@Default, @Any], target=org.acme.GreetingResource]
        at io.quarkus.arc.processor.BeanDeployment.processErrors(BeanDeployment.java:1435)
        at io.quarkus.arc.processor.BeanDeployment.init(BeanDeployment.java:310)
        at io.quarkus.arc.processor.BeanProcessor.initialize(BeanProcessor.java:155)
        at io.quarkus.arc.deployment.ArcProcessor.validate(ArcProcessor.java:469)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:568)
        at io.quarkus.deployment.ExtensionLoader$3.execute(ExtensionLoader.java:864)
        at io.quarkus.builder.BuildContext.run(BuildContext.java:282)
        at org.jboss.threads.ContextHandler$1.runWith(ContextHandler.java:18)
        at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
        at java.base/java.lang.Thread.run(Thread.java:833)
        at org.jboss.threads.JBossThread.run(JBossThread.java:501)
Caused by: jakarta.enterprise.inject.UnsatisfiedResolutionException: Unsatisfied dependency for type org.acme.SomeBean and qualifiers [@Default]
        - java member: org.acme.GreetingResource#bean
        - declared on CLASS bean [types=[org.acme.GreetingResource, java.lang.Object], qualifiers=[@Default, @Any], target=org.acme.GreetingResource]
        at io.quarkus.arc.processor.Beans.resolveInjectionPoint(Beans.java:477)
        at io.quarkus.arc.processor.BeanInfo.init(BeanInfo.java:624)
        at io.quarkus.arc.processor.BeanDeployment.init(BeanDeployment.java:298)
        ... 13 more

        at io.quarkus.runner.bootstrap.AugmentActionImpl.runAugment(AugmentActionImpl.java:336)
        at io.quarkus.runner.bootstrap.AugmentActionImpl.createInitialRuntimeApplication(AugmentActionImpl.java:253)
        at io.quarkus.runner.bootstrap.AugmentActionImpl.createInitialRuntimeApplication(AugmentActionImpl.java:60)
        at io.quarkus.deployment.dev.IsolatedDevModeMain.firstStart(IsolatedDevModeMain.java:82)
        at io.quarkus.deployment.dev.IsolatedDevModeMain.accept(IsolatedDevModeMain.java:423)
        at io.quarkus.deployment.dev.IsolatedDevModeMain.accept(IsolatedDevModeMain.java:55)
        at io.quarkus.bootstrap.app.CuratedApplication.runInCl(CuratedApplication.java:138)
        at io.quarkus.bootstrap.app.CuratedApplication.runInAugmentClassLoader(CuratedApplication.java:93)
        at io.quarkus.deployment.dev.DevModeMain.start(DevModeMain.java:131)
        at io.quarkus.deployment.dev.DevModeMain.main(DevModeMain.java:62)
Caused by: io.quarkus.builder.BuildException: Build failure: Build failed due to errors
        [error]: Build step io.quarkus.arc.deployment.ArcProcessor#validate threw an exception: jakarta.enterprise.inject.spi.DeploymentException: jakarta.enterprise.inject.UnsatisfiedResolutionException: Unsatisfied dependency for type org.acme.SomeBean and qualifiers [@Defau
lt]
        - java member: org.acme.GreetingResource#bean
        - declared on CLASS bean [types=[org.acme.GreetingResource, java.lang.Object], qualifiers=[@Default, @Any], target=org.acme.GreetingResource]
        at io.quarkus.arc.processor.BeanDeployment.processErrors(BeanDeployment.java:1435)
        at io.quarkus.arc.processor.BeanDeployment.init(BeanDeployment.java:310)
        at io.quarkus.arc.processor.BeanProcessor.initialize(BeanProcessor.java:155)
        at io.quarkus.arc.deployment.ArcProcessor.validate(ArcProcessor.java:469)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:568)
        at io.quarkus.deployment.ExtensionLoader$3.execute(ExtensionLoader.java:864)
        at io.quarkus.builder.BuildContext.run(BuildContext.java:282)
        at org.jboss.threads.ContextHandler$1.runWith(ContextHandler.java:18)
        at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
        at java.base/java.lang.Thread.run(Thread.java:833)
        at org.jboss.threads.JBossThread.run(JBossThread.java:501)
Caused by: jakarta.enterprise.inject.UnsatisfiedResolutionException: Unsatisfied dependency for type org.acme.SomeBean and qualifiers [@Default]
        - java member: org.acme.GreetingResource#bean
        - declared on CLASS bean [types=[org.acme.GreetingResource, java.lang.Object], qualifiers=[@Default, @Any], target=org.acme.GreetingResource]
        at io.quarkus.arc.processor.Beans.resolveInjectionPoint(Beans.java:477)
        at io.quarkus.arc.processor.BeanInfo.init(BeanInfo.java:624)
        at io.quarkus.arc.processor.BeanDeployment.init(BeanDeployment.java:298)
        ... 13 more

        at io.quarkus.builder.Execution.run(Execution.java:123)
        at io.quarkus.builder.BuildExecutionBuilder.execute(BuildExecutionBuilder.java:79)
        at io.quarkus.deployment.QuarkusAugmentor.run(QuarkusAugmentor.java:160)
        at io.quarkus.runner.bootstrap.AugmentActionImpl.runAugment(AugmentActionImpl.java:332)
        ... 9 more
Caused by: jakarta.enterprise.inject.spi.DeploymentException: jakarta.enterprise.inject.UnsatisfiedResolutionException: Unsatisfied dependency for type org.acme.SomeBean and qualifiers [@Default]
        - java member: org.acme.GreetingResource#bean
        - declared on CLASS bean [types=[org.acme.GreetingResource, java.lang.Object], qualifiers=[@Default, @Any], target=org.acme.GreetingResource]
        at io.quarkus.arc.processor.BeanDeployment.processErrors(BeanDeployment.java:1435)
        at io.quarkus.arc.processor.BeanDeployment.init(BeanDeployment.java:310)
        at io.quarkus.arc.processor.BeanProcessor.initialize(BeanProcessor.java:155)
        at io.quarkus.arc.deployment.ArcProcessor.validate(ArcProcessor.java:469)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:568)
        at io.quarkus.deployment.ExtensionLoader$3.execute(ExtensionLoader.java:864)
        at io.quarkus.builder.BuildContext.run(BuildContext.java:282)
        at org.jboss.threads.ContextHandler$1.runWith(ContextHandler.java:18)
        at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
        at java.base/java.lang.Thread.run(Thread.java:833)
        at org.jboss.threads.JBossThread.run(JBossThread.java:501)
Caused by: jakarta.enterprise.inject.UnsatisfiedResolutionException: Unsatisfied dependency for type org.acme.SomeBean and qualifiers [@Default]
        - java member: org.acme.GreetingResource#bean
        - declared on CLASS bean [types=[org.acme.GreetingResource, java.lang.Object], qualifiers=[@Default, @Any], target=org.acme.GreetingResource]
        at io.quarkus.arc.processor.Beans.resolveInjectionPoint(Beans.java:477)
        at io.quarkus.arc.processor.BeanInfo.init(BeanInfo.java:624)
        at io.quarkus.arc.processor.BeanDeployment.init(BeanDeployment.java:298)
        ... 13 more


2023-08-16 17:08:39,439 INFO  [io.qua.dep.dev.RuntimeUpdatesProcessor] (Aesh InputStream Reader) Restarting quarkus due to changes in SomeBeanProducer.class.
__  ____  __  _____   ___  __ ____  ______
 --/ __ \/ / / / _ | / _ \/ //_/ / / / __/
 -/ /_/ / /_/ / __ |/ , _/ ,< / /_/ /\ \
--\___\_\____/_/ |_/_/|_/_/|_|\____/___/
2023-08-16 17:08:40,461 INFO  [io.quarkus] (Quarkus Main Thread) cdi-crash-scope 1.0.0-SNAPSHOT on JVM (powered by Quarkus 3.2.4.Final) started in 1.014s. Listening on: http://localhost:8080

2023-08-16 17:08:40,464 INFO  [io.quarkus] (Quarkus Main Thread) Profile dev activated. Live Coding activated.
2023-08-16 17:08:40,466 INFO  [io.quarkus] (Quarkus Main Thread) Installed features: [cdi, resteasy-reactive, smallrye-context-propagation, vertx]
2023-08-16 17:08:40,468 INFO  [io.qua.dep.dev.RuntimeUpdatesProcessor] (Aesh InputStream Reader) Live reload total time: 1.727s
2023-08-16 17:08:44,940 INFO  [io.qua.dep.dev.RuntimeUpdatesProcessor] (Aesh InputStream Reader) Restarting quarkus due to changes in SomeBeanProducer.class.
2023-08-16 17:08:45,076 INFO  [io.quarkus] (Quarkus Main Thread) cdi-crash-scope stopped in 0.134s

--
Tests paused
Press [e] to edit command line args (currently ''), [r] to resume testing, [o] Toggle test output, [:] for the terminal, [h] for more options>
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  33.602 s
[INFO] Finished at: 2023-08-16T17:08:45+02:00
[INFO] ------------------------------------------------------------------------

How to Reproduce?

Reproducer:
cdi-crash-scope.zip

  1. mvn clean compile quarkus:dev
  2. -> unsatisfied dependency
  3. Add an @ApplicationScoped to the producer method in SomeBeanProducer
  4. Restart by pressing s in terminal -> quarkus now starts
  5. Remove the previously added scope annotation
  6. Restart -> quarkus crashes

Output of uname -a or ver

MINGW64_NT-10.0-19045 NANBCHL9NG3 3.3.6-341.x86_64 2022-09-05 20:28 UTC x86_64 Msys

Output of java -version

openjdk 17.0.4 2022-07-19 OpenJDK Runtime Environment Temurin-17.0.4+8 (build 17.0.4+8) OpenJDK 64-Bit Server VM Temurin-17.0.4+8 (build 17.0.4+8, mixed mode, sharing)

GraalVM version (if different from Java)

No response

Quarkus version or git rev

3.2.4.Final

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

Apache Maven 3.8.4 (9b656c72d54e5bacbed989b64718c159fe39b537) Maven home: C:\eclipse\tools\java\maven Java version: 17.0.4, vendor: Eclipse Adoptium, runtime: C:\eclipse\tools\java\17 Default locale: de_DE, platform encoding: Cp1252 OS name: "windows 10", version: "10.0", arch: "amd64", family: "windows"

Additional information

No response

@Postremus Postremus added the kind/bug Something isn't working label Aug 16, 2023
@quarkus-bot quarkus-bot bot added area/devmode env/windows Impacts Windows machines labels Aug 16, 2023
@Postremus Postremus added area/arc Issue related to ARC (dependency injection) and removed env/windows Impacts Windows machines labels Aug 16, 2023
@gsmet
Copy link
Member

gsmet commented Aug 16, 2023

/cc @mkouba @manovotn @Ladicek

@manovotn
Copy link
Contributor

manovotn commented Aug 16, 2023

Also, I often have these problems with ws.rs.Produces vs jakarta.inject.Produces. Can quarkus maybe log a warning If the wrong annotation is used?

This should already be happening IIRC.
EDIT: The processor I am talking about is here - https://github.com/quarkusio/quarkus/blob/main/extensions/arc/deployment/src/main/java/io/quarkus/arc/deployment/WrongAnnotationUsageProcessor.java

Add an @ApplicationScoped to the producer method in SomeBeanProducer

This is curious because even without scope annotation on the method, Arc should pick up the producer and just automatically assign it dependent scope by default - which would mean the bean should be picked up at all times.
Although I am only looking at this from my phone now, will need to test it out tomorrow hands-on (or Martin/Ladislav).

@mkouba
Copy link
Contributor

mkouba commented Aug 17, 2023

Also, I often have these problems with ws.rs.Produces vs jakarta.inject.Produces. Can quarkus maybe log a warning If the wrong annotation is used?

This should already be happening IIRC.

I think that we only detect this kind of problems after the dependencies are validated.

Add an @ApplicationScoped to the producer method in SomeBeanProducer

This is curious because even without scope annotation on the method, Arc should pick up the producer and just automatically assign it dependent scope by default - which would mean the bean should be picked up at all times. Although I am only looking at this from my phone now, will need to test it out tomorrow hands-on (or Martin/Ladislav).

And it does. @Postremus But the reproducer has the wrong annotation - @jakarta.ws.rs.Produces. If you add a scope annotation to the producer method, then a Quarkus-specific Simplified Producer Method Declaration comes into play, i.e. the right @Produces is added automatically. You can try to use quarkus.arc.auto-producer-methods=false to disable this feature.

@mkouba mkouba closed this as not planned Won't fix, can't repro, duplicate, stale Aug 17, 2023
@Postremus
Copy link
Member Author

Postremus commented Aug 17, 2023

@mkouba okay, sure, but why does dev mode crash when I remove the @ApplicationScoped? See reproducer in op.

@Postremus Postremus reopened this Aug 17, 2023
@mkouba
Copy link
Contributor

mkouba commented Aug 17, 2023

@mkouba okay, sure, but why does dev mode crash when I remove the @ApplicationScoped? See reproducer in op.

Ok sorry, I skipped the part about crashing ;-). So I can confirm that the app is stopped with no error message or anything. And TBH I have no idea why. But it does not look like a JVM crash as I don't see any dump file...

2023-08-17 09:10:35,188 INFO  [io.qua.dep.dev.RuntimeUpdatesProcessor] (Aesh InputStream Reader) Restarting quarkus due to changes in SomeBeanProducer.class.
2023-08-17 09:10:35,194 INFO  [io.quarkus] (Quarkus Main Thread) cdi-crash-scope stopped in 0.005s

@Ladicek
Copy link
Contributor

Ladicek commented Aug 17, 2023

I don't think we can in general detect misuse of jakarta.ws.rs.Produces. The only scenario where I'd be confident in printing a warning is a method annotated with @jakarta.ws.rs.Produces and also with a scope annotation.

Re the "crash", that is indeed interesting. Even if I enable debug logging for io.quarkus, there's nothing:

2023-08-17 09:08:49,124 INFO  [io.qua.dep.dev.RuntimeUpdatesProcessor] (Aesh InputStream Reader) Restarting quarkus due to changes in SomeBeanProducer.class.
2023-08-17 09:08:49,125 DEBUG [io.qua.run.Application] (Quarkus Main Thread) Stopping application
2023-08-17 09:08:49,126 DEBUG [io.qua.run.shu.ShutdownRecorder] (Quarkus Main Thread) Attempting to gracefully shutdown.
2023-08-17 09:08:49,135 DEBUG [io.qua.arc.impl] (Quarkus Main Thread) ArC DI container shut down
2023-08-17 09:08:49,136 INFO  [io.quarkus] (Quarkus Main Thread) cdi-crash-scope stopped in 0.010s

I'm relatively sure this has nothing to do with ArC. There's probably some internal logic that triggers shutdown based on a previous failure, and that logic could probably use some improvement... 🤷

@mkouba
Copy link
Contributor

mkouba commented Aug 17, 2023

I don't think we can in general detect misuse of jakarta.ws.rs.Produces. The only scenario where I'd be confident in printing a warning is a method annotated with @jakarta.ws.rs.Produces and also with a scope annotation.

Ladislav is right, the WrongAnnotationUsageProcessor does not handle jakarta.ws.rs.Produces for the reasons mentioned above.

@mkouba
Copy link
Contributor

mkouba commented Aug 17, 2023

It seems that the problem only occurs if Quarkus fails to start the app initially, i.e. it works fine if you add @ApplicationScoped to the producer method in SomeBeanProducer, then start the dev mode and then remove/add the annotation repeatedly.

I suspect that if the startup fails in the IsolatedDevModeMain here then the default exit code handler in ApplicationLifecycleManager is not replaced and so the app simply exits.

I will try to fix this locally and we'll see.

@mkouba mkouba removed the area/arc Issue related to ARC (dependency injection) label Aug 17, 2023
@mkouba mkouba self-assigned this Aug 17, 2023
mkouba added a commit to mkouba/quarkus that referenced this issue Aug 17, 2023
- IsolatedDevModeMain - replace the default exit handler _before_ the app is created
- previously, if there was a deployment problem then the default exit
handler was used; as a result the dev mode exited after the subsequent build
failure
- run DevModeListener.afterFirstStart() during restart if the first run
  did not succeed
- fix FixConfigOnErrorTest - add missing Test annotation
- fix Qute and ArC optimizations to skip generation of certain classes
- fixes quarkusio#35381
@quarkus-bot quarkus-bot bot added this to the 3.4 - main milestone Aug 19, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/devmode kind/bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants