How do I debug why unit tests sometimes fail due to Kotlin libs not being available?

Viewed 122

We have a really annoying issue with some flaky tests: they work 9/10 times, but every now and then they fail with a ClassNotFoundException when invoking some Kotlin code:

java.lang.ClassNotFoundException: kotlin.collections.Map
  at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:636)
  at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:182)
  at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:519)
  at java.base/java.lang.Class.forName0(Native Method)
  at java.base/java.lang.Class.forName(Class.java:375)
  at my-project.server.config.KConfigLoader.load(KConfigLoader.kt:77)
  at my-project.server.config.KConfigLoader.load(KConfigLoader.kt:53)
  at my-project.server.config.KConfigLoaderTest.loader_shold_register_unknown_properties(KConfigLoaderTest.kt:65)
  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78)
  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
  at java.base/java.lang.reflect.Method.invoke(Method.java:567)
  at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
  at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
  at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
  at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
  at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
  at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
  at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
  at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
  at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
  at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
  at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
  at org.apache.maven.surefire.junitcore.pc.Scheduler$1.run(Scheduler.java:405)
  at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
  at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
  at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
  at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630)
  at java.base/java.lang.Thread.run(Thread.java:831)

This happens on our CI server and sometimes locally. What I do not get is the flakyness aspect. Either the Kotlin standard library is on the classpath or not, right? I don't see how it can randomly fail at times.

Debugging info

Kotlin related stuff in parent pom

 ag -C2 kotlin ../pom.xml 
35:        <kotlin.version>1.5.20</kotlin.version>
36:        <kotlin.compiler.incremental>false</kotlin.compiler.incremental>
37-
38-        <maven.build.timestamp.format>yyyy-MM-dd'T'HH:mm:ss'Z'</maven.build.timestamp.format>
--
47-            </plugin>
48-            <plugin>
49:                <groupId>org.jetbrains.kotlin</groupId>
50:                <artifactId>kotlin-maven-plugin</artifactId>
51:                <version>${kotlin.version}</version>
52-                <executions>
53-                    <execution>
--
59-                        <configuration>
60-                            <sourceDirs>
61:                                <sourceDir>${project.basedir}/src/main/kotlin</sourceDir>
62-                                <sourceDir>${project.basedir}/src/main/java</sourceDir>
63-                            </sourceDirs>
--
71-                        <configuration>
72-                            <sourceDirs>
73:                                <sourceDir>${project.basedir}/src/test/kotlin</sourceDir>
74-                                <sourceDir>${project.basedir}/src/test/java</sourceDir>
75-                            </sourceDirs>
--
229-            <dependency>
230-                <groupId>com.fasterxml.jackson.module</groupId>
231:                <artifactId>jackson-module-kotlin</artifactId>
232-                <version>${jackson.version}</version>
233-            </dependency>
--
273-            </dependency>
274-            <dependency>
275:                <groupId>org.jetbrains.kotlin</groupId>
276:                <artifactId>kotlin-stdlib</artifactId>
277:                <version>${kotlin.version}</version>
278-            </dependency>
279-            <dependency>
280:                <groupId>org.jetbrains.kotlin</groupId>
281:                <artifactId>kotlin-test-junit</artifactId>
282:                <version>${kotlin.version}</version>
283-            </dependency>
284-            <dependency>
285:                <groupId>org.jetbrains.kotlin</groupId>
286:                <artifactId>kotlin-reflect</artifactId>
287:                <version>${kotlin.version}</version>
288-            </dependency>
289-            <dependency>

Plugin config

        <plugins>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-install-plugin</artifactId>
                <version>2.5.2</version>
            </plugin>
            <plugin>
                <groupId>org.jetbrains.kotlin</groupId>
                <artifactId>kotlin-maven-plugin</artifactId>
                <version>${kotlin.version}</version>
                <executions>
                    <execution>
                        <id>compile</id>
                        <phase>compile</phase>
                        <goals>
                            <goal>compile</goal>
                        </goals>
                        <configuration>
                            <sourceDirs>
                                <sourceDir>${project.basedir}/src/main/kotlin</sourceDir>
                                <sourceDir>${project.basedir}/src/main/java</sourceDir>
                            </sourceDirs>
                        </configuration>
                    </execution>
                    <execution>
                        <id>test-compile</id>
                        <goals>
                            <goal>test-compile</goal>
                        </goals>
                        <configuration>
                            <sourceDirs>
                                <sourceDir>${project.basedir}/src/test/kotlin</sourceDir>
                                <sourceDir>${project.basedir}/src/test/java</sourceDir>
                            </sourceDirs>
                        </configuration>
                    </execution>
                </executions>
            </plugin>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-compiler-plugin</artifactId>
                <version>3.8.1</version>
                <configuration>
                    <release>${jdk.version}</release>
                    <source>${jdk.version}</source>
                    <target>${jdk.version}</target>
                    <encoding>${project.build.sourceEncoding}</encoding>
                    <!--https://issues.apache.org/jira/browse/MCOMPILER-209-->
                    <useIncrementalCompilation>false</useIncrementalCompilation>
                    <compilerArgs>
                        <arg>-Xlint:all</arg>
                        <!--Silence class version ignore/deprecation warnings -->
                        <arg>-Xlint:-classfile</arg>
                        <!-- http://jdbi.org/#_compiling_with_parameter_names -->
                        <arg>-parameters</arg>
                    </compilerArgs>
                    <showWarnings>true</showWarnings>
                    <showDeprecation>true</showDeprecation>
                </configuration>
                <executions>
                    <!-- Replacing default-compile as it is treated specially by maven -->
                    <execution>
                        <id>default-compile</id>
                        <phase>none</phase>
                    </execution>
                    <!-- Replacing default-testCompile as it is treated specially by maven -->
                    <execution>
                        <id>default-testCompile</id>
                        <phase>none</phase>
                    </execution>
                    <execution>
                        <id>java-compile</id>
                        <phase>compile</phase>
                        <goals>
                            <goal>compile</goal>
                        </goals>
                    </execution>
                    <execution>
                        <id>java-test-compile</id>
                        <phase>test-compile</phase>
                        <goals>
                            <goal>testCompile</goal>
                        </goals>
                    </execution>
                </executions>
            </plugin>

Kotlin related in project pom

Pretty much everything happens in the parent pom wrt setup.

369-        <dependency>
370:            <groupId>org.jetbrains.kotlin</groupId>
371:            <artifactId>kotlin-stdlib</artifactId>
372-        </dependency>
373-        <dependency>
374:            <groupId>org.jetbrains.kotlin</groupId>
375:            <artifactId>kotlin-reflect</artifactId>
376-        </dependency>

Output from dependency:tree

This is what I get when running mvn dependency:tree -Dincludes=*jetbrains* in the folder containing the root pom:

22:39:55,407 [INFO] Scanning for projects...
22:39:55,542 [INFO] ------------------------------------------------------------------------
22:39:55,542 [INFO] Reactor Build Order:
22:39:55,542 [INFO] 
22:39:55,547 [INFO] my-project                                                             [pom]
22:39:55,547 [INFO] my-project-commons                                                     [jar]
22:39:55,547 [INFO] my-project-my-app-backend                                              [jar]
22:39:55,547 [INFO] my-project-people-backend                                              [jar]
22:39:55,957 [INFO] 
22:39:55,958 [INFO] ----------------------< no.ACME.my-project:my-project >-----------------------
22:39:55,959 [INFO] Building my-project 0.0.1-SNAPSHOT                                     [1/4]
22:39:55,959 [INFO] --------------------------------[ pom ]---------------------------------
22:39:55,971 [INFO] 
22:39:55,971 [INFO] --- maven-dependency-plugin:2.8:tree (default-cli) @ my-project ---
22:39:57,889 [INFO] 
22:39:57,891 [INFO] ------------------< no.ACME.my-project:my-project-commons >-------------------
22:39:57,892 [INFO] Building my-project-commons 0.0.1-SNAPSHOT                             [2/4]
22:39:57,892 [INFO] --------------------------------[ jar ]---------------------------------
22:39:58,354 [INFO] 
22:39:58,354 [INFO] --- maven-dependency-plugin:2.8:tree (default-cli) @ my-project-commons ---
22:39:58,385 [INFO] no.ACME.my-project:my-project-commons:jar:0.0.1-SNAPSHOT
22:39:58,385 [INFO] +- com.fasterxml.jackson.module:jackson-module-kotlin:jar:2.12.2:compile
22:39:58,385 [INFO] |  \- org.jetbrains.kotlin:kotlin-reflect:jar:1.5.20:compile
22:39:58,385 [INFO] |     \- org.jetbrains.kotlin:kotlin-stdlib:jar:1.5.20:compile
22:39:58,385 [INFO] |        +- org.jetbrains:annotations:jar:21.0.1:compile
22:39:58,385 [INFO] |        \- org.jetbrains.kotlin:kotlin-stdlib-common:jar:1.5.20:compile
22:39:58,385 [INFO] \- org.jetbrains.kotlin:kotlin-test-junit:jar:1.5.20:test
22:39:58,385 [INFO]    \- org.jetbrains.kotlin:kotlin-test:jar:1.5.20:test
22:39:58,386 [INFO] 
22:39:58,386 [INFO] ---------------< no.ACME.my-project:my-project-my-app-backend >---------------
22:39:58,386 [INFO] Building my-project-my-app-backend 0.0.1-SNAPSHOT                      [3/4]
22:39:58,386 [INFO] --------------------------------[ jar ]---------------------------------
22:39:59,524 [INFO] 
22:39:59,525 [INFO] --- maven-dependency-plugin:2.8:tree (default-cli) @ my-project-my-app-backend ---
22:39:59,568 [INFO] no.ACME.my-project:my-project-my-app-backend:jar:0.0.1-SNAPSHOT
22:39:59,568 [INFO] +- org.jetbrains.kotlin:kotlin-stdlib:jar:1.5.20:compile
22:39:59,568 [INFO] |  +- org.jetbrains:annotations:jar:21.0.1:compile
22:39:59,569 [INFO] |  \- org.jetbrains.kotlin:kotlin-stdlib-common:jar:1.5.20:compile
22:39:59,569 [INFO] \- org.jetbrains.kotlin:kotlin-reflect:jar:1.5.20:compile
22:39:59,569 [INFO] 
22:39:59,569 [INFO] ---------------< no.ACME.my-project:my-project-people-backend >---------------
22:39:59,569 [INFO] Building my-project-people-backend 0.0.1-SNAPSHOT                      [4/4]
22:39:59,569 [INFO] --------------------------------[ jar ]---------------------------------
22:39:59,656 [INFO] 
22:39:59,657 [INFO] --- maven-dependency-plugin:2.8:tree (default-cli) @ my-project-people-backend ---
22:39:59,670 [INFO] no.ACME.my-project:my-project-people-backend:jar:0.0.1-SNAPSHOT
22:39:59,671 [INFO] +- no.ACME.my-project:my-project-commons:jar:0.0.1-SNAPSHOT:compile
22:39:59,671 [INFO] |  \- com.fasterxml.jackson.module:jackson-module-kotlin:jar:2.12.2:compile
22:39:59,671 [INFO] |     \- org.jetbrains.kotlin:kotlin-reflect:jar:1.5.20:compile
22:39:59,671 [INFO] \- xyz.capybara:clamav-client:jar:2.0.2:compile
22:39:59,671 [INFO]    \- org.jetbrains.kotlin:kotlin-stdlib:jar:1.5.20:compile
22:39:59,671 [INFO]       +- org.jetbrains:annotations:jar:21.0.1:compile
22:39:59,671 [INFO]       \- org.jetbrains.kotlin:kotlin-stdlib-common:jar:1.5.20:compile
22:39:59,671 [INFO] ------------------------------------------------------------------------
22:39:59,671 [INFO] Reactor Summary for my-project 0.0.1-SNAPSHOT:
22:39:59,671 [INFO] 
22:39:59,674 [INFO] my-project ............................................. SUCCESS [  1.932 s]
22:39:59,677 [INFO] my-project-commons ..................................... SUCCESS [  0.497 s]
22:39:59,677 [INFO] my-project-my-app-backend .............................. SUCCESS [  1.183 s]
22:39:59,678 [INFO] my-project-people-backend .............................. SUCCESS [  0.102 s]
22:39:59,678 [INFO] ------------------------------------------------------------------------
22:39:59,678 [INFO] BUILD SUCCESS
22:39:59,678 [INFO] ------------------------------------------------------------------------
22:39:59,679 [INFO] Total time:  4.295 s
22:39:59,681 [INFO] Finished at: 2021-09-14T22:39:59+02:00
22:39:59,686 [INFO] ------------------------------------------------------------------------

Maven version

When this happens, it is usually on TeamCity when running Maven, but we sometimes see it in IntelliJ (not via Maven) as well.

Apache Maven 3.8.1 (05c21c65bdfed0f71a2f2ada8b84da59348c4c5d)
0 Answers
Related