Test container fails to stop when used as Spring bean

[vpavic]

If a container is used as a bean in Spring application (sort of like an embedded container) that runs on Tomcat, the container fails to stop when shutdown signal is sent.

Container is configured like this:

@Bean(initMethod = "start")
public GenericContainer redisContainer() {
	return new GenericContainer("redis:3.2.9").withExposedPorts(6379);
}

@Bean
public JedisConnectionFactory redisConnectionFactory() {
	JedisConnectionFactory connectionFactory = new JedisConnectionFactory();
	connectionFactory.setHostName(redisContainer().getContainerIpAddress());
	connectionFactory.setPort(redisContainer().getMappedPort(6379));
	return connectionFactory;
}

Shutdown error:

14-Jun-2017 14:48:10.987 SEVERE [localhost-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [ROOT] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@2b9ff8a8]) and a value of type [org.testcontainers.shaded.io.netty.util.internal.InternalThreadLocalMap] (value [org.testcontainers.shaded.io.netty.util.internal.InternalThreadLocalMap@4581e709]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
14-Jun-2017 14:48:10.988 SEVERE [localhost-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [ROOT] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@2b9ff8a8]) and a value of type [org.testcontainers.shaded.io.netty.util.internal.InternalThreadLocalMap] (value [org.testcontainers.shaded.io.netty.util.internal.InternalThreadLocalMap@13da7c79]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
14-Jun-2017 14:48:10.988 SEVERE [localhost-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.checkThreadLocalMapForLeaks The web application [ROOT] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@2b9ff8a8]) and a value of type [org.testcontainers.shaded.io.netty.util.internal.InternalThreadLocalMap] (value [org.testcontainers.shaded.io.netty.util.internal.InternalThreadLocalMap@34e88997]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.

This leaves Tomcat hanging.

The sample (a simple Spring Boot app) to reproduce the problem is available in this repo. To reproduce the problem either run the integrationTest Gradle task using ./gradlew integrationTest (this uses gretty to integration test the app on Tomcat 8), or build the WAR and run it on Tomcat (in this case the -Dspring.profiles.active=redisContainer VM parameter is needed).

To give some background - we're in the process of migrating Spring Session integration tests to TestContainers (spring-projects/spring-session#798).

JUnit @ClassRule based integration tests were easy to migrate however the project also contains some sample application which are packaged as WARs and then integration tested on Tomcat 8 using gretty.

The idea was to provide a Spring profile which would start appropriate test container (in this case Redis) and configure the consumer (Redis connection factory) to connect to it but this has proved to be problematic due to reasons explained above.

[rnorth]

Hmm, presumably there's nothing calling stop() on the container and that's what's leaving everything up in the air. The error you're getting, and the ThreadLocal it refers to, look unfamiliar, but I wonder if they correspond to unclosed DockerClient instances.

I'll try and have a better look tomorrow - I think we should be able to do something, it just might mean working out where the right hook point is to force a proper shutdown.

[vpavic]

Thanks for the feedback @rnorth!

Well, with GenericContainer being AutoCloseable the Spring context should trigger it upon closing the application context, which is the same as having things explicit like this:

@Bean(initMethod = "start", destroyMethod = "stop")
public GenericContainer redisContainer() {
	return new GenericContainer("redis:3.2.9").withExposedPorts(6379);
}

[kiview]

I've discovered something which might help in pinpointing the actual bug. After changing the project to use an embedded Tomcat, an error will be thrown on shutdown:

2017-06-23 17:21:24.951  INFO 23777 --- [       Thread-6] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans on shutdown
2017-06-23 17:21:25.249 ERROR 23777 --- [rjava-netty-1-5] c.g.d.core.async.ResultCallbackTemplate  : Error during callback

com.github.dockerjava.api.exception.BadRequestException: {"message":"removal of container 3d5b469b19c0071ea3bf57c26ccee3633fec7ec3e2365376c5efd3d38ca91e55 is already in progress"}

This seems to be a race condition between the Spring Context calling the destroy method and the ResourceReaper being triggered by the JVM shutdown (

testcontainers-java/core/src/main/java/org/testcontainers/utility/ResourceReaper.java

Line 34 in 8c14b99

Runtime.getRuntime().addShutdownHook(new Thread(this::performCleanup));

).

I could reproduce the error when building a fat-jar with compile 'org.springframework.boot:spring-boot-starter-jetty. So the setup of using Gradle and gretty seems to add to the problem.

[kiview]

I've started to debug a litte more into the Spring code and I found, that destroySingletons() in DefaultSingletonBeanRegistry did correctly trigger the shutdown of the Testcontainers bean and the docker container was removed afterwards. However Tomcat still hangs on

2017-06-23 17:54:34.262  INFO 19593 --- [ost-startStop-1] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans on shutdown

afterwards, so maybe we have to look deeper into Spring to find the actual reason?

[vpavic]

Thanks for the feedback @kiview, we'll try to get a better look at Spring part of this.

[bsideup]

@vpavic
Small status update:
I see an issue on TestContainers' side, or maybe not an issue, but something we didn't consider yet.

When the test is being executed by JUnit, it calls System.exit(0) at the end of all tests. It makes interrupts all threads, including non-daemon ones.

When you run your app with TC inside some application server, it doesn't happen and for instance, Netty keeps its threads.

I'll look at it and will try to solve by providing additional API to "close" everything in TestContainers :)

[vpavic]

Thanks for the update @bsideup!

Seeing this issue is assigned to 1.4.0 milestone which is scheduled for June 30 ATM, do you expect to have the described improvement in that timeline?

/cc @rwinch

[bsideup]

@vpavic I'm working on it right now, but can't promise anything at this moment :) So far it seems that the problem might come from docker-java and not TC itself. If so, I'll try to workaround it, otherwise we have to wait until it's fixed & released there

[bsideup]

@vpavic

Small status update:
After some digging, I've discovered a few places where threads are not released, mostly in docker-java.

However, with this PR I was able to achieve proper "exit 0" behaviour. The following snippet will exit once everything is cleaned & closed:

import org.testcontainers.DockerClientFactory;
import org.testcontainers.containers.GenericContainer;

public class Foo {

    public static void main(String[] args) throws Exception {
        try (GenericContainer container = new GenericContainer().withCommand("top")) {
            container.start();
        }

        DockerClientFactory.instance().client().close();

        System.out.println("QQQQ");
    }
}

I see some weird timeout-like behaviour after it prints "QQQQ", 30s or so, I think I know why will dig further, but at least it exits now :)
You can try it with jitpack ( https://www.testcontainers.org/usage.html#maven-dependencies ) or wait until 1.4.0, the release is around the corner :)

[vpavic]

Thanks again for the update @bsideup!

I've tried the snapshot by applying the following diff to the original repro project:

diff --git a/build.gradle b/build.gradle
index 4aaa259..86009a8 100644
--- a/build.gradle
+++ b/build.gradle
@@ -20,12 +20,13 @@ sourceCompatibility = 1.8
 
 repositories {
        jcenter()
+       maven { url 'https://jitpack.io' }
 }
 
 dependencies {
        compile 'org.springframework.boot:spring-boot-starter-data-redis'
        compile 'org.springframework.boot:spring-boot-starter-web'
-       compile 'org.testcontainers:testcontainers:1.3.0'
+       compile 'com.github.testcontainers.testcontainers-java:testcontainers:-SNAPSHOT'
 
        providedRuntime 'org.springframework.boot:spring-boot-starter-tomcat'
 

After running the ./gradlew clean integrationTest --refresh-dependencies command the result is unfortunately still the same, it ends up hanging.

Is it possible that the snapshot is not yet updated with your changes?

[bsideup]

@vpavic

it could be. Try compile 'com.github.testcontainers.testcontainers-java:testcontainers:3cce55a417' and let us know! Also, give it some time (like 30s or so), I see (locally) that it takes some time to exit (without doing anything, I'm still figuring out why)

[vpavic]

Yeah, I saw your comment so I gave it a quite a bit more than 30 sec but it didn't help.
OK, will try to build it myself and let you know.

[bsideup]

@vpavic FYI there was a mistake in my previous message (wrong GAV), I fixed it, sorry!