Quarkus: OverlappingFileLockException in JaCoCo when using offline instrumentation due to duplicate shutdown hooks (classloading issue)

Created on 6 Jun 2020 · 26Comments · Source: quarkusio/quarkus

Describe the bug
We are trying to implement test coverage measurement as described here: https://quarkus.io/guides/tests-with-coverage#instrumenting-the-classes-instead

For the most part this is working, but we are seeing this exception _at the end_ of the surefire/test executions in some of our Maven modules:

java.nio.channels.OverlappingFileLockException
        at java.base/sun.nio.ch.FileLockTable.checkList(FileLockTable.java:229)
        at java.base/sun.nio.ch.FileLockTable.add(FileLockTable.java:123)
        at java.base/sun.nio.ch.FileChannelImpl.lock(FileChannelImpl.java:1109)
        at java.base/java.nio.channels.FileChannel.lock(FileChannel.java:1063)
        at org.jacoco.agent.rt.internal_43f5073.output.FileOutput.openFile(FileOutput.java:70)
        at org.jacoco.agent.rt.internal_43f5073.output.FileOutput.writeExecutionData(FileOutput.java:54)
        at org.jacoco.agent.rt.internal_43f5073.Agent.shutdown(Agent.java:145)
        at org.jacoco.agent.rt.internal_43f5073.Agent$1.run(Agent.java:58)

After we stumbled upon https://github.com/jacoco/jacoco/issues/331#issuecomment-122827449, I debugged this and indeed in some cases the JaCoCo Agent ShutdownHook is registered twice, most likely because some of our instrumented classes are loaded from different classloaders (by Quarkus).

In one case the first Agent.getInstance() call stack looks like this:

Runtime.addShutdownHook(Thread) line: 213   
Agent.getInstance(AgentOptions) line: 55    
Offline.getRuntimeData() line: 39   
Offline.getProbes(long, String, int) line: 60   
SharedConfigSourceProvider.$jacocoInit(MethodHandles$Lookup, String, Class) line: not available 
404458571.invokeStaticInit(Object, Object, Object, Object) line: not available  
DelegatingMethodHandle$Holder.reinvoke_L(Object, Object, Object, Object) line: not available    
1131710157.invoke_MT(Object, Object, Object, Object, Object) line: not available    
BootstrapMethodInvoker.invoke(MethodHandle, MethodHandles$Lookup, String, Object) line: 204 
BootstrapMethodInvoker.invoke(Class<T>, MethodHandle, String, Object, Object, Class<?>) line: 90    
ConstantBootstraps.makeConstant(MethodHandle, String, Class<?>, Object, Class<?>) line: 67  
MethodHandleNatives.linkDynamicConstantImpl(Class<?>, MethodHandle, String, Class<?>, Object) line: 314 
MethodHandleNatives.linkDynamicConstant(Object, int, Object, Object, Object, Object) line: 306  
SharedConfigSourceProvider.<clinit>() line: 38  
NativeConstructorAccessorImpl.newInstance0(Constructor<?>, Object[]) line: not available [native method]    
NativeConstructorAccessorImpl.newInstance(Object[]) line: 62    
DelegatingConstructorAccessorImpl.newInstance(Object[]) line: 45    
Constructor<T>.newInstance(Object...) line: 490 
ServiceLoader$ProviderImpl<S>.newInstance() line: 779   
ServiceLoader$ProviderImpl<S>.get() line: 721   
ServiceLoader$3.next() line: 1394   
ServiceLoader<S>(Iterable<T>).forEach(Consumer<? super T>) line: 74 
SmallRyeConfigBuilder.discoverSources() line: 79    
SmallRyeConfigBuilder.build() line: 175 
ExtensionLoader.loadStepsFrom(ClassLoader, Properties, LaunchMode, Consumer<ConfigBuilder>) line: 192   
ExtensionLoader.loadStepsFrom(ClassLoader, LaunchMode, Consumer<ConfigBuilder>) line: 135   
QuarkusAugmentor.run() line: 101    
AugmentActionImpl.runAugment(boolean, Set<String>, ClassLoader, Class<BuildItem>...) line: 245  
AugmentActionImpl.createInitialRuntimeApplication() line: 130   
AugmentActionImpl.createInitialRuntimeApplication() line: 52    
QuarkusTestExtension.doJavaStart(ExtensionContext) line: 140

Notes:

SharedConfigSourceProvider is a custom ConfigSourceProvider we had to implement because we have multiple application*.yaml files in multiple modules
trace is truncated, I can post the full one if required

The second Agent.getInstance() call stack looks like this:

Runtime.addShutdownHook(Thread) line: 213   
Agent.getInstance(AgentOptions) line: 55    
Offline.getRuntimeData() line: 39   
Offline.getProbes(long, String, int) line: 60   
SharedConfigSourceProvider.$jacocoInit(MethodHandles$Lookup, String, Class) line: not available 
404458571.invokeStaticInit(Object, Object, Object, Object) line: not available  
DelegatingMethodHandle$Holder.reinvoke_L(Object, Object, Object, Object) line: not available    
1131710157.invoke_MT(Object, Object, Object, Object, Object) line: not available    
BootstrapMethodInvoker.invoke(MethodHandle, MethodHandles$Lookup, String, Object) line: 204 
BootstrapMethodInvoker.invoke(Class<T>, MethodHandle, String, Object, Object, Class<?>) line: 90    
ConstantBootstraps.makeConstant(MethodHandle, String, Class<?>, Object, Class<?>) line: 67  
MethodHandleNatives.linkDynamicConstantImpl(Class<?>, MethodHandle, String, Class<?>, Object) line: 314 
MethodHandleNatives.linkDynamicConstant(Object, int, Object, Object, Object, Object) line: 306  
SharedConfigSourceProvider.<clinit>() line: 38  
NativeConstructorAccessorImpl.newInstance0(Constructor<?>, Object[]) line: not available [native method]    
NativeConstructorAccessorImpl.newInstance(Object[]) line: 62    
DelegatingConstructorAccessorImpl.newInstance(Object[]) line: 45    
Constructor<T>.newInstance(Object...) line: 490 
ServiceLoader$ProviderImpl<S>.newInstance() line: 779   
ServiceLoader$ProviderImpl<S>.get() line: 721   
ServiceLoader$3.next() line: 1394   
ServiceLoader<S>(Iterable<T>).forEach(Consumer<? super T>) line: 74 
SmallRyeConfigBuilder.discoverSources() line: 79    
SmallRyeConfigBuilder.build() line: 175 
Config.<clinit>() line: 16096   
ApplicationImpl.<clinit>() line: 213    
Class<T>.forName0(String, boolean, ClassLoader, Class<?>) line: not available [native method]   
Class<T>.forName(String, boolean, ClassLoader) line: 398    
StartupActionImpl.run(String...) line: 161  
QuarkusTestExtension.doJavaStart(ExtensionContext) line: 151

It seems our SharedConfigSourceProvider is loaded a second time by a different classloader and therefore Agent.singleton is null (not initialized yet).
In this case there is only a single QuarkusTest in the respective module, no other test is present.

In another case the first Agent.getInstance() is triggered by a non-QuarkusTest (vanilla Junit5 Jupiter test) and the call stack looks like this:

Runtime.addShutdownHook(Thread) line: 213   
Agent.getInstance(AgentOptions) line: 55    
Offline.getRuntimeData() line: 39   
Offline.getProbes(long, String, int) line: 60   
ConfigurationContext.$jacocoInit(MethodHandles$Lookup, String, Class) line: not available   
DirectMethodHandle$Holder.invokeStatic(Object, Object, Object, Object) line: not available  
DelegatingMethodHandle$Holder.reinvoke_L(Object, Object, Object, Object) line: not available    
366252104.invoke_MT(Object, Object, Object, Object, Object) line: not available 
BootstrapMethodInvoker.invoke(MethodHandle, MethodHandles$Lookup, String, Object) line: 204 
BootstrapMethodInvoker.invoke(Class<T>, MethodHandle, String, Object, Object, Class<?>) line: 90    
ConstantBootstraps.makeConstant(MethodHandle, String, Class<?>, Object, Class<?>) line: 67  
MethodHandleNatives.linkDynamicConstantImpl(Class<?>, MethodHandle, String, Class<?>, Object) line: 314 
MethodHandleNatives.linkDynamicConstant(Object, int, Object, Object, Object, Object) line: 306  
<unknown receiving type>(ConfigurationContext).<init>(Map<Class<Annotation>,Annotation>, Class<?>, Class<?>, String, CallModifier) line: 44 
ConfigurationContextTest.doBefore() line: 34

Notes:

ConfigurationContext is one of our classes
ConfigurationContextTest.doBefore() is a @BeforeAll method
trace is truncated, I can post the full one if required

After this non-QuarkusTest there is a QuarkustTest which triggers another "initial" Agent.getInstance() invocation through ArC:

Runtime.addShutdownHook(Thread) line: 213   
Agent.getInstance(AgentOptions) line: 55    
Offline.getRuntimeData() line: 39   
Offline.getProbes(long, String, int) line: 60   
SoapClientAccessorBuilder.$jacocoInit(MethodHandles$Lookup, String, Class) line: not available  
789998945.invokeStaticInit(Object, Object, Object, Object) line: not available  
DelegatingMethodHandle$Holder.reinvoke_L(Object, Object, Object, Object) line: not available    
366252104.invoke_MT(Object, Object, Object, Object, Object) line: not available 
BootstrapMethodInvoker.invoke(MethodHandle, MethodHandles$Lookup, String, Object) line: 204 
BootstrapMethodInvoker.invoke(Class<T>, MethodHandle, String, Object, Object, Class<?>) line: 90    
ConstantBootstraps.makeConstant(MethodHandle, String, Class<?>, Object, Class<?>) line: 67  
MethodHandleNatives.linkDynamicConstantImpl(Class<?>, MethodHandle, String, Class<?>, Object) line: 314 
MethodHandleNatives.linkDynamicConstant(Object, int, Object, Object, Object, Object) line: 306  
SoapClientAccessorBuilder.<clinit>() line: 85   
Class<T>.forName0(String, boolean, ClassLoader, Class<?>) line: not available [native method]   
Class<T>.forName(String, boolean, ClassLoader) line: 398    
SoapClientAccessorBuilder_Bean.<init>() line: 543   
Default_ComponentsProvider.addBeans1(Map) line: 117 
Default_ComponentsProvider.getComponents() line: 38 
ArcContainerImpl.<init>() line: 106 
Arc.initialize() line: 20   
ArcRecorder.getContainer(ShutdownContext) line: 35  
ArcProcessor$generateResources11.deploy_0(StartupContext, Object[]) line: 72    
ArcProcessor$generateResources11.deploy(StartupContext) line: 36    
ApplicationImpl.<clinit>() line: 275    
Class<T>.forName0(String, boolean, ClassLoader, Class<?>) line: not available [native method]   
Class<T>.forName(String, boolean, ClassLoader) line: 398    
StartupActionImpl.run(String...) line: 161  
QuarkusTestExtension.doJavaStart(ExtensionContext) line: 151

Note: SoapClientAccessorBuilder is one of our classes.

This can all be debugged by adding a breakpoint to Runtime.addShutdownHook() plus mvn ... -Dmaven.surefire.debug.

Expected behavior
Quarkus classloading should not interfere with JaCoCo coverage via offline instrumentation.

Actual behavior
Duplicate JaCoCo Shutdownhook registrations seem to be caused by Quarkus classloading mechanisms, causing OverlappingFileLockExceptions to be logged that leave the user uncertain whether the coverage data can be trusted.

To Reproduce
Steps to reproduce the behavior for the ConfigSourceProvider case:

Clone https://github.com/famod/quarkus-issue-9837.git
This is basically https://github.com/quarkusio/quarkus-quickstarts/tree/1.5.0.Final/tests-with-coverage-quickstart with a no-op ConfigSourceProvider.
Switch to branch ConfigSourceProvider
mvn clean verify should yield:
[INFO] --- maven-surefire-plugin:2.22.1:test (integration-tests) @ tests-with-coverage-quickstart --- [INFO] [INFO] ------------------------------------------------------- [INFO] T E S T S [INFO] ------------------------------------------------------- [INFO] Running org.acme.testcoverage.GreetingResourceTest ::: SomeConfigSourceProvider.getConfigSources() called ::: SomeConfigSourceProvider.getConfigSources() called ::: SomeConfigSourceProvider.getConfigSources() called 2020-06-07 17:20:27,662 INFO [io.quarkus] (main) Quarkus 1.5.0.Final on JVM started in 1.447s. Listening on: http://0.0.0.0:8081 2020-06-07 17:20:27,664 INFO [io.quarkus] (main) Profile test activated. 2020-06-07 17:20:27,664 INFO [io.quarkus] (main) Installed features: [cdi, resteasy] [INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.075 s - in org.acme.testcoverage.GreetingResourceTest 2020-06-07 17:20:28,639 INFO [io.quarkus] (main) Quarkus stopped in 0.022s java.nio.channels.OverlappingFileLockException at java.base/sun.nio.ch.FileLockTable.checkList(FileLockTable.java:229) at java.base/sun.nio.ch.FileLockTable.add(FileLockTable.java:123) at java.base/sun.nio.ch.FileChannelImpl.lock(FileChannelImpl.java:1109) at java.base/java.nio.channels.FileChannel.lock(FileChannel.java:1063) at org.jacoco.agent.rt.internal_035b120.output.FileOutput.openFile(FileOutput.java:69) at org.jacoco.agent.rt.internal_035b120.output.FileOutput.writeExecutionData(FileOutput.java:53) at org.jacoco.agent.rt.internal_035b120.Agent.shutdown(Agent.java:137) at org.jacoco.agent.rt.internal_035b120.Agent$1.run(Agent.java:54) [INFO] [INFO] Results: [INFO] [INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0

I can also try to create a reproducer for the other case, if needed.

Configuration
n/a

Environment (please complete the following information):

Output of uname -a or ver:
MINGW64_NT-10.0-18363 W4DEUMSY9003463 3.0.7-338.x86_64 2019-11-21 23:07 UTC x86_64 Msys
Output of java -version:
openjdk version "11.0.7" 2020-04-14 OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.7+10) OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.7+10, mixed mode)
GraalVM version (if different from Java): n/a
Quarkus version or git rev: 1.4.2.Final & 1.5.0.Final
Build tool (ie. output of mvnw --version or gradlew --version): Apache Maven 3.6.3

Additional context
This might be more of an interoperability issue between Quarkus and JaCoCo than a "classical" Quarkus-only bug, but since JaCoCo offline instumentation is "officially" documented in the Quarkus docs this should work without issues.

The classes indirectly causing the duplicate hooks can be excluded from JaCoCo instrumentation, but then they will (obviously) have 0% coverage in the report.
In one we case we did do so, though, because the "offending" class was a QuarkusTestResourceLifecycleManager from a test support module which should be ignored anyway.

kinbug

Source

famod

👍2

All 26 comments

cc @harthorst & @tkalmar

famod on 8 Jun 2020

WDYT @stuartwdouglas (and @geoand maybe)?

famod on 8 Jun 2020

I think we want the agent based instrumentation to be our default approach. I am not sure why it says that this approach is not compatible with Quarkus, its the approach we use for code coverage within Quarkus itself.

stuartwdouglas on 9 Jun 2020

@stuartwdouglas It is because of constructor injection. The problem is described here: https://quarkus.io/guides/tests-with-coverage#the-coverage-does-not-seem-to-correspond-to-the-reality

famod on 9 Jun 2020

What if Quarkus would create no-arg constructors for CDI-beans by default? cc @mkouba @manovotn
Not sure whether this would be possible.

More context:
We (~10 developers) just had an internal discussion and we would like to use _online_ instrumentation, also because that just works in IDEs whereas _offline_ instrumentation seems impossible.
But we do not want to hand-write no-arg constructors, especially since our injected members are usually final.
We also do _not_ want to go back to field injection (various reasons).

We considered https://projectlombok.org/api/lombok/NoArgsConstructor.html but we do not want to pull in Lombok just because of that and with this annotation we still would have to remember to add it to new (CDI-managed) classes.

That discussion lead to the following solutions:

implement custom AnnotationProcessor that adds a no-arg constructors to classes that are annotated with @ApplicationScoped, @RequestScoped etc.
or let Quarkus do that (maybe switchable via a config property?)

Plan B (way inferior to the pervious solutions):

implement a custom Checkstyle check that detects missing no-arg constructors
or implement ArchUnit (or similar framework) test that detects missing no-arg constructors
or ...?

famod on 9 Jun 2020

What if Quarkus would create no-arg constructors for CDI-beans by default? cc @mkouba @manovotn
Not sure whether this would be possible.

We already do that in some circumestances we know it's necessary

geoand on 9 Jun 2020

That is the problem, it means the classes loaded into memory are not the same as the ones jacoco sees on disk, and this causes problems.

We do have the ability to dump the transformed classes to disk, I wonder if jacoco could use that.

stuartwdouglas on 9 Jun 2020

are not the same as the ones jacoco sees on disk,

AFAIK, as long as the classes already have the constructor when they are _loaded_ (from whatever source) and are processed by the JaCoCo agent, eveything is fine. But I guess this is too early for the Quarkus mechanism?

famod on 9 Jun 2020

On Tue, 9 Jun 2020 at 21:24, Falko Modler notifications@github.com wrote:

are not the same as the ones jacoco sees on disk,

AFAIK, as long as the classes already have the constructor when they are
loaded (from whatever source) and are processed by the JaCoCo agent,
eveything is fine. But I guess this is too early for the Quarkus mechanism?

They definitely have them when they are loaded, the agent will see the
final class file that will be provided to the JVM. It won't be the same as
the one on disk though.

Maybe it is also loading the originals, and this is confusing it.

Stuart

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/quarkusio/quarkus/issues/9837#issuecomment-641226975,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AACQG65W2YWMOWLFM5TVKT3RVYLWFANCNFSM4NVIWV3Q
.

stuartwdouglas on 9 Jun 2020

Again AFAIK but in online mode the JaCoCo agent should not do anything with the class files.
When generating a report, though, it does need the source files. But I guess it won't fail if it doesn't find the no-arg constructor there.

cc @marchof

famod on 9 Jun 2020

@famod The JaCoCo agent also transforms class files, but on-the-fly while classes are loaded in memory. During report generation the exact same original class files are required (source files are optional if you want highlighted class files). If the class files are transformed before JaCoCo agent sees them, they do not match any more. JaCoCo does not look at specific constructors. Any modification will result in a mismatch.

This is correctly described in another chapter of the document referenced earlier:

https://quarkus.io/guides/tests-with-coverage#instrumenting-the-classes-instead

marchof on 9 Jun 2020

@marchof thanks for clarifying this.

So how do we me move on from here?

famod on 9 Jun 2020

To quote myself:

implement custom AnnotationProcessor that adds a no-arg constructors to classes that are annotated with @ApplicationScoped, @RequestScoped etc.

I've just learned that you cannot modify existing code with annotation processors, you can only generate new classes.
So custom bytecode manipulation is needed (in case the problem is not somehow solved in Quarkus), maybe via https://github.com/raphw/byte-buddy/tree/master/byte-buddy-maven-plugin.

famod on 14 Jun 2020

One possibility would be that we could maybe write a jacoco extension that integrates with @QuarkusTest, and somehow we wire it up so it works of the transformed classes. Not sure how practical this idea is (or even if it is possible) but maybe it would also allow for the best user experience.

stuartwdouglas on 15 Jun 2020

Update regarding _offline_ instrumentation: I've just successfully tested a fix that is supposed to land in JaCoCo 0.8.6: https://github.com/jacoco/jacoco/pull/1057

Once 0.8.6 is out I am going to update the Quarkus docs (and the example) to use 0.8.6.

Aside from that I'd still prefer a working _online_ instrumentation.

famod on 17 Jun 2020

We also have that issue and apparently others. See e.g. https://quarkusio.zulipchat.com/#narrow/stream/187030-users/topic/JaCoCo.20coverage.20and.20JDK.20versions

pilhuhn on 22 Jun 2020

👀1

@famod So you built JaCoCo 0.8.6 locally with that change? Or is there a snapshot version already out in some repo?

pilhuhn on 22 Jun 2020

@pilhuhn I had built this branch: https://github.com/jacoco/jacoco/pull/1057

famod on 22 Jun 2020

👍1

🎉 Update regarding online instrumentation: It seems we (or better to say @mickroll who actually implemented it) were successful in creating a plugin for byte-buddy-maven-plugin that auto-adds no-arg constructors to classes with @ApplicationScoped etc. and even add @Inject to the "proper" injection constructor.

https://gist.github.com/mickroll/1310eeed7f34a514461b25a470d434db

Please let me or @mickroll know, whether you need more info (preferably as a comment under the gist).

famod on 7 Jul 2020

@stuartwdouglas WDYT, should we update the documentation to point to this issue and maybe also the JaCoCo issue?

famod on 7 Jul 2020

Is there a reproducer somewhere for the agent based instrumentation issue?

stuartwdouglas on 10 Sep 2020

@stuartwdouglas I've just modified the quickstart:

clone https://github.com/famod/quarkus-quickstarts.git
switch to issue-9837-jacoco-online
cd tests-with-coverage-quickstart
mvn clean verify

target/site/jacoco* will then not contain any coverage for GreetingResource (it does with the offline flavor).

PS: I kept the separation into UTs and ITs, which makes it a bit more complex.

famod on 13 Sep 2020

So it looks like this is hard coded into the maven plugin, so we can't override it to look at the transformed classes.

The best way forward might be to create a Quarkus jacoco extension. We could perform the instrumentation using our existing transformers, and do the reporting based on the transformed classes.

stuartwdouglas on 14 Sep 2020

Update regarding _offline_ instrumentation: I've just successfully tested a fix that is supposed to land in JaCoCo 0.8.6: jacoco/jacoco#1057

Once 0.8.6 is out I am going to update the Quarkus docs (and the example) to use 0.8.6.

Bummer, 0.8.6 has just been released _without_ this fix: https://github.com/jacoco/jacoco/issues/331#issuecomment-693211642 😞

_Update_, quote from one of the jacoco members:

There will be a release soon, for official Java 15 support, so there is another chance to get this PR in.

famod on 16 Sep 2020

❤1

I had a bit of a think about how to improve this, and started some PoC work here: https://github.com/quarkusio/quarkus/compare/master...stuartwdouglas:jacoco?expand=1

My idea is to have a Jacoco extension, that will use our transformers to instrument, and then automatically generate a report once the tests are done. There are some challenges though, as there is no reliable way to automatically link to the source.

stuartwdouglas on 16 Sep 2020

👍1

@stuartwdouglas sounds interesting!
One thing worth considering is test coverage reporting via IDE, e.g. EclEmma in Eclipse.
It would be great if that would work as well...

Btw, we have been using our ByteBuddy plugin for weeks now, without any major problems.

famod on 16 Sep 2020

👀1

Was this page helpful?

0 / 5 - 0 ratings