1.6.0.CR1 - Random Classloading Problems #10371

Postremus · 2020-06-30T13:36:12Z

Describe the bug
I have a rather big project running in quarkus 1.5.2.Final without problems.
This project has about 130 modules.

Today, I tried out if there are any regressions with quarkus 1.6.
The project does not start any more in dev mode. It works fine when run as jar (in docker).

Problem looks related to classes being loaded multiple times by different instances of the classloader.
In the stacktrace below, BasePlainEntity is an @MappedSupperClass, used in multiple classes and modules.
The BasePlainEntity itself is from another external module.

The same stacktrace also happens randomly for different classes, most often though for BasePlainEntity.

Expected behavior
No Classloading problems during startup.

Actual behavior
Stacktrace always looks like this, AnnotationMetaDataProvider is the last class called before classloading stuff happens.

30.06.2020 13:15:44 INFO  [org.hibernate.validator.internal.util.Version] HV000001: Hibernate Validator 6.1.5.Final
30.06.2020 13:15:44 ERROR  [io.quarkus.runner.bootstrap.StartupActionImpl] Error running Quarkus: java.lang.reflect.InvocationTargetException
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at io.quarkus.runner.bootstrap.StartupActionImpl$3.run(StartupActionImpl.java:136)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.ExceptionInInitializerError
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
        at java.base/java.lang.Class.newInstance(Class.java:584)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:60)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:38)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:106)
        at io.quarkus.runner.GeneratedMain.main(GeneratedMain.zig:29)
        ... 6 more
Caused by: java.lang.RuntimeException: Failed to start quarkus
        at io.quarkus.runner.ApplicationImpl.<clinit>(ApplicationImpl.zig:243)
        ... 15 more
Caused by: java.lang.LinkageError: loader constraint violation: loader io.quarkus.bootstrap.classloading.QuarkusClassLoader @3b2c8bda wants to load abstract class com.product.BasePlainEntity. A different abstract class with the
 same name was previously loaded by io.quarkus.bootstrap.classloading.QuarkusClassLoader @7e1953f7. (com.product.BasePlainEntity is in unnamed module of loader io.quarkus.bootstrap.classloading.QuarkusClassLoader @7e1953f7, par
ent loader 'platform')
        at java.base/java.lang.ClassLoader.defineClass1(Native Method)
        at java.base/java.lang.ClassLoader.defineClass(ClassLoader.java:1017)
        at io.quarkus.bootstrap.classloading.QuarkusClassLoader.loadClass(QuarkusClassLoader.java:354)
        at io.quarkus.bootstrap.classloading.QuarkusClassLoader.loadClass(QuarkusClassLoader.java:317)
        at java.base/java.lang.Class.getDeclaredMethods0(Native Method)
        at java.base/java.lang.Class.privateGetDeclaredMethods(Class.java:3166)
        at java.base/java.lang.Class.getDeclaredMethods(Class.java:2309)
        at org.hibernate.validator.internal.util.privilegedactions.GetDeclaredMethods.run(GetDeclaredMethods.java:30)
        at org.hibernate.validator.internal.util.privilegedactions.GetDeclaredMethods.run(GetDeclaredMethods.java:17)
        at org.hibernate.validator.internal.metadata.provider.AnnotationMetaDataProvider.run(AnnotationMetaDataProvider.java:601)
        at org.hibernate.validator.internal.metadata.provider.AnnotationMetaDataProvider.getMethodMetaData(AnnotationMetaDataProvider.java:277)
        at org.hibernate.validator.internal.metadata.provider.AnnotationMetaDataProvider.retrieveBeanConfiguration(AnnotationMetaDataProvider.java:130)
        at org.hibernate.validator.internal.metadata.provider.AnnotationMetaDataProvider.getBeanConfiguration(AnnotationMetaDataProvider.java:120)
        at org.hibernate.validator.internal.metadata.PredefinedScopeBeanMetaDataManager.getBeanConfigurationForHierarchy(PredefinedScopeBeanMetaDataManager.java:183)
        at org.hibernate.validator.internal.metadata.PredefinedScopeBeanMetaDataManager.createBeanMetaData(PredefinedScopeBeanMetaDataManager.java:150)
        at org.hibernate.validator.internal.metadata.PredefinedScopeBeanMetaDataManager.<init>(PredefinedScopeBeanMetaDataManager.java:100)
        at org.hibernate.validator.internal.engine.PredefinedScopeValidatorFactoryImpl.<init>(PredefinedScopeValidatorFactoryImpl.java:176)
        at org.hibernate.validator.PredefinedScopeHibernateValidator.buildValidatorFactory(PredefinedScopeHibernateValidator.java:42)
        at org.hibernate.validator.internal.engine.AbstractConfigurationImpl.buildValidatorFactory(AbstractConfigurationImpl.java:430)
        at io.quarkus.hibernate.validator.runtime.HibernateValidatorRecorder$1.created(HibernateValidatorRecorder.java:130)
        at io.quarkus.arc.runtime.ArcRecorder.initBeanContainer(ArcRecorder.java:106)
        at io.quarkus.deployment.steps.ArcProcessor$generateResources-1120260799.deploy_0(ArcProcessor$generateResources-1120260799.zig:585)
        at io.quarkus.deployment.steps.ArcProcessor$generateResources-1120260799.deploy(ArcProcessor$generateResources-1120260799.zig:36)
        at io.quarkus.runner.ApplicationImpl.<clinit>(ApplicationImpl.zig:202)
        ... 15 more

30.06.2020 13:15:44 ERROR  [io.quarkus.deployment.dev.DevModeMain] Failed to start Quarkus: java.lang.RuntimeException: java.lang.LinkageError: loader constraint violation: loader io.quarkus.bootstrap.classloading.QuarkusClassLoader @3b2c8bda wants t
o load abstract class com.product.BasePlainEntity. A different abstract class with the same name was previously loaded by io.quarkus.bootstrap.classloading.QuarkusClassLoader @7e1953f7. (com.activelogistics.wolf.common.db.BaseP
lainEntity is in unnamed module of loader io.quarkus.bootstrap.classloading.QuarkusClassLoader @7e1953f7, parent loader 'platform')
        at io.quarkus.dev.appstate.ApplicationStateNotification.waitForApplicationStart(ApplicationStateNotification.java:51)
        at io.quarkus.runner.bootstrap.StartupActionImpl.runMainClass(StartupActionImpl.java:147)
        at io.quarkus.deployment.dev.IsolatedDevModeMain.firstStart(IsolatedDevModeMain.java:95)
        at io.quarkus.deployment.dev.IsolatedDevModeMain.accept(IsolatedDevModeMain.java:296)
        at io.quarkus.deployment.dev.IsolatedDevModeMain.accept(IsolatedDevModeMain.java:42)
        at io.quarkus.bootstrap.app.CuratedApplication.runInCl(CuratedApplication.java:128)
        at io.quarkus.bootstrap.app.CuratedApplication.runInAugmentClassLoader(CuratedApplication.java:81)
        at io.quarkus.deployment.dev.DevModeMain.start(DevModeMain.java:132)
        at io.quarkus.deployment.dev.DevModeMain.main(DevModeMain.java:57)
Caused by: java.lang.LinkageError: loader constraint violation: loader io.quarkus.bootstrap.classloading.QuarkusClassLoader @3b2c8bda wants to load abstract class com.product.BasePlainEntity. A different abstract class with the
 same name was previously loaded by io.quarkus.bootstrap.classloading.QuarkusClassLoader @7e1953f7. (com.product.BasePlainEntity is in unnamed module of loader io.quarkus.bootstrap.classloading.QuarkusClassLoader @7e1953f7, par
ent loader 'platform')
        at java.base/java.lang.ClassLoader.defineClass1(Native Method)
        at java.base/java.lang.ClassLoader.defineClass(ClassLoader.java:1017)
        at io.quarkus.bootstrap.classloading.QuarkusClassLoader.loadClass(QuarkusClassLoader.java:354)
        at io.quarkus.bootstrap.classloading.QuarkusClassLoader.loadClass(QuarkusClassLoader.java:317)
        at java.base/java.lang.Class.getDeclaredMethods0(Native Method)
        at java.base/java.lang.Class.privateGetDeclaredMethods(Class.java:3166)
        at java.base/java.lang.Class.getDeclaredMethods(Class.java:2309)
        at org.hibernate.validator.internal.util.privilegedactions.GetDeclaredMethods.run(GetDeclaredMethods.java:30)
        at org.hibernate.validator.internal.util.privilegedactions.GetDeclaredMethods.run(GetDeclaredMethods.java:17)
        at org.hibernate.validator.internal.metadata.provider.AnnotationMetaDataProvider.run(AnnotationMetaDataProvider.java:601)
        at org.hibernate.validator.internal.metadata.provider.AnnotationMetaDataProvider.getMethodMetaData(AnnotationMetaDataProvider.java:277)
        at org.hibernate.validator.internal.metadata.provider.AnnotationMetaDataProvider.retrieveBeanConfiguration(AnnotationMetaDataProvider.java:130)
        at org.hibernate.validator.internal.metadata.provider.AnnotationMetaDataProvider.getBeanConfiguration(AnnotationMetaDataProvider.java:120)
        at org.hibernate.validator.internal.metadata.PredefinedScopeBeanMetaDataManager.getBeanConfigurationForHierarchy(PredefinedScopeBeanMetaDataManager.java:183)
        at org.hibernate.validator.internal.metadata.PredefinedScopeBeanMetaDataManager.createBeanMetaData(PredefinedScopeBeanMetaDataManager.java:150)
        at org.hibernate.validator.internal.metadata.PredefinedScopeBeanMetaDataManager.<init>(PredefinedScopeBeanMetaDataManager.java:100)
        at org.hibernate.validator.internal.engine.PredefinedScopeValidatorFactoryImpl.<init>(PredefinedScopeValidatorFactoryImpl.java:176)
        at org.hibernate.validator.PredefinedScopeHibernateValidator.buildValidatorFactory(PredefinedScopeHibernateValidator.java:42)
        at org.hibernate.validator.internal.engine.AbstractConfigurationImpl.buildValidatorFactory(AbstractConfigurationImpl.java:430)
        at io.quarkus.hibernate.validator.runtime.HibernateValidatorRecorder$1.created(HibernateValidatorRecorder.java:130)
        at io.quarkus.arc.runtime.ArcRecorder.initBeanContainer(ArcRecorder.java:106)
        at io.quarkus.deployment.steps.ArcProcessor$generateResources-1120260799.deploy_0(ArcProcessor$generateResources-1120260799.zig:585)
        at io.quarkus.deployment.steps.ArcProcessor$generateResources-1120260799.deploy(ArcProcessor$generateResources-1120260799.zig:36)
        at io.quarkus.runner.ApplicationImpl.<clinit>(ApplicationImpl.zig:202)
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
        at java.base/java.lang.Class.newInstance(Class.java:584)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:60)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:38)
        at io.quarkus.runtime.Quarkus.run(Quarkus.java:106)
        at io.quarkus.runner.GeneratedMain.main(GeneratedMain.zig:29)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at io.quarkus.runner.bootstrap.StartupActionImpl$3.run(StartupActionImpl.java:136)
        at java.base/java.lang.Thread.run(Thread.java:834)

To Reproduce
No idea how to reproduce it. I was not able to create a small reproducer project yet.

Environment (please complete the following information):

Output of uname -a or ver:
MSYS_NT-10.0 NANB7NLNVP2 2.10.0(0.325/5/3) 2018-06-13 23:34 x86_64 Msys
Quarkus version or git rev:
1.6.0.CR1
Build tool (ie. output of mvnw --version or gradlew --version):
Apache Maven 3.6.3 (cecedd343002696d0abb50b32b541b8a6ba2883f)
Maven home: C:\eclipse\tools\apache-maven\bin..
Java version: 11.0.7, vendor: Azul Systems, Inc., runtime: C:\eclipse\tools\zulu11.39.15-ca-jdk11.0.7-win_x64
Default locale: de_DE, platform encoding: Cp1252
OS name: "windows 10", version: "10.0", arch: "amd64", family: "windows"

The text was updated successfully, but these errors were encountered:

gsmet · 2020-06-30T15:17:41Z

/cc @geoand @stuartwdouglas

gsmet · 2020-06-30T19:03:58Z

@Postremus thanks for reporting. Looks like a nasty one but also probably something that will be hard to track.

If you end up finding a way to reproduce it, that would be very helpful.

In any case, I'm not entirely sure we will be able to fix that one for 1.6.0.

aloubyansky · 2020-06-30T20:26:23Z

@Postremus just in case, would you be able to test a custom branch of Quarkus repo to help debug the issue?

Postremus · 2020-06-30T20:35:26Z

@aloubyansky yes, I can test custom branches / revisions.

aloubyansky · 2020-06-30T21:28:17Z

I am wondering whether the regression was caused by commit b39620b6c6f88475f55e831ff51649ed430cb1a9. @Postremus could you please try the last commit before that one by git checkout 2a6cd9b88b20cc68ba30462e4256a68be2f0c8b0? And if that works then git checkout b39620b6c6f88475f55e831ff51649ed430cb1a9 to see if it breaks it? Thanks a lot.

jaikiran · 2020-07-01T01:41:53Z

@Postremus What you can additionally do (to provide us some debug data) is pass the following when you launch the application in quarkus:dev mode:

mvn clean quarkus:dev -Djvm.args=-verbose:class > classloading.txt

I've intentionally redirected the output to a file since the output is going to be extremely large. Share the file with us (after you have managed to generate the classcast/classloading error).

Postremus · 2020-07-01T06:18:29Z

@aloubyansky dev mode works in both b39620b6c6f88475f55e831ff51649ed430cb1a9 and 2a6cd9b88b20cc68ba30462e4256a68be2f0c8b0.

@jaikiran Can I send you the log privatly trough zulip?

geoand · 2020-07-01T06:22:15Z

@Postremus two more commits to try if you could: 18f1ca2 and 4e58a7d

Postremus · 2020-07-01T07:34:14Z

@geoand @aloubyansky dev mode does not work with 18f1ca2792940386cc50b0efa70c15c25d307505, same stacktrace.

Dev mode works in the commit directly before that, c1d1ac896e

geoand · 2020-07-01T07:39:30Z

@Postremus thanks a lot for that info, it's very helpful. If you could perform one final check so we can absolutely positive that it's that commit that causes the problem: Can you test the latest master with the addition of having that commit reverted?

@aloubyansky any idea why that might be happening with the commit in question (18f1ca2)? Looks to me like we can safely revert it need be.

jaikiran · 2020-07-01T07:40:52Z

@jaikiran Can I send you the log privatly trough zulip?

I have been trying to avoid joining too many chat/email applications, so I'm not on Zulip, sorry. But if you are willing to send me that log over email, then my address is ... (email has been received, removing address from this message)

Postremus · 2020-07-01T08:09:52Z

@geoand

Can you test the latest master with the addition of having that commit reverted?

I reverted the commit in question on master. Dev mode works.
See Postremus@07a19e0 for the revert.

gsmet · 2020-07-01T08:22:30Z

I just wanted to say good work everyone :).

geoand · 2020-07-01T08:29:28Z

Unable to see this in action, I personally can't really tell what the actual problem with that commit is. So all I have to offer is the suggestion to revert.

By just eyeballing I am inclined to think it might have to do with constScanning, but that's just a guess...

aloubyansky · 2020-07-01T08:34:07Z

@aloubyansky any idea why that might be happening with the commit in question (18f1ca2)? Looks to me like we can safely revert it need be.

I'll create a branch and push a commit to see if it fixes the issue. But I'm afk atm :(

aloubyansky · 2020-07-01T08:43:37Z

BTW, I had the same suspicion as @geoand

famod · 2020-07-01T18:53:16Z

This revert seems to fix at least one more problem:
In context of my CXF ClassCastException problem I posted on Zulip, I also tried out 1.6.0.CR1 just to face another problem: missing no-arg constructors in some CDI beans. Normally Quarkus should auto-generate them.

When I build from @Postremus' branch and use that SNAPSHOT of Quarkus in my project then the no-arg constructor problem vanishes!

Does that make sense?

PS: My main CCE-problem persists though, but that is another topic.

geoand · 2020-07-01T19:02:10Z

I kinda makes sense if the transformer handling breaks (no-args constructors are in some cases added via a transformation)

gsmet · 2020-07-06T14:51:54Z

@stuartwdouglas FYI, in case you missed it, due to this issue (and a few other cases reported), we had to revert your work in #10398 for 1.6.0.Final.

stuartwdouglas · 2020-07-07T03:50:09Z

Yea, I have just not had time to look into it. It's not a hight priority, it just seemed like it would be a code simplification.

jaikiran · 2020-07-24T04:43:09Z

Hello @gsmet, OK to close this one? Given that the issue has been sorted out by reverting the commit?

stuartwdouglas · 2020-08-05T01:45:43Z

I think I can see the problem and I have made another attempt at this for 1.8: #11214

This change does simplify things and will allow for some nice optimisations in dev mode, so I do want to get it in.

Postremus added the kind/bug Something isn't working label Jun 30, 2020

geoand added the area/core label Jul 1, 2020

jimbogithub mentioned this issue Jul 1, 2020

quarkus-maven-plugin DevMojo erroneously excludes local project dependencies #10143

Closed

gastaldi added triage/out-of-date This issue/PR is no longer valid or relevant and removed kind/bug Something isn't working labels Aug 4, 2020

gastaldi closed this as completed Aug 4, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

1.6.0.CR1 - Random Classloading Problems #10371

1.6.0.CR1 - Random Classloading Problems #10371

Postremus commented Jun 30, 2020

gsmet commented Jun 30, 2020

gsmet commented Jun 30, 2020

aloubyansky commented Jun 30, 2020

Postremus commented Jun 30, 2020

aloubyansky commented Jun 30, 2020

jaikiran commented Jul 1, 2020

Postremus commented Jul 1, 2020

geoand commented Jul 1, 2020

Postremus commented Jul 1, 2020

geoand commented Jul 1, 2020 •

edited

Loading

jaikiran commented Jul 1, 2020 •

edited

Loading

Postremus commented Jul 1, 2020

gsmet commented Jul 1, 2020

geoand commented Jul 1, 2020 •

edited

Loading

aloubyansky commented Jul 1, 2020

aloubyansky commented Jul 1, 2020

famod commented Jul 1, 2020 •

edited

Loading

geoand commented Jul 1, 2020

gsmet commented Jul 6, 2020 •

edited

Loading

stuartwdouglas commented Jul 7, 2020

jaikiran commented Jul 24, 2020

stuartwdouglas commented Aug 5, 2020

1.6.0.CR1 - Random Classloading Problems #10371

1.6.0.CR1 - Random Classloading Problems #10371

Comments

Postremus commented Jun 30, 2020

gsmet commented Jun 30, 2020

gsmet commented Jun 30, 2020

aloubyansky commented Jun 30, 2020

Postremus commented Jun 30, 2020

aloubyansky commented Jun 30, 2020

jaikiran commented Jul 1, 2020

Postremus commented Jul 1, 2020

geoand commented Jul 1, 2020

Postremus commented Jul 1, 2020

geoand commented Jul 1, 2020 • edited Loading

jaikiran commented Jul 1, 2020 • edited Loading

Postremus commented Jul 1, 2020

gsmet commented Jul 1, 2020

geoand commented Jul 1, 2020 • edited Loading

aloubyansky commented Jul 1, 2020

aloubyansky commented Jul 1, 2020

famod commented Jul 1, 2020 • edited Loading

geoand commented Jul 1, 2020

gsmet commented Jul 6, 2020 • edited Loading

stuartwdouglas commented Jul 7, 2020

jaikiran commented Jul 24, 2020

stuartwdouglas commented Aug 5, 2020

geoand commented Jul 1, 2020 •

edited

Loading

jaikiran commented Jul 1, 2020 •

edited

Loading

geoand commented Jul 1, 2020 •

edited

Loading

famod commented Jul 1, 2020 •

edited

Loading

gsmet commented Jul 6, 2020 •

edited

Loading