Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Container.followOutput() leaks thread #2276

Open
danberindei opened this issue Jan 21, 2020 · 7 comments
Open

Container.followOutput() leaks thread #2276

danberindei opened this issue Jan 21, 2020 · 7 comments
Labels
resolution/acknowledged

Comments

@danberindei
Copy link

Container.followOutput() uses LogUtils.attachConsumer(), which opens a long-running okhttp request and processes it using a FrameConsumerResultCallback.

The problem is that the FrameConsumerResultCallback, so it can't be closed after stopping the container, and the server side doesn't close the connection either, so the processing thread stays alive forever.

Our test suite uses an inheritable ThreadLocal to track and report thread leaks, and this is what it reports:

23:30:59,651 ERROR [TestSuiteProgress] Test failed: UNKNOWN.ThreadLeakChecker
org.infinispan.commons.test.ThreadLeakChecker$LeakException: Leaked thread: tc-okhttp-stream-1282372255 << testng-GracefulShutdownRestartIT << UNKNOWN
	at org.testcontainers.shaded.org.scalasbt.ipcsocket.UnixDomainSocketLibrary.read(Native Method) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.shaded.org.scalasbt.ipcsocket.UnixDomainSocket$UnixDomainSocketInputStream.doRead(UnixDomainSocket.java:149) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.shaded.org.scalasbt.ipcsocket.UnixDomainSocket$UnixDomainSocketInputStream.read(UnixDomainSocket.java:136) ~[testcontainers-1.12.4.jar:?]
	at java.io.FilterInputStream.read(FilterInputStream.java:133) ~[?:?]
	at org.testcontainers.dockerclient.transport.okhttp.UnixSocketFactory$1$1.read(UnixSocketFactory.java:46) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.shaded.okio.Okio$2.read(Okio.java:140) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.shaded.okio.AsyncTimeout$2.read(AsyncTimeout.java:237) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.shaded.okio.RealBufferedSource.request(RealBufferedSource.java:72) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.shaded.okio.RealBufferedSource.require(RealBufferedSource.java:65) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.shaded.okio.RealBufferedSource.readHexadecimalUnsignedLong(RealBufferedSource.java:307) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.shaded.okhttp3.internal.http1.Http1ExchangeCodec$ChunkedSource.readChunkSize(Http1ExchangeCodec.java:492) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.shaded.okhttp3.internal.http1.Http1ExchangeCodec$ChunkedSource.read(Http1ExchangeCodec.java:471) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.shaded.okhttp3.internal.connection.Exchange$ResponseBodySource.read(Exchange.java:286) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.shaded.okio.RealBufferedSource.exhausted(RealBufferedSource.java:61) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.dockerclient.transport.okhttp.OkHttpInvocationBuilder$FramedSink.accept(OkHttpInvocationBuilder.java:363) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.dockerclient.transport.okhttp.OkHttpInvocationBuilder$FramedSink.accept(OkHttpInvocationBuilder.java:352) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.dockerclient.transport.okhttp.OkHttpInvocationBuilder.lambda$executeAndStream$3(OkHttpInvocationBuilder.java:314) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.dockerclient.transport.okhttp.OkHttpInvocationBuilder$$Lambda$1863/0x0000000100fd5840.run(Unknown Source) ~[?:?]
	at java.lang.Thread.run(Thread.java:834) ~[?:?]
Caused by: org.infinispan.commons.test.ThreadLeakChecker$LeakException: testng-GracefulShutdownRestartIT << UNKNOWN
	at org.infinispan.commons.test.ThreadLeakChecker$ThreadInfoLocal.childValue(ThreadLeakChecker.java:107) ~[infinispan-commons-test-11.0.0-SNAPSHOT.jar:11.0.0-SNAPSHOT]
	at org.infinispan.commons.test.ThreadLeakChecker$ThreadInfoLocal.childValue(ThreadLeakChecker.java:104) ~[infinispan-commons-test-11.0.0-SNAPSHOT.jar:11.0.0-SNAPSHOT]
	at java.lang.ThreadLocal$ThreadLocalMap.<init>(ThreadLocal.java:411) ~[?:?]
	at java.lang.ThreadLocal.createInheritedMap(ThreadLocal.java:276) ~[?:?]
	at java.lang.Thread.<init>(Thread.java:450) ~[?:?]
	at java.lang.Thread.<init>(Thread.java:709) ~[?:?]
	at java.lang.Thread.<init>(Thread.java:630) ~[?:?]
	at org.testcontainers.dockerclient.transport.okhttp.OkHttpInvocationBuilder.executeAndStream(OkHttpInvocationBuilder.java:319) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.dockerclient.transport.okhttp.OkHttpInvocationBuilder.executeAndStream(OkHttpInvocationBuilder.java:295) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.dockerclient.transport.okhttp.OkHttpInvocationBuilder.get(OkHttpInvocationBuilder.java:89) ~[testcontainers-1.12.4.jar:?]
	at com.github.dockerjava.core.exec.LogContainerCmdExec.execute0(LogContainerCmdExec.java:42) ~[testcontainers-1.12.4.jar:?]
	at com.github.dockerjava.core.exec.LogContainerCmdExec.execute0(LogContainerCmdExec.java:12) ~[testcontainers-1.12.4.jar:?]
	at com.github.dockerjava.core.exec.AbstrAsyncDockerCmdExec.execute(AbstrAsyncDockerCmdExec.java:56) ~[testcontainers-1.12.4.jar:?]
	at com.github.dockerjava.core.exec.AbstrAsyncDockerCmdExec.exec(AbstrAsyncDockerCmdExec.java:21) ~[testcontainers-1.12.4.jar:?]
	at com.github.dockerjava.core.exec.AbstrAsyncDockerCmdExec.exec(AbstrAsyncDockerCmdExec.java:12) ~[testcontainers-1.12.4.jar:?]
	at com.github.dockerjava.core.command.AbstrAsyncDockerCmd.exec(AbstrAsyncDockerCmd.java:21) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.utility.LogUtils.attachConsumer(LogUtils.java:99) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.utility.LogUtils.followOutput(LogUtils.java:36) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.utility.LogUtils.followOutput(LogUtils.java:51) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.containers.Container.followOutput(Container.java:391) ~[testcontainers-1.12.4.jar:?]
	at java.util.ArrayList.forEach(ArrayList.java:1540) ~[?:?]
	at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:412) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.containers.GenericContainer.lambda$doStart$0(GenericContainer.java:317) ~[testcontainers-1.12.4.jar:?]
	at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:81) ~[duct-tape-1.0.8.jar:?]
	at org.testcontainers.containers.GenericContainer.doStart(GenericContainer.java:315) ~[testcontainers-1.12.4.jar:?]
	at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:302) ~[testcontainers-1.12.4.jar:?]
	at org.infinispan.server.test.ContainerInfinispanServerDriver.start(ContainerInfinispanServerDriver.java:146) ~[test-classes/:?]
	at org.infinispan.server.test.InfinispanServerDriver.start(InfinispanServerDriver.java:109) ~[test-classes/:?]
	at org.infinispan.server.test.InfinispanServerRule$1.evaluate(InfinispanServerRule.java:86) ~[test-classes/:?]
@stale
Copy link

stale bot commented Apr 23, 2020

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. If you believe this is a mistake, please reply to this comment to keep it open. If there isn't one already, a PR to fix or at least reproduce the problem in a test case will always help us get back on track to tackle this.

@stale stale bot added the stale label Apr 23, 2020
@stale
Copy link

stale bot commented May 7, 2020

This issue has been automatically closed due to inactivity. We apologise if this is still an active problem for you, and would ask you to re-open the issue if this is the case.

@stale stale bot closed this as completed May 7, 2020
@rnorth
Copy link
Member

rnorth commented May 7, 2020

Sorry that we’ve not had a chance to look into this yet. Let’s reopen.

@bsideup
Copy link
Member

bsideup commented May 7, 2020

@rnorth actually, it should be moved to docker-java now :)

@danberindei
Copy link
Author

I forgot about this issue, because I had modified our tests to ignore any tc-okhttp-stream-.* thread leaks.

The good news first: upgrading to testcontainers 1.15.0-rc1 (which includes docker-java 3.2.5) fixed the leak.

The bad news is that there is still a thread leak, with a new thread name pattern: docker-java-stream--.*. It appears because calling DockerClientFactory.instance().client() creates a Ryuk container, and a log callback to monitor the progress of Ryuk in case it fails to start that needs a thread, but closing the log callback does not stop the thread:

org.infinispan.commons.test.ThreadLeakChecker$LeakException: Leaked thread: docker-java-stream--98336395 << testng-InfinispanRuleBasicTest << org.infinispan.server.test.junit4.InfinispanRuleBasicTest
	at app//org.testcontainers.shaded.com.github.dockerjava.okhttp.UnixDomainSocket.recv(Native Method)
	at app//org.testcontainers.shaded.com.github.dockerjava.okhttp.UnixDomainSocket$UnixSocketInputStream.read(UnixDomainSocket.java:250)
	at java.base@11.0.7/java.io.FilterInputStream.read(FilterInputStream.java:133)
	at app//org.testcontainers.shaded.com.github.dockerjava.okhttp.UnixSocketFactory$1$1.read(UnixSocketFactory.java:45)
	at app//org.testcontainers.shaded.okio.Okio$2.read(Okio.java:140)
	at app//org.testcontainers.shaded.okio.AsyncTimeout$2.read(AsyncTimeout.java:237)
	at app//org.testcontainers.shaded.okio.RealBufferedSource.request(RealBufferedSource.java:72)
	at app//org.testcontainers.shaded.okio.RealBufferedSource.require(RealBufferedSource.java:65)
	at app//org.testcontainers.shaded.okio.RealBufferedSource.readHexadecimalUnsignedLong(RealBufferedSource.java:307)
	at app//org.testcontainers.shaded.okhttp3.internal.http1.Http1ExchangeCodec$ChunkedSource.readChunkSize(Http1ExchangeCodec.java:492)
	at app//org.testcontainers.shaded.okhttp3.internal.http1.Http1ExchangeCodec$ChunkedSource.read(Http1ExchangeCodec.java:471)
	at app//org.testcontainers.shaded.okhttp3.internal.connection.Exchange$ResponseBodySource.read(Exchange.java:286)
	at app//org.testcontainers.shaded.okio.RealBufferedSource$1.read(RealBufferedSource.java:436)
	at app//org.testcontainers.shaded.com.github.dockerjava.core.FramedInputStreamConsumer.accept(FramedInputStreamConsumer.java:30)
	at app//org.testcontainers.shaded.com.github.dockerjava.core.FramedInputStreamConsumer.accept(FramedInputStreamConsumer.java:12)
	at app//org.testcontainers.shaded.com.github.dockerjava.core.DefaultInvocationBuilder.lambda$executeAndStream$1(DefaultInvocationBuilder.java:275)
	at app//org.testcontainers.shaded.com.github.dockerjava.core.DefaultInvocationBuilder$$Lambda$181/0x00000008402da440.run(Unknown Source)
	at java.base@11.0.7/java.lang.Thread.run(Thread.java:834)
Caused by: org.infinispan.commons.test.ThreadLeakChecker$LeakException: testng-InfinispanRuleBasicTest << org.infinispan.server.test.junit4.InfinispanRuleBasicTest
	at org.infinispan.commons.test.ThreadLeakChecker$ThreadInfoLocal.childValue(ThreadLeakChecker.java:111)
	at org.infinispan.commons.test.ThreadLeakChecker$ThreadInfoLocal.childValue(ThreadLeakChecker.java:108)
	at java.base/java.lang.ThreadLocal$ThreadLocalMap.<init>(ThreadLocal.java:411)
	at java.base/java.lang.ThreadLocal.createInheritedMap(ThreadLocal.java:276)
	at java.base/java.lang.Thread.<init>(Thread.java:450)
	at java.base/java.lang.Thread.<init>(Thread.java:709)
	at java.base/java.lang.Thread.<init>(Thread.java:582)
	at org.testcontainers.shaded.com.github.dockerjava.core.DefaultInvocationBuilder.executeAndStream(DefaultInvocationBuilder.java:280)
	at org.testcontainers.shaded.com.github.dockerjava.core.DefaultInvocationBuilder.get(DefaultInvocationBuilder.java:66)
	at org.testcontainers.shaded.com.github.dockerjava.core.exec.LogContainerCmdExec.execute0(LogContainerCmdExec.java:42)
	at org.testcontainers.shaded.com.github.dockerjava.core.exec.LogContainerCmdExec.execute0(LogContainerCmdExec.java:12)
	at org.testcontainers.shaded.com.github.dockerjava.core.exec.AbstrAsyncDockerCmdExec.execute(AbstrAsyncDockerCmdExec.java:56)
	at org.testcontainers.shaded.com.github.dockerjava.core.exec.AbstrAsyncDockerCmdExec.exec(AbstrAsyncDockerCmdExec.java:21)
	at org.testcontainers.shaded.com.github.dockerjava.core.exec.AbstrAsyncDockerCmdExec.exec(AbstrAsyncDockerCmdExec.java:12)
	at org.testcontainers.shaded.com.github.dockerjava.core.command.AbstrAsyncDockerCmd.exec(AbstrAsyncDockerCmd.java:21)
	at org.testcontainers.utility.ResourceReaper.start(ResourceReaper.java:101)
	at org.testcontainers.DockerClientFactory.client(DockerClientFactory.java:197)
	at org.infinispan.server.test.core.ContainerInfinispanServerDriver.getDockerBridgeAddress(ContainerInfinispanServerDriver.java:86)
	at org.infinispan.server.test.core.ContainerInfinispanServerDriver.<init>(ContainerInfinispanServerDriver.java:79)
	at org.infinispan.server.test.core.ServerRunMode$2.newDriver(ServerRunMode.java:17)
	at org.infinispan.server.test.core.TestServer.initServerDriver(TestServer.java:139)
	at org.infinispan.server.test.junit4.InfinispanServerRule$1.evaluate(InfinispanServerRule.java:67)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:115)
	at org.testng.junit.JUnit4TestRunner.start(JUnit4TestRunner.java:82)
	at org.testng.junit.JUnit4TestRunner.run(JUnit4TestRunner.java:70)
	at org.testng.TestRunner$1.run(TestRunner.java:570)
	at org.testng.TestRunner.runJUnitWorkers(TestRunner.java:717)
	at org.testng.TestRunner.privateRunJUnit(TestRunner.java:601)
	at org.testng.TestRunner.run(TestRunner.java:502)
	at org.testng.SuiteRunner.runTest(SuiteRunner.java:455)
	at org.testng.SuiteRunner.access$000(SuiteRunner.java:40)
	at org.testng.SuiteRunner$SuiteWorker.run(SuiteRunner.java:489)
	at org.testng.internal.thread.ThreadUtil$1.call(ThreadUtil.java:52)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	... 1 more
Caused by: org.infinispan.commons.test.ThreadLeakChecker$LeakException: org.infinispan.server.test.junit4.InfinispanRuleBasicTest

I'm not sure if it's a testcontainers issue or a docker-java issue, but since it's a single thread I'm ok ignoring the new thread name pattern for now.

@bsideup bsideup reopened this Sep 15, 2020
@bsideup
Copy link
Member

bsideup commented Sep 15, 2020

@danberindei Thanks for the update! I re-opened the issue so that we remember to investigate Ryuk's leak 👍

@eastlondoner
Copy link

I am seeing this issue as well

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
resolution/acknowledged
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@rnorth @danberindei @bsideup @eastlondoner