Occurence of java.lang.RuntimeException: java.nio.file.NoSuchFileException: `CoveredTestResultPerTest.dat`

DehengYang commented 3 years ago

I have encountered a new exception as follows when I use flacoco to localize an NPE bug in https://github.com/mybatis/mybatis-3/commit/5a26fd106832fc70c08d0a1597a1999798236581:

[543] INFO EntryPoint - Path to runner Classes: /home/apr/tools/flacoco/target/flacoco-1.0.1-SNAPSHOT-jar-with-dependencies.jar
[551] INFO EntryPoint - /home/apr/tools/flacoco/target/flacoco-1.0.1-SNAPSHOT-jar-with-dependencies.jar
[551] INFO EntryPoint - /home/apr/tools/flacoco/target/flacoco-1.0.1-SNAPSHOT-jar-with-dependencies.jar
[551] INFO EntryPoint - /home/apr/tools/flacoco/target/flacoco-1.0.1-SNAPSHOT-jar-with-dependencies.jar
[551] INFO EntryPoint - /home/apr/tools/flacoco/target/flacoco-1.0.1-SNAPSHOT-jar-with-dependencies.jar
[553] INFO EntryPoint - /home/apr/tools/flacoco/target/flacoco-1.0.1-SNAPSHOT-jar-with-dependencies.jar
[553] INFO EntryPoint - /home/apr/tools/flacoco/target/flacoco-1.0.1-SNAPSHOT-jar-with-dependencies.jar
[553] INFO EntryPoint - /home/apr/tools/flacoco/target/flacoco-1.0.1-SNAPSHOT-jar-with-dependencies.jar
[553] INFO EntryPoint - /home/apr/tools/flacoco/target/flacoco-1.0.1-SNAPSHOT-jar-with-dependencies.jar
[553] INFO EntryPoint - /home/apr/tools/flacoco/target/flacoco-1.0.1-SNAPSHOT-jar-with-dependencies.jar
[553] INFO EntryPoint - /home/apr/tools/flacoco/target/flacoco-1.0.1-SNAPSHOT-jar-with-dependencies.jar
[553] INFO EntryPoint - /home/apr/tools/flacoco/target/flacoco-1.0.1-SNAPSHOT-jar-with-dependencies.jar
java.lang.RuntimeException: java.nio.file.NoSuchFileException: /mnt/data/tests/mybatis/first_bug/mybatis-3-tbar/./target/CoveredTestResultPerTest.dat
    at eu.stamp_project.testrunner.listener.utils.ListenerUtils.loadFromMemoryMappedFile(ListenerUtils.java:83)
    at eu.stamp_project.testrunner.listener.impl.OnlineCoveredTestResultPerTestMethodImpl.load(OnlineCoveredTestResultPerTestMethodImpl.java:169)
    at eu.stamp_project.testrunner.EntryPoint.runOnlineCoveredTestResultPerTestMethods(EntryPoint.java:664)
    at fr.spoonlabs.flacoco.core.coverage.framework.JUnit5Strategy.execute(JUnit5Strategy.java:30)
    at fr.spoonlabs.flacoco.core.coverage.CoverageRunner.getCoverageMatrix(CoverageRunner.java:47)
    at fr.spoonlabs.flacoco.localization.spectrum.SpectrumRunner.computeCoverageMatrix(SpectrumRunner.java:56)
    at fr.spoonlabs.flacoco.localization.spectrum.SpectrumRunner.run(SpectrumRunner.java:32)
    at fr.spoonlabs.flacoco.api.Flacoco.run(Flacoco.java:31)
    at fr.spoonlabs.flacoco.cli.FlacocoMain.call(FlacocoMain.java:157)
    at fr.spoonlabs.flacoco.cli.FlacocoMain.call(FlacocoMain.java:27)
    at picocli.CommandLine.executeUserObject(CommandLine.java:1953)
    at picocli.CommandLine.access$1300(CommandLine.java:145)
    at picocli.CommandLine$RunLast.executeUserObjectOfLastSubcommandWithSameParent(CommandLine.java:2352)
    at picocli.CommandLine$RunLast.handle(CommandLine.java:2346)
    at picocli.CommandLine$RunLast.handle(CommandLine.java:2311)
    at picocli.CommandLine$AbstractParseResultHandler.execute(CommandLine.java:2179)
    at picocli.CommandLine.execute(CommandLine.java:2078)
    at fr.spoonlabs.flacoco.cli.FlacocoMain.main(FlacocoMain.java:148)
Caused by: java.nio.file.NoSuchFileException: /mnt/data/tests/mybatis/first_bug/mybatis-3-tbar/./target/CoveredTestResultPerTest.dat
    at sun.nio.fs.UnixException.translateToIOException(UnixException.java:86)
    at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
    at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
    at sun.nio.fs.UnixFileSystemProvider.newFileChannel(UnixFileSystemProvider.java:177)
    at java.nio.channels.FileChannel.open(FileChannel.java:287)
    at java.nio.channels.FileChannel.open(FileChannel.java:335)
    at eu.stamp_project.testrunner.listener.utils.ListenerUtils.loadFromMemoryMappedFile(ListenerUtils.java:67)
    ... 17 more

My script is:

flacocoPath=/home/apr/tools/flacoco/target/flacoco-1.0.1-SNAPSHOT-jar-with-dependencies.jar

curDir="$(cd $(dirname $0); pwd)"
tool=tbar
bug_dir="$curDir/mybatis-3-${tool}"

src_java=${bug_dir}/"src/main/java/"
bin_java=${bug_dir}/"target/classes/"
bin_test=${bug_dir}/"target/test-classes/"
classpath=""

cd $bug_dir;
mvn dependency:copy-dependencies
cd -;

for file in ${bug_dir}/target/dependency/*
do
    if [[ $file == *".jar" ]]; then
        classpath="${classpath}:${file}"
    fi
done

cd $bug_dir;
echo -e "java -jar $flacocoPath --projectpath $bug_dir --classpath ${bin_java}:${bin_test}$classpath \n\n"

java -jar $flacocoPath --projectpath $bug_dir --classpath ${bin_java}:${bin_test}$classpath

It would be sincerely appreciated if any advice could be given. Thank you!

andre15silva commented 3 years ago

Hi @DehengYang ,

Would you be able to run it again with the following options: -v --testRunnerVerbose?

DehengYang commented 3 years ago

Sure, here is the full log I have obtained:

flacoco_mybatis.log

Thank you!

andre15silva commented 3 years ago

Hi @DehengYang ,

From my understanding, the issue is due to classpaths. More specifically, there are probably two or more versions of asm in the classpath of the test execution process (similar to https://github.com/quarkusio/quarkus/issues/9832).

In your log:

Caused by: java.lang.IllegalArgumentException: Unsupported api 589824
    at org.objectweb.asm.ClassVisitor.<init>(ClassVisitor.java:70)
    at org.jacoco.core.internal.flow.ClassProbesVisitor.<init>(ClassProbesVisitor.java:38)
    at org.jacoco.core.internal.flow.ClassProbesVisitor.<init>(ClassProbesVisitor.java:28)
    at org.jacoco.core.internal.analysis.ClassAnalyzer.<init>(ClassAnalyzer.java:59)
    at org.jacoco.core.analysis.Analyzer$1.<init>(Analyzer.java:97)
    at org.jacoco.core.analysis.Analyzer.createAnalyzingVisitor(Analyzer.java:94)
    at org.jacoco.core.analysis.Analyzer.analyzeClass(Analyzer.java:114)
    at org.jacoco.core.analysis.Analyzer.analyzeClass(Analyzer.java:132)
    ... 22 more

This is weird because, in theory, the asm dependency to be used would be the one included in JaCoCo (9.2) and would override the one from the project you are analyzing.

I'm not being able to further debug it because I'm not being able to reproduce the project in question. I receive the following error:

❯ mvn test -DskipTests
[INFO] Scanning for projects...
[ERROR] [ERROR] Some problems were encountered while processing the POMs:
[FATAL] Non-resolvable parent POM for org.mybatis:mybatis:3.5.6-SNAPSHOT: org.mybatis:mybatis-parent:pom:32-SNAPSHOT was not found in https://oss.sonatype.org/content/repositories/snapshots during a previous attempt. This failure was cached in the local repository and resolution is not reattempted until the update interval of sonatype-oss-snapshots has elapsed or updates are forced and 'parent.relativePath' points at no local POM @ line 22, column 11
 @
[ERROR] The build could not read 1 project -> [Help 1]
[ERROR]
[ERROR]   The project org.mybatis:mybatis:3.5.6-SNAPSHOT (/home/andre/tmp/mybatis-3/pom.xml) has 1 error
[ERROR]     Non-resolvable parent POM for org.mybatis:mybatis:3.5.6-SNAPSHOT: org.mybatis:mybatis-parent:pom:32-SNAPSHOT was not found in https://oss.sonatype.org/content/repositories/snapshots during a previous attempt. This failure was cached in the local repository and resolution is not reattempted until the update interval of sonatype-oss-snapshots has elapsed or updates are forced and 'parent.relativePath' points at no local POM @ line 22, column 11 -> [Help 2]
[ERROR]
[ERROR] To see the full stack trace of the errors, re-run Maven with the -e switch.
[ERROR] Re-run Maven using the -X switch to enable full debug logging.
[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/ProjectBuildingException
[ERROR] [Help 2] http://cwiki.apache.org/confluence/display/MAVEN/UnresolvableModelException

I cannot find any information on their repo. Before asking them, do you know how to overcome this?

Their snapshot repo does not seem to have it (https://oss.sonatype.org/content/repositories/snapshots/org/mybatis/mybatis/)

DehengYang commented 3 years ago

Cool. Thank you for your kind help. Sorry for my late reply due to some other interruptions.

I cannot find any information on their repo. Before asking them, do you know how to overcome this?

Their snapshot repo does not seem to have it (https://oss.sonatype.org/content/repositories/snapshots/org/mybatis/mybatis/)

I also encountered such error. Since the snapshot is no longer available at the online repository, we have to first clone the parent of mybatis project: git clone git@github.com:mybatis/parent.git, then checkout an associated version (e.g., cff417a) for version 32-SNAPSHOT.

Then, I edited the pom.xml of mybatis project by adding the relative path entry of the parent pom project, as follows:

  <parent>
    <groupId>org.mybatis</groupId>
    <artifactId>mybatis-parent</artifactId>
    <version>32-SNAPSHOT</version>
    <relativePath>../parent</relativePath>
  </parent>

After that, the mvn test -DskipTests will work well.

Thank you again for your help. Please kindly advise.

monperrus commented 2 years ago

Hitting the same problem on Nopol CI job on Jenkins: https://ci.inria.fr/sos/job/nopol/1465/console

Note that the CI job on Github Actions works.

Nothing in the log, so flacoco or test-runner completely silence the underlying error.

monperrus commented 2 years ago

Trying with config.setTestRunnerVerbose(true);, see https://github.com/SpoonLabs/nopol/commit/8f587440aee4b5ecddfbfd3198f9c784bef19286

monperrus commented 2 years ago

This gives

OpenJDK 64-Bit Server VM warning: INFO: os::commit_memory(0x0000000080000000, 2147483648, 0) failed; error='Not enough space' (errno=12)
#
# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (mmap) failed to map 2147483648 bytes for committing reserved memory.
# An error report file with more information is saved as:
# /builds/workspace/nopol/nopol/hs_err_pid1435.log

This is a RAM memory problem. Indeed, the CI nodes have a little 2GB RAM.

monperrus commented 2 years ago

Action: asked to increase the RAM of the CI nodes.

In flacoco, we should add a precheck on the amount of available RAM and early stop with a clear message if this is too low.

WDYT @andre15silva?

andre15silva commented 2 years ago

Hi @monperrus

In flacoco, we should add a precheck on the amount of available RAM and early stop with a clear message if this is too low.

I don't think that's a good idea:

The amount of RAM necessary has varies quite a lot, and we might be introducing an too low threshold.
There are several meaning for "available RAM":
- Overall memory, which may be large but unavailable
- Overall available memory at a given point, which can vary
- Memory available for the test-runner JVM (the one which actually matters in this case, and could be modified through the configurable options too).

I agree, however, that we need to make it more explicit when RAM related issues occur.

I'll take this two actions:

[x] Introduce a warning message when the system memory is below a certain threshold (I think focusing on this meaning is the best idea for the warning purpose)
[x] Increase the error message propagation in https://github.com/STAMP-project/test-runner/issues/130

monperrus commented 2 years ago

that's a great plan, let's do that.

ASSERT-KTH / flacoco

Occurence of java.lang.RuntimeException: java.nio.file.NoSuchFileException: `CoveredTestResultPerTest.dat` #121