spring-session

spring-session copied to clipboard

When running the build I see warnings like this:

:spring-session-sample-javaconfig-redis:jar UP-TO-DATE
:spring-session-sample-javaconfig-redis:integrationTest
:spring-session-sample-javaconfig-redis:appAfterIntegrationTest
19:43:55.657 [localhost-startStop-1] INFO  o.s.w.c.s.AnnotationConfigWebApplicationContext - Closing Root WebApplicationContext: startup date [Thu Sep 07 19:43:50 CDT 2017]; root of context hierarchy
19:43:55.658 [localhost-startStop-1] INFO  o.s.c.s.DefaultLifecycleProcessor - Stopping beans in phase 2147483647

19:43:57 WARN  The web application [ROOT] appears to have started a thread named [dockerjava-netty-1-1] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 java.lang.Thread.sleep(Native Method)
 org.testcontainers.shaded.io.netty.util.concurrent.SingleThreadEventExecutor.confirmShutdown(SingleThreadEventExecutor.java:705)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:325)
 org.testcontainers.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
 org.testcontainers.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
 java.lang.Thread.run(Thread.java:745)
19:43:57 WARN  The web application [ROOT] appears to have started a thread named [threadDeathWatcher-3-1] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 java.lang.Thread.sleep(Native Method)
 org.testcontainers.shaded.io.netty.util.ThreadDeathWatcher$Watcher.run(ThreadDeathWatcher.java:152)
 org.testcontainers.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
 java.lang.Thread.run(Thread.java:745)
19:43:57 WARN  The web application [ROOT] appears to have started a thread named [dockerjava-netty-1-2] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 java.lang.Thread.sleep(Native Method)
 org.testcontainers.shaded.io.netty.util.concurrent.SingleThreadEventExecutor.confirmShutdown(SingleThreadEventExecutor.java:705)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:325)
 org.testcontainers.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
 org.testcontainers.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
 java.lang.Thread.run(Thread.java:745)

we should ensure all the threads are shutdown properly

@vpavic Can you take a look at this?

@rwinch I think the problem is related to the fact that Netty's ThreadPool in docker-java is starting non-daemon threads as explained by @bsideup in testcontainers/testcontainers-java#369. Not sure we can do much about that from our side.

Hey guys! Yes, our beloved docker-java dependency brings the issue :) I don't think it's a real memory issue because 1) it's testing 2) we start a single pool for all tests, but I definitely want to fix it one day. Does it cause issues to you, or so far it's just an annoying warning?

@bsideup I think the leak is contributing to memory being consumed in our build since we run lots of different samples war applications for integration tests which cannot be cleaned up.

I'm afraid we're blocked here until testcontainers/testcontainers-java#369 is addressed.

@vpavic does it mean that the workaround I provided didn't help?

Hi @bsideup, your workaround did help us to get things working, this issue is only about memory leak warnings we're encountering.

@vpavic ok, I will take a look again and try to fix it in docker-java because AFAIR we can't control it in TestContainers

We're still experiencing these with TestContainers 1.7.1:

Apr 20, 2018 2:26:54 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
WARNING: The web application [ROOT] appears to have started a thread named [ducttape-0] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 sun.misc.Unsafe.park(Native Method)
 java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
 java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
 java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
 java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
 java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
 java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
 java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
 java.lang.Thread.run(Thread.java:748)
Apr 20, 2018 2:26:54 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
WARNING: The web application [ROOT] appears to have started a thread named [testcontainers-netty-1-1] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait0(Native Method)
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait(Native.java:111)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:231)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:255)
 org.testcontainers.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
 org.testcontainers.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
 java.lang.Thread.run(Thread.java:748)
Apr 20, 2018 2:26:54 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
WARNING: The web application [ROOT] appears to have started a thread named [threadDeathWatcher-3-1] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 java.lang.Thread.sleep(Native Method)
 org.testcontainers.shaded.io.netty.util.ThreadDeathWatcher$Watcher.run(ThreadDeathWatcher.java:152)
 org.testcontainers.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
 java.lang.Thread.run(Thread.java:748)
Apr 20, 2018 2:26:54 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
WARNING: The web application [ROOT] appears to have started a thread named [testcontainers-netty-1-2] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait0(Native Method)
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait(Native.java:111)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:231)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:255)
 org.testcontainers.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
 org.testcontainers.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
 java.lang.Thread.run(Thread.java:748)
Apr 20, 2018 2:26:54 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
WARNING: The web application [ROOT] appears to have started a thread named [testcontainers-netty-1-3] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait0(Native Method)
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait(Native.java:111)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:231)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:255)
 org.testcontainers.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
 org.testcontainers.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
 java.lang.Thread.run(Thread.java:748)
Apr 20, 2018 2:26:54 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
WARNING: The web application [ROOT] appears to have started a thread named [testcontainers-netty-1-4] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait0(Native Method)
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait(Native.java:111)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:231)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:255)
 org.testcontainers.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
 org.testcontainers.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
 java.lang.Thread.run(Thread.java:748)
Apr 20, 2018 2:26:54 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
WARNING: The web application [ROOT] appears to have started a thread named [testcontainers-netty-1-5] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait0(Native Method)
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait(Native.java:111)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:231)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:255)
 org.testcontainers.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
 org.testcontainers.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
 java.lang.Thread.run(Thread.java:748)
Apr 20, 2018 2:26:54 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
WARNING: The web application [ROOT] appears to have started a thread named [testcontainers-netty-1-6] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait0(Native Method)
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait(Native.java:111)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:231)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:255)
 org.testcontainers.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
 org.testcontainers.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
 java.lang.Thread.run(Thread.java:748)
Apr 20, 2018 2:26:54 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
WARNING: The web application [ROOT] appears to have started a thread named [testcontainers-netty-1-7] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait0(Native Method)
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait(Native.java:111)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:231)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:255)
 org.testcontainers.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
 org.testcontainers.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
 java.lang.Thread.run(Thread.java:748)
Apr 20, 2018 2:26:54 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
WARNING: The web application [ROOT] appears to have started a thread named [testcontainers-ryuk] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 java.lang.Object.wait(Native Method)
 org.testcontainers.utility.ResourceReaper.lambda$start$2(ResourceReaper.java:127)
 org.testcontainers.utility.ResourceReaper$$Lambda$99/254873768.run(Unknown Source)
 java.lang.Thread.run(Thread.java:748)
Apr 20, 2018 2:26:54 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
WARNING: The web application [ROOT] appears to have started a thread named [testcontainers-netty-1-8] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait0(Native Method)
 org.testcontainers.shaded.io.netty.channel.epoll.Native.epollWait(Native.java:111)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.epollWait(EpollEventLoop.java:231)
 org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:255)
 org.testcontainers.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
 org.testcontainers.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
 java.lang.Thread.run(Thread.java:748)

testcontainers/testcontainers-java#651 is tracking this on TestContainers side.

As explained in more detail in https://github.com/testcontainers/testcontainers-java/issues/651#issuecomment-429444961, I'm pretty sure this could be solved (or more correctly, the warnings omitted), by setting the skipMemoryLeakChecksOnJvmShutdown Tomcat context attribute.

If this would be a desired solution, I'd propose to make this attribute configurable via TomcatWebServerFactoryCustomizer (is this the correct class?) and enabling it for the tests.

Thanks for the update @kiview.

@rwinch In light of Kevin's comment on testcontainers/testcontainers-java#651 do you agree that we could simply live with this?

It seems like the threads should still be explicitly shut down. Is there a reason we cannot do that?

While a daemon thread isn't an issue in terms of letting the JVM shutdown, it can still leak memory if it isn't explicitly shutdown in an environment where the JVM process might out live the scope of the application. Consider a web application that is deployed to Tomcat and then the application is undeployed and a new version is deployed. In this scenario if the daemon thread is not shut down it will continue to run because it has its own GC root.

it can still leak memory if it isn't explicitly shutdown in an environment where the JVM process might out live the scope of the application.

Yeah, I'm aware of that. But bear in mind that this only happens in our Gretty based sample app integration tests, where we use Testcontainers as @Beans which outside of its intended usage. On top of that, our usage is also tied to a specific app profile that runs only when explicitly enabled which we do for integration tests only:

https://github.com/spring-projects/spring-session/blob/5f1b7d67223c019678c9e679c080ef436ec6f58c/samples/javaconfig/custom-cookie/src/main/java/sample/EmbeddedRedisConfig.java#L28

https://github.com/spring-projects/spring-session/blob/5f1b7d67223c019678c9e679c080ef436ec6f58c/samples/javaconfig/custom-cookie/spring-session-sample-javaconfig-custom-cookie.gradle#L22

First we do have a link related to test containers, so I don't think we should ignore the leak.

Second, I think this extra noise makes it hard to find additional issues.

But bear in mind that this only happens in our Gretty based sample app integration tests, where we use Testcontainers as @Beans which outside of its intended usage

It's not really that different. The daemon thread doesn't shutdown when a test has completed. Instead it waits till all of the tests are done and the JVM exits. This means there is a leak in tests when used as intended too.

It seems like that we should wait until it gets properly fixed to close this out.

Thanks for both your input. We will try to investigate in Testcontainers if we have enough control over those threads, to terminate them in an orderly fashion.

The threads from OkHttp might we out of our control though, but we'll check it.

I haven't been keeping up, but if there isn't a way to to it with OkHttp has a ticket been logged?

We just recently switched from Netty to OkHttp as the transport (for multiple different reasons), so we haven't investigated OkHttp's behavior in this regard yet.

But understanding your use case and the actual problem better now, we should be able to generate at least some insights regarding which work would be involved on our side to actually fix it. Also it was important to us to understand, if you had an issue with the root cause or just with the warnings.