Maven Build hangs between Surefire Tests
Asked Answered
S

1

6

For no apparent reason, and without any relevant changes to the code, my DB surefire tests are hanging after a specific test. The console output indicates that test 50 completes successfully and that test 51 has not yet started

[INFO] Running xxxx.server.db.dao.Test50
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.954 s - in xxxx.server.db.dao.Test50

I've run the following command to retrieve the thread dump below

mvndebug -DforkCount=0 clean install

The following does not function either and causes the same behavour at the same point in the test run

mvn clean install

The tests are being run on Windows 10 with a MySQL 5.7 Server using maven 3.3.9. I've tried using different versions of maven without success. Furthermore, I have tried different versions of the surefire plugin and different fork settings, with the only workable combination below

        <plugin>
            <groupId>org.apache.maven.plugins</groupId>
            <artifactId>maven-surefire-plugin</artifactId>
            <version>2.21.0</version>
            <configuration>
                <forkMode>always</forkMode>
                <forkCount>1</forkCount>
                <reuseForks>true</reuseForks>
                <threadCount>1</threadCount>
                <parallel>suites</parallel>
            </configuration>
        </plugin>

The thread dump state at hang time is as follows:

    "main@1" prio=5 tid=0x1 nid=NA waiting
    java.lang.Thread.State: WAITING
    at sun.misc.Unsafe.park(Unsafe.java:-1)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:429)
    at java.util.concurrent.FutureTask.get(FutureTask.java:191)
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter.awaitResultsDone(ForkStarter.java:460)
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter.runSuitesForkPerTestSet(ForkStarter.java:441)
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:293)
    at org.apache.maven.plugin.surefire.booterclient.ForkStarter.run(ForkStarter.java:245)
    at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeProvider(AbstractSurefireMojo.java:1149)
    at org.apache.maven.plugin.surefire.AbstractSurefireMojo.executeAfterPreconditionsChecked(AbstractSurefireMojo.java:978)
    at org.apache.maven.plugin.surefire.AbstractSurefireMojo.execute(AbstractSurefireMojo.java:854)
    at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo(DefaultBuildPluginManager.java:134)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:207)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:153)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute(MojoExecutor.java:145)
    at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:116)
    at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject(LifecycleModuleBuilder.java:80)
    at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build(SingleThreadedBuilder.java:51)
    at org.apache.maven.lifecycle.internal.LifecycleStarter.execute(LifecycleStarter.java:128)
    at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:307)
    at org.apache.maven.DefaultMaven.doExecute(DefaultMaven.java:193)
    at org.apache.maven.DefaultMaven.execute(DefaultMaven.java:106)
    at org.apache.maven.cli.MavenCli.execute(MavenCli.java:863)
    at org.apache.maven.cli.MavenCli.doMain(MavenCli.java:288)
    at org.apache.maven.cli.MavenCli.main(MavenCli.java:199)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-1)
    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:289)
    at org.codehaus.plexus.classworlds.launcher.Launcher.launch(Launcher.java:229)
    at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode(Launcher.java:415)
    at org.codehaus.plexus.classworlds.launcher.Launcher.main(Launcher.java:356)


    "Thread-17@5301" daemon prio=5 tid=0x37 nid=NA runnable
    java.lang.Thread.State: RUNNABLE
    at java.io.FileInputStream.readBytes(FileInputStream.java:-1)
    at java.io.FileInputStream.read(FileInputStream.java:255)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:284)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
    - locked <0x14bb> (a java.io.BufferedInputStream)
    at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
    at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
    at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
    - locked <0x14bc> (a java.io.InputStreamReader)
    at java.io.InputStreamReader.read(InputStreamReader.java:184)
    at java.io.BufferedReader.fill(BufferedReader.java:161)
    at java.io.BufferedReader.readLine(BufferedReader.java:324)
    at java.io.BufferedReader.readLine(BufferedReader.java:389)
    at org.apache.maven.surefire.shade.org.apache.maven.shared.utils.cli.StreamPumper.run(StreamPumper.java:76)

    "Thread-17@5301" daemon prio=5 tid=0x37 nid=NA runnable
    java.lang.Thread.State: RUNNABLE
    at java.io.FileInputStream.readBytes(FileInputStream.java:-1)
    at java.io.FileInputStream.read(FileInputStream.java:255)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:284)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
    - locked <0x14bb> (a java.io.BufferedInputStream)
    at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
    at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
    at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
    - locked <0x14bc> (a java.io.InputStreamReader)
    at java.io.InputStreamReader.read(InputStreamReader.java:184)
    at java.io.BufferedReader.fill(BufferedReader.java:161)
    at java.io.BufferedReader.readLine(BufferedReader.java:324)
    at java.io.BufferedReader.readLine(BufferedReader.java:389)
    at org.apache.maven.surefire.shade.org.apache.maven.shared.utils.cli.StreamPumper.run(StreamPumper.java:76)


    "Thread-18@5300" daemon prio=5 tid=0x38 nid=NA runnable
    java.lang.Thread.State: RUNNABLE
    at java.io.FileInputStream.readBytes(FileInputStream.java:-1)
    at java.io.FileInputStream.read(FileInputStream.java:255)
    at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
    at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
    at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
    - locked <0x14ba> (a java.io.InputStreamReader)
    at java.io.InputStreamReader.read(InputStreamReader.java:184)
    at java.io.BufferedReader.fill(BufferedReader.java:161)
    at java.io.BufferedReader.readLine(BufferedReader.java:324)
    at java.io.BufferedReader.readLine(BufferedReader.java:389)
    at org.apache.maven.surefire.shade.org.apache.maven.shared.utils.cli.StreamPumper.run(StreamPumper.java:76)

    "Thread-16@5299" daemon prio=5 tid=0x36 nid=NA waiting
    java.lang.Thread.State: WAITING
    at sun.misc.Unsafe.park(Unsafe.java:-1)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
    at java.util.concurrent.Semaphore.acquire(Semaphore.java:312)
    at org.apache.maven.plugin.surefire.booterclient.lazytestprovider.TestLessInputStream.awaitNextCommand(TestLessInputStream.java:165)
    at org.apache.maven.plugin.surefire.booterclient.lazytestprovider.TestLessInputStream.beforeNextCommand(TestLessInputStream.java:136)
    at org.apache.maven.plugin.surefire.booterclient.lazytestprovider.AbstractCommandStream.read(AbstractCommandStream.java:100)
    at org.apache.maven.surefire.shade.org.apache.maven.shared.utils.cli.StreamFeeder.feed(StreamFeeder.java:123)
    at org.apache.maven.surefire.shade.org.apache.maven.shared.utils.cli.StreamFeeder.run(StreamFeeder.java:60)


    "ping-timer-10s@5111" daemon prio=5 tid=0x19 nid=NA waiting
    java.lang.Thread.State: WAITING
    at sun.misc.Unsafe.park(Unsafe.java:-1)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)


    "timeout-check-timer@5108" daemon prio=5 tid=0x18 nid=NA waiting
    java.lang.Thread.State: WAITING
    at sun.misc.Unsafe.park(Unsafe.java:-1)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
    at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

All 5 Resolver deamons are in the same state

    "resolver-5@5058" daemon prio=5 tid=0x17 nid=NA waiting
    java.lang.Thread.State: WAITING
    at sun.misc.Unsafe.park(Unsafe.java:-1)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

    "ThreadedStreamConsumer@5298" daemon prio=5 tid=0x34 nid=NA waiting
    java.lang.Thread.State: WAITING
    at sun.misc.Unsafe.park(Unsafe.java:-1)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:403)
    at org.apache.maven.plugin.surefire.booterclient.output.ThreadedStreamConsumer$Pumper.run(ThreadedStreamConsumer.java:83)
    at java.lang.Thread.run(Thread.java:748)

It always hangs at the same place in the test run. I've tried cheching and setting the max connections on the DB. There are only 3 connections active at this time and the limit is 151. The thread setting in MySql has a max of 64.

All the application DB connections for test50 are closed in final try blocks.

Disabling test50 causes the same result. I don't know which test is being run next.

There is of course something that I am missing. Any ideas?

Schematism answered 22/5, 2018 at 18:25 Comment(6)
What Java version did you use when it worked and what are you using now?Zita
Hi Thorbjorn, the java version has not changed and is 1.8.0-151.Schematism
Post the entire thread dump via pastebin.Welborn
rustyx, I've posted the entire thread dump, but am not aware of pastebinSchematism
Have you tried to run the suspicious tests alone ?Coloquintida
Hi khmarbaise, all tests run alone. The issue is that I'm not sure which test runs next as it is not started. I tried ignoring the other tests in the package, but still no luck.Schematism
S
0

The issue in the end was an environmental variable setting. The PATH on my Windows box included C:\ProgramData\Oracle\javapath, which is a link to C:\ProgramData\Oracle\Java\javapath. The JAVA_HOME variable was set to my installation of Java under Program files.

C:\ProgramData\Oracle\Java\javapath only contains 3 files (java.exe, javaw.exe and javaws.exe) of a previous version.

When I changed the path to my bin directory of JAVA_HOME, everything worked after that.

Schematism answered 30/5, 2018 at 6:19 Comment(0)

© 2022 - 2024 — McMap. All rights reserved.