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

Activate camel-core integration tests via -Dnative #2352

Merged
merged 4 commits into from
May 13, 2019

Conversation

ppalaga
Copy link
Contributor

@ppalaga ppalaga commented May 6, 2019

@gnodet could you please review?

@ppalaga
Copy link
Contributor Author

ppalaga commented May 6, 2019

Hm... the Windows build failed in opentracing which has nothing to do with any of the current changes.

@ppalaga
Copy link
Contributor Author

ppalaga commented May 7, 2019

Build_Native_Linux is passing for me locally without -Dnative-image.docker-build. Let me check with -Dnative-image.docker-build.

@ppalaga
Copy link
Contributor Author

ppalaga commented May 7, 2019

The Build_Native_Linux job on Azure fails as follows:

[INFO] --- quarkus-maven-plugin:999-SNAPSHOT:native-image (native-image) @ quarkus-integration-test-camel-core ---
[INFO] [io.quarkus.creator.phase.nativeimage.NativeImagePhase] Running Quarkus native-image plugin on OpenJDK 64-Bit Server VM
[INFO] [io.quarkus.creator.phase.nativeimage.NativeImagePhase] docker run -v /home/vsts/work/1/s/integration-tests/camel-core/target:/project:z --rm --user 1001:117 quay.io/quarkus/centos-quarkus-native-image:graalvm-1.0.0-rc16 -J-Djava.util.logging.manager=org.jboss.logmanager.LogManager -J-Dio.netty.leakDetection.level=DISABLED -J-Dcom.sun.xml.bind.v2.bytecode.ClassTailor.noOptimize=true -J-DCamelSimpleLRUCacheFactory=true -J-Dio.netty.noUnsafe=true -H:InitialCollectionPolicy=com.oracle.svm.core.genscavenge.CollectionPolicy$BySpaceAndTime -jar quarkus-integration-test-camel-core-999-SNAPSHOT-runner.jar -J-Djava.util.concurrent.ForkJoinPool.common.parallelism=1 -H:FallbackThreshold=0 -J-Xmx6g -H:-AddAllCharsets -H:EnableURLProtocols=http -H:-SpawnIsolates -H:-JNI --no-server -H:-UseServiceLoaderFeature -H:+StackTrace
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:6]    classlist:  11,976.05 ms
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:6]        (cap):   1,218.27 ms
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:6]        setup:   2,928.06 ms
21:08:48,252 INFO  [org.apa.cam.imp.con.FastTypeConverterRegistry] Type converters loaded (core: 183, classpath: 34)
21:08:48,750 INFO  [org.jbo.res.res.i18n] RESTEASY002225: Deploying javax.ws.rs.core.Application: class io.quarkus.it.camel.core.CamelApplication
21:08:50,181 INFO  [org.jbo.threads] JBoss Threads version 3.0.0.Beta3
21:08:51,323 INFO  [org.xnio] XNIO version 3.7.0.Final
21:08:51,469 INFO  [org.xni.nio] XNIO NIO Implementation Version 3.7.0.Final
Warning: RecomputeFieldValue.FieldOffset automatic substitution failed. The automatic substitution registration was attempted because a call to sun.misc.Unsafe.objectFieldOffset(Field) was detected in the static initializer of protostream.com.google.protobuf.UnsafeUtil. Detailed failure reason(s): The argument of Unsafe.objectFieldOffset(Field) is not a constant field., Could not determine the field where the value produced by the call to sun.misc.Unsafe.objectFieldOffset(Field) for the field offset computation is stored. The call is not directly followed by a field store or by a sign extend node followed directly by a field store. 
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:6]     analysis:  73,434.04 ms
Error: Class that is marked for delaying initialization to run time got initialized during image building: com.sun.xml.internal.bind.v2.runtime.reflect.opt.Injector
Error: Use -H:+ReportExceptionStackTraces to print stacktrace of underlying exception
Error: Image build request failed with exit status 1

But it is passing for me

cd quarkus && mvn clean install -DskipTests -Dinvoker.skip=true
...
cd integration-tests/camel-core && mvn clean verify -Dnative -Dnative-image.docker-build
...
[INFO] --- quarkus-maven-plugin:999-SNAPSHOT:native-image (native-image) @ quarkus-integration-test-camel-core ---
[INFO] [io.quarkus.creator.phase.nativeimage.NativeImagePhase] Running Quarkus native-image plugin on OpenJDK 64-Bit Server VM
[INFO] [io.quarkus.creator.phase.nativeimage.NativeImagePhase] docker run -v /home/ppalaga/orgs/quarkus/quarkus/integration-tests/camel-core/target:/project:z --rm --user 1000:1000 quay.io/quarkus/centos-quarkus-native-image:graalvm-1.0.0-rc16 -J-Djava.util.logging.manager=org.jboss.logmanager.LogManager -J-Dio.netty.leakDetection.level=DISABLED -J-Dcom.sun.xml.bind.v2.bytecode.ClassTailor.noOptimize=true -J-DCamelSimpleLRUCacheFactory=true -J-Dio.netty.noUnsafe=true -H:InitialCollectionPolicy=com.oracle.svm.core.genscavenge.CollectionPolicy$BySpaceAndTime -jar quarkus-integration-test-camel-core-999-SNAPSHOT-runner.jar -J-Djava.util.concurrent.ForkJoinPool.common.parallelism=1 -H:FallbackThreshold=0 -H:-AddAllCharsets -H:EnableURLProtocols=http -H:-SpawnIsolates -H:-JNI --no-server -H:-UseServiceLoaderFeature -H:+StackTrace
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]    classlist:   8,524.15 ms
08:22:34,342 INFO  [com.sun.xml.bin.v2.run.ref.opt.AccessorInjector] The optimized code generation is disabled
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]        (cap):     954.37 ms
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]        setup:   2,464.86 ms
08:22:36,872 INFO  [org.apa.cam.imp.con.FastTypeConverterRegistry] Type converters loaded (core: 183, classpath: 34)
08:22:37,233 INFO  [org.jbo.res.res.i18n] RESTEASY002225: Deploying javax.ws.rs.core.Application: class io.quarkus.it.camel.core.CamelApplication
08:22:38,038 INFO  [org.jbo.threads] JBoss Threads version 3.0.0.Beta3
08:22:38,445 INFO  [org.xnio] XNIO version 3.7.0.Final
08:22:38,516 INFO  [org.xni.nio] XNIO NIO Implementation Version 3.7.0.Final
Warning: RecomputeFieldValue.FieldOffset automatic substitution failed. The automatic substitution registration was attempted because a call to sun.misc.Unsafe.objectFieldOffset(Field) was detected in the static initializer of protostream.com.google.protobuf.UnsafeUtil. Detailed failure reason(s): The argument of Unsafe.objectFieldOffset(Field) is not a constant field., Could not determine the field where the value produced by the call to sun.misc.Unsafe.objectFieldOffset(Field) for the field offset computation is stored. The call is not directly followed by a field store or by a sign extend node followed directly by a field store. 
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]   (typeflow):  51,652.46 ms
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]    (objects):  61,358.61 ms
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]   (features):   2,160.67 ms
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]     analysis: 121,638.82 ms
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]     universe:   2,871.03 ms
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]      (parse):   6,930.79 ms
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]     (inline):   9,260.93 ms
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]    (compile):  36,483.63 ms
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]      compile:  56,019.91 ms
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]        image:   9,052.52 ms
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]        write:   1,446.75 ms
[quarkus-integration-test-camel-core-999-SNAPSHOT-runner:8]      [total]: 202,329.03 ms
[INFO] 
[INFO] --- maven-failsafe-plugin:2.22.0:integration-test (default) @ quarkus-integration-test-camel-core ---
...

What makes it pass here and fail there?

@ppalaga
Copy link
Contributor Author

ppalaga commented May 7, 2019

When I add -Dnative-image.xmx=6g -Dnative -Dno-format locally, the docker run command differs only in -v and --user values which I do not think should matter and it is still passing.

Any other ideas what makes it pass here and fail there?

@dmlloyd
Copy link
Member

dmlloyd commented May 7, 2019

It could be a timing difference.

@ppalaga
Copy link
Contributor Author

ppalaga commented May 7, 2019

It could be a timing difference.

What kind of timing?

@dmlloyd
Copy link
Member

dmlloyd commented May 7, 2019

Like a case where a race condition determines the value of a field, which in turn causes something to get initialized or not initialized. Essentially it would mean there is a bug, but it might not manifest all the time.

@ppalaga
Copy link
Contributor Author

ppalaga commented May 7, 2019

Thanks. That hypothetical bug would be in SVM, right?

I am just reading this article that explains --delay-class-initialization-to-runtime https://medium.com/graalvm/understanding-class-initialization-in-graalvm-native-image-generation-d765b7e4d6ed

Do you happen to know if a similar issue was seen on Quarkus before (and how it was solved)?

@dmlloyd
Copy link
Member

dmlloyd commented May 7, 2019

Thanks. That hypothetical bug would be in SVM, right?

In this case, no, probably not. Something causes an Injector instance to sometimes be reachable during static init. The bug would be in that code.

I am just reading this article that explains --delay-class-initialization-to-runtime https://medium.com/graalvm/understanding-class-initialization-in-graalvm-native-image-generation-d765b7e4d6ed

Do you happen to know if a similar issue was seen on Quarkus before (and how it was solved)?

This kind of thing happens fairly frequently. You need to follow the reference graph that is produced in order to deduce where it is coming from. There are reports generated by the build that could be helpful for this purpose.

@ppalaga
Copy link
Contributor Author

ppalaga commented May 7, 2019

Thanks for the explanation, @dmlloyd !

cd integration-tests/camel-core/target/reports && grep 'com.sun.xml.internal.bind.v2.runtime.reflect.opt.Injector' *.txt returns zero occurrences on my laptop. Maybe it is because my build went along the happy path. I'll try to find a way how to check those files on Azure CI.

@dmlloyd
Copy link
Member

dmlloyd commented May 7, 2019

Exactly; it'll only show up on the failing system.

@dmlloyd
Copy link
Member

dmlloyd commented May 8, 2019

I don't know how you ended up with an extra Windows Build. What I do know is that I don't have enough permissions to delete it off of there. 🤷‍♂

@ppalaga
Copy link
Contributor Author

ppalaga commented May 8, 2019

I don't know how you ended up with an extra Windows Build.

Interesting. I am not aware of doing anything to create it.

@ppalaga
Copy link
Contributor Author

ppalaga commented May 9, 2019

I was able to get a call graph of a failing build - see the bash step in https://dev.azure.com/peter0443/quarkus/_build/results?buildId=9 but there is still no single occurrence of com.sun.xml.internal.bind.v2.runtime.reflect.opt.Injector there. It looks like class initializers are not listed there at all. I'll have to come up with another way of finding out which class is triggering the Injector initialization.

@ppalaga
Copy link
Contributor Author

ppalaga commented May 10, 2019

com.sun.xml.internal.bind.v2.runtime.reflect.opt.Injector seems to be referenced only from com.sun.xml.internal.bind.v2.runtime.reflect.opt.AccessorInjector.prepare(Class, String, String, String...). We have a substitution for that one

@Substitute
public static Class<?> prepare(
Class beanClass, String templateClassName, String newClassName, String... replacements) {
return null;
}
. Shouldn't the substitution prevent the Injector from being initialized at build time (at least via this particular call path)? If yes, I do not see how the error may occur.

Injector has package visibility so other potential references to it can exist only in its own package and there do not seem to exist any others beyond the mentioned AccessorInjector.prepare().

Before this change -Dnative-camel was needed and the camel-core
integration tests were not run on Quarkus CI.
@dmlloyd
Copy link
Member

dmlloyd commented May 10, 2019

If that's the case then the only conclusion I can think of is that substitution is sometimes not working, or that there's a conflicting substitution which is sometimes taking priority and SubstrateVM is not complaining about it.

@ppalaga
Copy link
Contributor Author

ppalaga commented May 10, 2019

I just found the magic switch quarkus.camel.disable-jaxb=true that might help as a workaround d2809a1#diff-924069698fddcbdf7963a1706812aacbR10

@gnodet
Copy link
Contributor

gnodet commented May 10, 2019

Fwiw, in theory disabling xml and/or jaxb should not be a condition to have native support for Camel. Those flags were added as a way to have lightweight camel native applications by using more dead code elimination.

@ppalaga
Copy link
Contributor Author

ppalaga commented May 10, 2019

Yes, I also rather see the magic switches as a workaround. I'll file a new issue for the Injector failure on monday.

Is the current PR good to merge?

@ppalaga
Copy link
Contributor Author

ppalaga commented May 13, 2019

Reported #2417

@gsmet gsmet merged commit 79f1a3a into quarkusio:master May 13, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants