Open mgonzcast opened 2 years ago
The error looks to be occuring in the minion launched to gather block coverage, so gc parameters need to be passed to the child process. This can be done using pitest's jvmArgs
property.
Unless this module is excessively large, it seems likely that there is some sort of memory leak in the tests when run via pitest. I can see powermock is in use, which is a likely culprit. What else is in use?
Also, CLASSLIMIT
will reduce the number of mutations generated, but has no effect on the number of tests detected.
-DjvmArgs="-Xmx4096M,-XX:ReservedCodeCacheSize=2048M,-XX:-UseGCOverheadLimit"
Thanks! As you can see I already use jvmArgs. Is there anything am I missing?
Unless this module is excessively large, it seems likely that there is some sort of memory leak in the tests when run via pitest. I can see powermock is in use, which is a likely culprit. What else is in use?
Junit tests. Is there anyway to narrow down which test(s) is(are) the culprit?
This is exactly the output of the error on the second command:
12:12:57 PIT >> INFO : Verbose logging is disabled. If you encounter a problem, please enable it before reporting an issue. 12:13:02 PIT >> INFO : Incremental analysis reduced number of mutations by 0 12:13:02 PIT >> INFO : Created 325 mutation test units in pre scan 12:13:03 PIT >> INFO : Sending 861 test classes to minion 12:13:04 PIT >> INFO : Sent tests to minion \12:17:24 PIT >> INFO : MINION : log4j:ERROR A "org.apache.log4j.xml.DOMConfigurator" object is not assignable to a "org.apache.log4j.spi.Configurator" variable. 12:17:24 PIT >> INFO : MINION : log4j:ERROR The class "org.apache.log4j.spi.Configurator" was loaded by 12:17:24 PIT >> INFO : MINION : log4j:ERROR [org.powermock.core.classloader.javassist.JavassistMockClassLoader@785f57d0] whereas object of type 12:17:24 PIT >> INFO : MINION : log4j:ERROR "org.apache.log4j.xml.DOMConfigurator" was loaded by [sun.misc.Launcher$AppClassLoader@18b4aac2]. 12:17:24 PIT >> INFO : MINION : log4j:ERROR Could not instantiate configurator [org.apache.log4j.xml.DOMConfigurator]. \12:43:39 PIT >> WARNING : Error while watching child process java.util.concurrent.ExecutionException: java.lang.OutOfMemoryError: GC overhead limit exceeded at java.util.concurrent.FutureTask.report(FutureTask.java:122) at java.util.concurrent.FutureTask.get(FutureTask.java:192) at org.pitest.util.CommunicationThread.waitToFinish(CommunicationThread.java:59) at org.pitest.coverage.execute.CoverageProcess.waitToDie(CoverageProcess.java:35) at org.pitest.coverage.execute.DefaultCoverageGenerator.gatherCoverageData(DefaultCoverageGenerator.java:138) at org.pitest.coverage.execute.DefaultCoverageGenerator.calculateCoverage(DefaultCoverageGenerator.java:90) at org.pitest.coverage.execute.DefaultCoverageGenerator.calculateCoverage(DefaultCoverageGenerator.java:52) at org.pitest.mutationtest.tooling.MutationCoverage.runAnalysis(MutationCoverage.java:149) at org.pitest.mutationtest.tooling.MutationCoverage.runReport(MutationCoverage.java:139) at org.pitest.mutationtest.tooling.EntryPoint.execute(EntryPoint.java:123) at org.pitest.mutationtest.tooling.EntryPoint.execute(EntryPoint.java:54) at org.pitest.maven.RunPitStrategy.execute(RunPitStrategy.java:35) at org.pitest.maven.AbstractPitMojo.analyse(AbstractPitMojo.java:489) at org.pitest.maven.AbstractPitMojo.execute(AbstractPitMojo.java:419) at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:137) at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:210) at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:156) at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:148) at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:117) at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:81) at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:56) at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:128) at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:305) at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:192) at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:105) at org.apache.maven.cli.MavenCli.execute(MavenCli.java:972) at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:293) at org.apache.maven.cli.MavenCli.main(MavenCli.java:196) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:282) at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:225) at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:406) at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:347) Caused by: java.lang.OutOfMemoryError: GC overhead limit exceeded at java.util.zip.ZipCoder.toString(ZipCoder.java:49) at java.util.zip.ZipFile.getZipEntry(ZipFile.java:584) at java.util.zip.ZipFile.access$900(ZipFile.java:60) at java.util.zip.ZipFile$ZipEntryIterator.next(ZipFile.java:540) at java.util.zip.ZipFile$ZipEntryIterator.nextElement(ZipFile.java:515) at java.util.zip.ZipFile$ZipEntryIterator.nextElement(ZipFile.java:496) at org.pitest.classpath.ArchiveClassPathRoot.classNames(ArchiveClassPathRoot.java:91) at org.pitest.classpath.NameCachingRoot.classNames(NameCachingRoot.java:51) at org.pitest.classpath.NameCachingRoot.getData(NameCachingRoot.java:36) at org.pitest.classpath.CompoundClassPathRoot.getData(CompoundClassPathRoot.java:27) at org.pitest.classpath.ClassPath.getClassData(ClassPath.java:101) at org.pitest.classpath.ClassPathByteArraySource.getBytes(ClassPathByteArraySource.java:41) at org.pitest.classinfo.Repository.querySource(Repository.java:82) at org.pitest.classpath.CodeSource.fetchClassBytes(CodeSource.java:80) at org.pitest.classpath.CodeSource.getBytes(CodeSource.java:95) at org.pitest.coverage.analysis.LineMapper.mapLines(LineMapper.java:31) at org.pitest.coverage.LegacyClassCoverage.calculateLinesForBlocks(LegacyClassCoverage.java:135) at org.pitest.coverage.LegacyClassCoverage.getLinesForBlock(LegacyClassCoverage.java:124) at org.pitest.coverage.LegacyClassCoverage.addTestToClasses(LegacyClassCoverage.java:89) at org.pitest.coverage.CoverageData.calculateClassCoverage(CoverageData.java:66) at org.pitest.coverage.execute.DefaultCoverageGenerator$1.accept(DefaultCoverageGenerator.java:184) at org.pitest.coverage.execute.DefaultCoverageGenerator$1.accept(DefaultCoverageGenerator.java:176) at org.pitest.coverage.execute.Receive.handleTestEnd(Receive.java:76) at org.pitest.coverage.execute.Receive.apply(Receive.java:43) at org.pitest.util.SocketReadingCallable.receiveResults(SocketReadingCallable.java:56) at org.pitest.util.SocketReadingCallable.call(SocketReadingCallable.java:34) at org.pitest.util.SocketReadingCallable.call(SocketReadingCallable.java:11) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.lang.Thread.run(Thread.java:748) 12:43:39 PIT >> SEVERE : Coverage generator Minion exited abnormally due to UNKNOWN_ERROR
Thanks! As you can see I already use jvmArgs. Is there anything am I missing?
Sorry, I completely misread the command line. That looks correct to me for passing params to the minions, however, now we have the full stack trace, the GC overhead limit exceeded error looks to be being thrown in the main process.
So, working around this would require tweaking memory settings in both the minion and the main process.
Which still leaves the question of what is going on.
Either
Turning on verbose logging might help identify a problematic test (I usually pipe the whole output to a file and wade through). Disabling any test that use powermock / anything the manipulates bytecode might also help narrow down the issue to a list of culprets.
A thread dump of the main process would also shed some light.
So, working around this would require tweaking memory settings in both the minion and the main process.
How do I do that? Setting MAVEN_OPTS maybe? If I try to set up:
set MAVEN_OPTS="-Xmx1024M, -XX:ReservedCodeCacheSize=1024M,-XX:-UseGCOverheadLimit"
I get an error complaining about the heap size. I remove the -Xmx1024M flag I get an error regarding the reservedcochecachesize
Turning on verbose logging might help identify a problematic test (I usually pipe the whole output to a file and wade through). Disabling any test that use powermock / anything the manipulates bytecode might also help narrow down the issue to a list of culprets.
How do I disable any particular test? with excludedTestClasses?
A thread dump of the main process would also shed some light.
Which command do you recommend me for that?
How do I do that? Setting MAVEN_OPTS maybe? If I try to set up:
set MAVEN_OPTS="-Xmx1024M, -XX:ReservedCodeCacheSize=1024M,-XX:-UseGCOverheadLimit"
I get an error complaining about the heap size. I remove the -Xmx1024M flag I get an error regarding the reservedcochecachesize
This is because of the commas. Try:
MAVEN_OPTS="-Xmx1024M -XX:ReservedCodeCacheSize=1024M -XX:-UseGCOverheadLimit"
This is because of the commas. Try:
MAVEN_OPTS="-Xmx1024M -XX:ReservedCodeCacheSize=1024M -XX:-UseGCOverheadLimit"
I still get
Invalid maximum heap size: -Xmx1024M -XX:ReservedCodeCacheSize=1024M -XX:-UseGCOverheadLimit Error: Could not create the Java Virtual Machine. Error: A fatal exception has occurred. Program will exit.
Then I wonder whether there are any non-visible/non-space characters in there. For example, with both JDK 11 and 17 I get:
$ MAVEN_OPTS="-XmxFOO -XX:ReservedCodeCacheSize=1024M -XX:-UseGCOverheadLimit" mvn clean
Invalid maximum heap size: -XmxFOO
Error: Could not create the Java Virtual Machine.
Error: A fatal exception has occurred. Program will exit.
Observe how my error message says Invalid maximum heap size: -XmxFOO
but does not include the rest of the string. This makes me believe that in your case the space after -Xmx1024M
isn't a regular space, but e.g. a non-breaking space.
Many thanks, apparently on Windows you can´t use quotes with MAVEN_OPTS, so you have to use:
set MAVEN_OPTS=-Xmx1024M -XX:ReservedCodeCacheSize=1024M -XX:-UseGCOverheadLimit
without quotes
After excluding a powermock class it took more than 4 hours but no luck:
7:32:23 PIT >> INFO : Verbose logging is disabled. If you encounter a problem, please enable it before reporting an issue. 7:32:28 PIT >> INFO : Incremental analysis reduced number of mutations by 0 7:32:28 PIT >> INFO : Created 325 mutation test units in pre scan 7:32:29 PIT >> INFO : Sending 861 test classes to minion 7:32:30 PIT >> INFO : Sent tests to minion -12:01:32 PIT >> WARNING : Error while watching child process java.util.concurrent.ExecutionException: java.lang.OutOfMemoryError: Java heap space at java.util.concurrent.FutureTask.report(FutureTask.java:122) at java.util.concurrent.FutureTask.get(FutureTask.java:192) at org.pitest.util.CommunicationThread.waitToFinish(CommunicationThread.java:59) at org.pitest.coverage.execute.CoverageProcess.waitToDie(CoverageProcess.java:35) at org.pitest.coverage.execute.DefaultCoverageGenerator.gatherCoverageData(DefaultCoverageGenerator.java:138) at org.pitest.coverage.execute.DefaultCoverageGenerator.calculateCoverage(DefaultCoverageGenerator.java:90) at org.pitest.coverage.execute.DefaultCoverageGenerator.calculateCoverage(DefaultCoverageGenerator.java:52) at org.pitest.mutationtest.tooling.MutationCoverage.runAnalysis(MutationCoverage.java:149) at org.pitest.mutationtest.tooling.MutationCoverage.runReport(MutationCoverage.java:139) at org.pitest.mutationtest.tooling.EntryPoint.execute(EntryPoint.java:123) at org.pitest.mutationtest.tooling.EntryPoint.execute(EntryPoint.java:54) at org.pitest.maven.RunPitStrategy.execute(RunPitStrategy.java:35) at org.pitest.maven.AbstractPitMojo.analyse(AbstractPitMojo.java:489) at org.pitest.maven.AbstractPitMojo.execute(AbstractPitMojo.java:419) at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:137) at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:210) at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:156) at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:148) at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:117) at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:81) at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:56) at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:128) at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:305) at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:192) at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:105) at org.apache.maven.cli.MavenCli.execute(MavenCli.java:972) at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:293) at org.apache.maven.cli.MavenCli.main(MavenCli.java:196) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced(Launcher.java:282) at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:225) at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:406) at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:347) Caused by: java.lang.OutOfMemoryError: Java heap space at java.util.TreeSet.<init>(TreeSet.java:141) at org.pitest.coverage.CoverageData.addTestsToBlockMap(CoverageData.java:123) at org.pitest.coverage.CoverageData.calculateClassCoverage(CoverageData.java:71) at org.pitest.coverage.execute.DefaultCoverageGenerator$1.accept(DefaultCoverageGenerator.java:184) at org.pitest.coverage.execute.DefaultCoverageGenerator$1.accept(DefaultCoverageGenerator.java:176) at org.pitest.coverage.execute.Receive.handleTestEnd(Receive.java:76) at org.pitest.coverage.execute.Receive.apply(Receive.java:43) at org.pitest.util.SocketReadingCallable.receiveResults(SocketReadingCallable.java:56) at org.pitest.util.SocketReadingCallable.call(SocketReadingCallable.java:34) at org.pitest.util.SocketReadingCallable.call(SocketReadingCallable.java:11) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.lang.Thread.run(Thread.java:748) 12:01:34 PIT >> SEVERE : Coverage generator Minion exited abnormally due to UNKNOWN_ERROR [INFO] ------------------------------------------------------------------------ [INFO] BUILD FAILURE [INFO] ------------------------------------------------------------------------ [INFO] Total time: 04:34 h [INFO] Finished at: 2022-06-16T12:01:34+02:00 [INFO] ------------------------------------------------------------------------
I have to say I am using JDK 8 and Maven 3.8.4
@mgonzcast Can you give an indication of how large this module is? How long do the tests take to run wihtout pitest? Roughly how many thousand lines of code is it?
Thanks for being so responsive. The module has 17k lines of code and 1.6K of junit tests. I would say the tests take around 20-30 minutes to run.
Do you have any pitest configuration in the pom?
Do you have any pitest configuration in the pom?
No, nothing in pom about pitest. I have to say this is part of three module project but no pom has any reference about pitest. The other two modules are quite smaller (2.7k lines of code and 1.2k junit tests) and run pitest without any issue.
I have checked and tests take around 7 minutes to run, sorry.
I am going to start excluding classes from pitest so I can narrow down where the issue is:
mvn clean install org.pitest:pitest-maven:mutationCoverage -DtimeoutConstant=10000 -DoutputFormats=XML -DexportLineCoverage=true -DtimestampedReports=false -DjvmArgs="-Xmx4096M,-XX:ReservedCodeCacheSize=2048M,-XX:-UseGCOverheadLimit" -Dthreads=4 -DexcludedClasses="my.company.group.bizz.*"
Do you think is the best way?
You'll need to use excludedTestClasses
, but yes, taking some educated guesses as to where the issue might be and excluded them seems like a good step forward.
7 minutes to 4 hours is quite a leap. Generally the coverage system adds about 10% overhead. The slow down is almost certainly due to the excessive memory consumption.
I think this issue has been previously reported here
https://github.com/hcoles/pitest/issues/841
Which is fortunate as I am able to replicate it using the assertj project as an input. The issue is not as severe, but memory consumption is much higher than I'd expect.
I've identified something in the coverage code which looks (on the face of it) to be incredibly stupid, and should significantly reduce memory consumption if fixed. I'm not sure if this is the actual root cause problem here, or just an exasperating factor.
So, should I wait until you get the chance to look at it?
@mgonzcast Anything you find would be useful, but unless repeatedly running a test suite is something that brings you great pleasure, you might want to wait until the fix that assertj has highlighted is confirmed + available.
@mgonzcast Anything you find would be useful, but unless repeatedly running a test suite is something that brings you great pleasure, you might want to wait until the fix that assertj has highlighted is confirmed + available.
:) No great pleasure
I see the tests after your changes have worked. Let me know how I update pitest and if maybe the pitest sonarqube plugin has to be updated as well.
It will likely be a little while before this is merged in. Changes to the coverage system have subtly degraded the performance of the overall mutation analysis on the past, so I'll need to do a bit of playing around to sanity check it.
Since it's a big change that affects the file pitest produces, it will go into a 1.9.0 release. I'll probably release the other queued changes as a 1.8.x release before then.
To play with it before then, you'll need to check out and build it. If you do a local install, the version number will be 1.0.0-SNAPSHOT.
Since it's a big change that affects the file pitest produces, it will go into a 1.9.0 release. I'll probably release the other queued changes as a 1.8.x release before then.
When do you expect to release those changes? I can wait a couple of weeks.
To play with it before then, you'll need to check out and build it. If you do a local install, the version number will be 1.0.0-SNAPSHOT.
Not sure which parts do i have to rebuild and where to place them in my machine. Do I have to download code as it is now? Any instructions?
@mgonzcast Should be released some time next week.
@mgonzcast This is now released. 1.9.0 contains a fix for high memory consumption in the main process (it has no effect on the minions), and a change that greatly speedups up JUnit 5 tests during the coverage stage.
Since you look to have high memory consumption in the minions as well, I don't know how big the impact will be, but hopefully with things improved in the main process it will be easier to find any remaining issues.
@hcoles Thanks. Today I tried the new release 1.9.0 with the following settings:
set MAVEN_OPTS=-Xmx1024M -XX:ReservedCodeCacheSize=1024M -XX:-UseGCOverheadLimit
mvn clean install org.pitest:pitest-maven:mutationCoverage -DtimeoutConstant=10000 -DoutputFormats=XML -DexportLineCoverage=true -DtimestampedReports=false -DjvmArgs="-Xmx4096M,-XX:ReservedCodeCacheSize=2048M,-XX:-UseGCOverheadLimit" -Dthreads=4 -DexcludedClasses="my.company.package1.*,my.company.package2.*" -Dfeatures="+CLASSLIMIT(limit[5])" -DwithHistory
And I get:
9:00:52 PIT >> INFO : Verbose logging is disabled. If you encounter a problem, please enable it before reporting an issue.
9:00:53 PIT >> INFO : Incremental analysis reduced number of mutations by 0
9:00:53 PIT >> INFO : Created 141 mutation test units in pre scan
9:00:55 PIT >> INFO : Sending 861 test classes to minion
9:00:55 PIT >> INFO : Sent tests to minion
/9:23:15 PIT >> INFO : MINION : Exception in thread "main" org.pitest.util.PitError: Software caused connection abort: socket write error
9:23:37 PIT >> INFO : MINION :
9:23:37 PIT >> INFO : MINION : Please copy and paste the information and the complete stacktrace below when reporting an issue
9:23:37 PIT >> INFO : MINION : VM : Java HotSpot(TM) 64-Bit Server VM
[INFO] ------------------------------------------------------------------------9:23:37 PIT >> INFO : MINION : Vendor : Oracle Corporation
9:23:37 PIT >> INFO : MINION : Version : 25.301-b09
9:23:37 PIT >> INFO : MINION : Uptime : 1326847
[INFO] BUILD FAILURE9:23:37 PIT >> INFO : MINION : Input ->
9:23:37 PIT >> INFO : MINION : 1 : -Djava.awt.headless=true
[INFO] ------------------------------------------------------------------------9:23:37 PIT >> INFO : MINION : 2 : -Xmx4096M
9:23:37 PIT >> INFO : MINION : 3 : -XX:ReservedCodeCacheSize=2048M
9:23:37 PIT >> INFO : MINION : 4 : -XX:-UseGCOverheadLimit
9:23:37 PIT >> INFO : MINION : 5 : -javaagent:C:\Users\myuser\AppData\Local\Temp\1656399652205054211747762176572642187201910552711.jar
9:23:37 PIT >> INFO : MINION : 6 : -Dclassworlds.conf=C:\Apache\apache-maven-3.8.4\bin\m2.conf
9:23:37 PIT >> INFO : MINION : 7 : -Dmaven.home=C:\Apache\apache-maven-3.8.4
9:23:37 PIT >> INFO : MINION : 8 : -Dlibrary.jansi.path=C:\Apache\apache-maven-3.8.4\lib\jansi-native
9:23:37 PIT >> INFO : MINION : 9 : -Dmaven.multiModuleProjectDirectory=C:\Users\myuser\code
9:23:37 PIT >> INFO : MINION : BootClassPathSupported : true
9:23:37 PIT >> INFO : MINION :
9:23:37 PIT >> INFO : MINION : at org.pitest.util.Unchecked.translateCheckedException(Unchecked.java:20)
[INFO] Total time: 28:19 min9:23:37 PIT >> INFO : MINION : at org.pitest.util.SafeDataOutputStream.writeByte(SafeDataOutputStream.java:85)
9:23:37 PIT >> INFO : MINION : at org.pitest.coverage.execute.CoveragePipe.end(CoveragePipe.java:41)
9:23:37 PIT >> INFO : MINION : at org.pitest.coverage.execute.CoverageMinion.main(CoverageMinion.java:109)
9:23:37 PIT >> INFO : MINION : Caused by: java.net.SocketException: Software caused connection abort: socket write error9:23:37 PIT >> INFO : MINION : at java.net.SocketOutputStream.socketWrite0(Native Method)
[INFO] Finished at: 2022-06-28T09:23:37+02:009:23:37 PIT >> INFO : MINION : at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111)
9:23:37 PIT >> INFO : MINION : at java.net.SocketOutputStream.write(SocketOutputStream.java:155)
[INFO] ------------------------------------------------------------------------9:23:37 PIT >> INFO : MINION : at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
9:23:37 PIT >> INFO : MINION : at java.io.BufferedOutputStream.write(BufferedOutputStream.java:95)
9:23:37 PIT >> INFO : MINION : at java.io.DataOutputStream.writeByte(DataOutputStream.java:153)
9:23:37 PIT >> INFO : MINION : at org.pitest.util.SafeDataOutputStream.writeByte(SafeDataOutputStream.java:83)
9:23:37 PIT >> INFO : MINION : ... 2 more
Thanks @mgonzcast, I assume this is for the large module?
Can you enable verbose logging and see if it provides any additional info?
Thanks @mgonzcast, I assume this is for the large module?
Can you enable verbose logging and see if it provides any additional info?
Sure @hcoles. I enabled -X debug option and I get this in the logs:
------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 27:36 min
[INFO] Finished at: 2022-06-29T10:05:46+02:00
[INFO] ------------------------------------------------------------------------
[ERROR] Java heap space -> [Help 1]
java.lang.OutOfMemoryError: Java heap space
at java.util.Arrays.copyOf (Arrays.java:3332)
at java.lang.AbstractStringBuilder.ensureCapacityInternal (AbstractStringBuilder.java:124)
at java.lang.AbstractStringBuilder.append (AbstractStringBuilder.java:448)
at java.lang.StringBuffer.append (StringBuffer.java:270)
at java.io.StringWriter.write (StringWriter.java:112)
at java.io.PrintWriter.write (PrintWriter.java:456)
at java.io.PrintWriter.write (PrintWriter.java:473)
at java.io.PrintWriter.print (PrintWriter.java:603)
at java.io.PrintWriter.println (PrintWriter.java:756)
at java.lang.Throwable$WrappedPrintWriter.println (Throwable.java:765)
at java.lang.Throwable.printStackTrace (Throwable.java:659)
at java.lang.Throwable.printStackTrace (Throwable.java:722)
at org.pitest.util.Log$PlainFormatter.format (Log.java:81)
at java.util.logging.StreamHandler.publish (StreamHandler.java:211)
at java.util.logging.ConsoleHandler.publish (ConsoleHandler.java:116)
at java.util.logging.Logger.log (Logger.java:738)
at java.util.logging.Logger.doLog (Logger.java:765)
at java.util.logging.Logger.log (Logger.java:876)
at org.pitest.util.CommunicationThread.waitToFinish (CommunicationThread.java:61)
at org.pitest.coverage.execute.CoverageProcess.waitToDie (CoverageProcess.java:34)
at org.pitest.coverage.execute.DefaultCoverageGenerator.gatherCoverageData (DefaultCoverageGenerator.java:138)
at org.pitest.coverage.execute.DefaultCoverageGenerator.calculateCoverage (DefaultCoverageGenerator.java:90)
at org.pitest.coverage.execute.DefaultCoverageGenerator.calculateCoverage (DefaultCoverageGenerator.java:52)
at org.pitest.mutationtest.tooling.MutationCoverage.runAnalysis (MutationCoverage.java:148)
at org.pitest.mutationtest.tooling.MutationCoverage.runReport (MutationCoverage.java:138)
at org.pitest.mutationtest.tooling.EntryPoint.execute (EntryPoint.java:124)
at org.pitest.mutationtest.tooling.EntryPoint.execute (EntryPoint.java:54)
at org.pitest.maven.RunPitStrategy.execute (RunPitStrategy.java:35)
at org.pitest.maven.AbstractPitMojo.analyse (AbstractPitMojo.java:504)
at org.pitest.maven.AbstractPitMojo.execute (AbstractPitMojo.java:434)
at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo (DefaultBuildPluginManager.java:137)
at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:210)
[ERROR]
[ERROR]
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/OutOfMemoryError
@hcoles any ideas of what can I try now to narrow down the issue?
@mgonzcast If you set pitest's own logging to verbose (-Dverbose=true), then it might show something, although I'm not too hopeful.
After that it would be question of whittling away at the module to turn it into the smallest thing that reproduces the issue, and that you are happy to share (which can be done privately if that helps).
If you set pitest's own logging to verbose (-Dverbose=true), then it might show something, although I'm not too hopeful.
@hcoles I did and I get this strange error (I replaced real strings for anonimity):
18:15:39 PIT >> INFO : MINION : 18:15:38 PIT >> SEVERE : Error while running adapter JUnit fixture class com.mycompany.com.mymodule with filter Optional[mymoduleTest(com.mycompany.com.mymodule)]
18:15:39 PIT >> FINE : MINION : org.pitest.util.PitError: PowerMock internal error: Should never throw exception at this level
18:16:02 PIT >> FINE : MINION :
18:16:02 PIT >> INFO : MINION : java.lang.RuntimeException: PowerMock internal error: Should never throw exception at this level
18:16:02 PIT >> FINE : MINION : Please copy and paste the information and the complete stacktrace below when reporting an issue
18:16:02 PIT >> INFO : MINION : at org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl$PowerMockJUnit44MethodRunner.handleException(PowerMockJUnit44RunnerDelegateImpl.java:384)
I don´t quite understand why It´s checking that module because I added to the list of Excluded classes, maybe I am excluding it wrongly?
Also I still see the socket error...maybe the antivirus is coming to play?
18:16:02 PIT >> FINE : MINION : Caused by: java.lang.RuntimeException: PowerMock internal error: Should never throw exception at this level
18:16:02 PIT >> INFO : MINION : at javassist.ClassPoolTail.openClassfile(ClassPoolTail.java:340)
18:16:02 PIT >> FINE : MINION : at org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl$PowerMockJUnit44MethodRunner.handleException(PowerMockJUnit44RunnerDelegateImpl.java:384)
18:16:02 PIT >> INFO : MINION : at javassist.ClassPoolTail.writeClassfile(ClassPoolTail.java:293)
18:16:02 PIT >> FINE : MINION : at org.powermock.modules.junit4.internal.impl.PowerMockJUnit47RunnerDelegateImpl$PowerMockJUnit47MethodRunner.evaluateStatement(PowerMockJUnit47RunnerDelegateImpl.java:110)
18:16:02 PIT >> INFO : MINION : at javassist.ClassPool.writeClassfile(ClassPool.java:627)
18:16:02 PIT >> FINE : MINION : at org.powermock.modules.junit4.internal.impl.PowerMockJUnit47RunnerDelegateImpl$PowerMockJUnit47MethodRunner.executeTest(PowerMockJUnit47RunnerDelegateImpl.java:82)
18:16:02 PIT >> INFO : MINION : at javassist.CtClassType.toBytecode(CtClassType.java:1589)
18:16:02 PIT >> FINE : MINION : at org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl$PowerMockJUnit44MethodRunner.runBeforesThenTestThenAfters(PowerMockJUnit44RunnerDelegateImpl.java:298)
18:16:02 PIT >> INFO : MINION : at javassist.CtClass.toBytecode(CtClass.java:1519)
18:16:02 PIT >> FINE : MINION : at org.junit.internal.runners.MethodRoadie.runTest(MethodRoadie.java:87)
18:16:02 PIT >> INFO : MINION : at org.powermock.core.classloader.javassist.JavassistMockClassLoader.loadUnmockedClass(JavassistMockClassLoader.java:83)
18:16:02 PIT >> FINE : MINION : at org.junit.internal.runners.MethodRoadie.run(MethodRoadie.java:50)
18:16:02 PIT >> INFO : MINION : ... 33 more
18:16:02 PIT >> FINE : MINION : at org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl.invokeTestMethod(PowerMockJUnit44RunnerDelegateImpl.java:218)
18:16:02 PIT >> INFO : MINION : Caused by: java.net.SocketException: Software caused connection abort: socket write error
18:16:02 PIT >> FINE : MINION : at org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl.runMethods(PowerMockJUnit44RunnerDelegateImpl.java:160)
18:16:02 PIT >> INFO : MINION : at java.net.SocketOutputStream.socketWrite0(Native Method)
18:16:02 PIT >> FINE : MINION : at org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl$1.run(PowerMockJUnit44RunnerDelegateImpl.java:134)
18:16:02 PIT >> INFO : MINION : at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111)
18:16:02 PIT >> FINE : MINION : at org.junit.internal.runners.ClassRoadie.runUnprotected(ClassRoadie.java:34)
18:16:02 PIT >> INFO : MINION : at java.net.SocketOutputStream.write(SocketOutputStream.java:155)
18:16:02 PIT >> FINE : MINION : at org.junit.internal.runners.ClassRoadie.runProtected(ClassRoadie.java:44)
18:16:02 PIT >> INFO : MINION : at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
18:16:02 PIT >> FINE : MINION : at org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl.run(PowerMockJUnit44RunnerDelegateImpl.java:136)
18:16:02 PIT >> INFO : MINION : at java.io.BufferedOutputStream.write(BufferedOutputStream.java:126)
18:16:02 PIT >> FINE : MINION : at org.powermock.modules.junit4.common.internal.impl.JUnit4TestSuiteChunkerImpl.run(JUnit4TestSuiteChunkerImpl.java:117)
18:16:02 PIT >> INFO : MINION : at java.io.DataOutputStream.write(DataOutputStream.java:107)
18:16:02 PIT >> FINE : MINION : at org.powermock.modules.junit4.common.internal.impl.AbstractCommonPowerMockRunner.run(AbstractCommonPowerMockRunner.java:57)
18:16:02 PIT >> INFO : MINION : at java.io.FilterOutputStream.write(FilterOutputStream.java:97)
18:16:02 PIT >> FINE : MINION : at org.powermock.modules.junit4.PowerMockRunner.run(PowerMockRunner.java:59)
18:16:02 PIT >> INFO : MINION : at org.pitest.util.SafeDataOutputStream.writeBytes(SafeDataOutputStream.java:51)
18:16:02 PIT >> FINE : MINION : at org.pitest.junit.adapter.CustomRunnerExecutor.run(CustomRunnerExecutor.java:42)
18:16:02 PIT >> INFO : MINION : ... 44 more
18:16:02 PIT >> FINE : MINION : at org.pitest.junit.adapter.AdaptedJUnitTestUnit.execute(AdaptedJUnitTestUnit.java:69)
18:16:02 PIT >> FINE : MINION : ... 6 more
18:16:02 PIT >> FINE : MINION : Caused by: java.lang.RuntimeException: Failed to loaded class org.powermock.reflect.internal.WhiteboxImpl$2
18:16:02 PIT >> FINE : MINION : at org.powermock.core.classloader.javassist.JavassistMockClassLoader.loadUnmockedClass(JavassistMockClassLoader.java:88)
18:16:02 PIT >> FINE : MINION : at org.powermock.core.classloader.MockClassLoader.loadClassByThisClassLoader(MockClassLoader.java:104)
18:16:02 PIT >> FINE : MINION : at org.powermock.core.classloader.DeferSupportingClassLoader.loadClass1(DeferSupportingClassLoader.java:147)
18:16:02 PIT >> FINE : MINION : at org.powermock.core.classloader.DeferSupportingClassLoader.loadClass(DeferSupportingClassLoader.java:98)
18:16:02 PIT >> FINE : MINION : at java.lang.ClassLoader.loadClass(ClassLoader.java:351)
18:16:02 PIT >> FINE : MINION : at org.powermock.reflect.internal.WhiteboxImpl.doGetAllMethods(WhiteboxImpl.java:1497)
18:16:02 PIT >> FINE : MINION : at org.powermock.reflect.internal.WhiteboxImpl.getAllMethods(WhiteboxImpl.java:1481)
18:16:02 PIT >> FINE : MINION : at org.powermock.reflect.internal.WhiteboxImpl.findMethodOrThrowException(WhiteboxImpl.java:861)
18:16:02 PIT >> FINE : MINION : at org.powermock.reflect.internal.WhiteboxImpl.doInvokeMethod(WhiteboxImpl.java:821)
18:16:02 PIT >> FINE : MINION : at org.powermock.reflect.internal.WhiteboxImpl.invokeMethod(WhiteboxImpl.java:689)
18:16:02 PIT >> FINE : MINION : at org.powermock.reflect.Whitebox.invokeMethod(Whitebox.java:401)
18:16:02 PIT >> FINE : MINION : at org.powermock.modules.junit4.internal.impl.PowerMockJUnit44RunnerDelegateImpl$PowerMockJUnit44MethodRunner.handleException(PowerMockJUnit44RunnerDelegateImpl.java:361)
18:16:02 PIT >> FINE : MINION : ... 22 more
18:16:02 PIT >> FINE : MINION : Caused by: org.pitest.util.PitError: Software caused connection abort: socket write error
@mgonzcast How are you excluding the powermock tests? Although I'm not sure what's happening, they are a likely root cause.
It is certainly possible that antivirus is interfering with the communication between the main process and the minion, there have been reports of this in the past. I don't see how it would result in the OutOfMemoryError you reported earlier however.
@mgonzcast How are you excluding the powermock tests? Although I'm not sure what's happening, they are a likely root cause.
I was excluding classes with -DexcludedClasses switch. I have searched for the string powermock and I found all powermock instances (all in src\test).
Your question made me think that I was doing the exclusion wrongly and after googling around I found another switch -DexcludedTestClasses. If I exclude the tests classes with powermock using that switch, pitest doesn´t fail but I get this poor results:
================================================================================
- Statistics
================================================================================
>> Line Coverage: 41/25845 (0%)
>> Generated 11408 mutations Killed 6 (0%)
>> Mutations with no coverage 11401. Test strength 86%
>> Ran 7 tests (0 tests per mutation)
Enhanced functionality available at https://www.arcmutate.com/
I will try to narrow more the list
I was excluding classes with -DexcludedClasses switch. I have searched for the string powermock and I found all powermock instances (all in src\test).
Just wondering...why some tests with powermock don´t work with pitest and others do? Do I have to look for anything in particular?
@mgonzcast I'm not sure what the issue is. If you could post an example of a test that doesn't work, that would be helpful.
As you said it was mockito tests. It makes sense:
import org.mockito.junit.MockitoJUnitRunner;
@RunWith(MockitoJUnitRunner.class)
Excluding those test classes I was able to run the pitest. But it takes around 6-7 hours for 1300 lines of code (originally before exclusion 18k lines of code)
@mgonzcast Can you post a full (simplified) example of a test that causes the issue? Pitest already runs tests against MockitoJunitRunner as part of its build, so more info will be required to reproduce this.
PowerMocks are used too (sorry I didn´t say earlier).
PowerMock example:
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.when;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.mockito.InjectMocks;
import org.mockito.Mock;
import org.powermock.api.mockito.PowerMockito;
import org.powermock.core.classloader.annotations.PrepareForTest;
import org.powermock.modules.junit4.PowerMockRunner;
import org.springframework.context.ApplicationContext;
import com.company.myproject.module1.Sender;
@RunWith(PowerMockRunner.class)
@PrepareForTest(StaticApplicationContext.class)
public class example1Test {
@InjectMocks
private TriggerSender injectedMock;
@Mock
private ApplicationContext applicationContextMock;
@Mock
private Sender senderMock;
@Test
public void runTest() {
PowerMockito.mockStatic(StaticApplicationContext.class);
when(StaticApplicationContext.getApplicationContext()).thenReturn(this.applicationContextMock);
when(this.applicationContextMock.getBean(sender.class)).thenReturn(this.senderMock);
this.injectedMock.run();
verify(this.senderMock).send();
}
}
@hcoles Does this help?
@hcoles do you need more examples?
@mgonzcast I've not been able to reproduce the problem. If you can put together an minimal project that reproduces the issue, that would help.
Hi,
I have several modules in a project and only (the biggest one) fails with GC overhead limit exceeded.
I have searched around and I can´t find how to fix this.
Originally I run this command (which works in the rest of modules):
mvn clean install org.pitest:pitest-maven:mutationCoverage -DtimeoutConstant=10000 -DoutputFormats=XML -DexportLineCoverage=true -DtimestampedReports=false
and I get:
[INFO] Defaulting target classes to match packages in build directory [INFO] Defaulting target tests to match packages in test build directory 11:38:57 PIT >> INFO : Verbose logging is disabled. If you encounter a problem, please enable it before reporting an issue. 11:39:04 PIT >> INFO : Incremental analysis reduced number of mutations by 0 11:39:04 PIT >> INFO : Created 668 mutation test units in pre scan 11:39:05 PIT >> INFO : Sending 861 test classes to minion 11:39:05 PIT >> INFO : Sent tests to minion \11:43:12 PIT >> INFO : MINION : log4j:ERROR A "org.apache.log4j.xml.DOMConfigurator" object is not assignable to a "org.apache.log4j.spi.Configurator" variable. 11:43:12 PIT >> INFO : MINION : log4j:ERROR The class "org.apache.log4j.spi.Configurator" was loaded by 11:43:12 PIT >> INFO : MINION : log4j:ERROR [org.powermock.core.classloader.javassist.JavassistMockClassLoader@1e313166] whereas object of type 11:43:12 PIT >> INFO : MINION : log4j:ERROR "org.apache.log4j.xml.DOMConfigurator" was loaded by [sun.misc.Launcher$AppClassLoader@18b4aac2]. 11:43:12 PIT >> INFO : MINION : log4j:ERROR Could not instantiate configurator [org.apache.log4j.xml.DOMConfigurator]. /11:59:21 PIT >> INFO : MINION : Java HotSpot(TM) 64-Bit Server VM warning: CodeCache is full. Compiler has been disabled. 11:59:21 PIT >> INFO : MINION : Java HotSpot(TM) 64-Bit Server VM warning: Try increasing the code cache size using -XX:ReservedCodeCacheSize= -
I have tried:
mvn clean install org.pitest:pitest-maven:mutationCoverage -DtimeoutConstant=10000 -DoutputFormats=XML -DexportLineCoverage=true -DtimestampedReports=false -DjvmArgs="-Xmx4096M,-XX:ReservedCodeCacheSize=2048M,-XX:-UseGCOverheadLimit" -Dthreads=4 " -Dfeatures="+CLASSLIMIT" -DwithHistory
But although the number of tests unit decreased, the number of test classes sent to minion are still 865 and I get an outofmemroy and GC overhead limit exceeded.
Any hint?