testcontainers / testcontainers/testcontainers-java

Container start failure can lead to repeated error from Docker Java client

Offen
#687 1 Kommentar 0 Reaktionen 0 zugewiesene Personen Auf GitHub ansehen

Dieses Issue hat noch niemand übernommen.

resolution/acknowledged
Vorherrschende Sprache
Java
Sterne
8.7k
Forks
1.9k
Ø Merge
2 T. 17 Std.
Gemergte PRs (30 T.)
9

Beschreibung

We have some tests in Spring Boot that use Testcontainers 1.7.2 to run Cassandra. Sometimes, when Cassandra fails to start, things seem to get stuck such that Docker Java client repeatedly logs an error message. We give Cassandra 3 attempts to start, each timing out at 60 seconds.

The first attempt to start Cassandra fails:

2018-05-11 09:44:13.522  INFO 5291 --- [           main] tAndSystemPropertyClientProviderStrategy : Found docker client settings from environment
2018-05-11 09:44:13.553  INFO 5291 --- [           main] o.t.d.DockerClientProviderStrategy       : Found Docker environment with Environment variables, system properties
and defaults. Resolved:
    dockerHost=unix:///var/run/docker.sock
    apiVersion='{UNKNOWN_VERSION}'
    registryUrl='https://index.docker.io/v1/'
    registryUsername='root'
    registryPassword='null'
    registryEmail='null'
    dockerConfig='DefaultDockerClientConfig[dockerHost=unix:///var/run/docker.sock,registryUsername=root,registryPassword=<null>,registryEmail=<null>,registryUrl=https://i
ndex.docker.io/v1/,dockerConfigPath=/root/.docker,sslConfig=<null>,apiVersion={UNKNOWN_VERSION},dockerConfig=<null>]'

2018-05-11 09:44:18.196  INFO 5291 --- [           main] org.testcontainers.DockerClientFactory   : Docker host IP address is 172.17.0.1
2018-05-11 09:44:18.499  INFO 5291 --- [           main] org.testcontainers.DockerClientFactory   : Connected to docker:
  Server Version: 17.05.0-ce
  API Version: 1.29
  Operating System: Debian GNU/Linux buster/sid (containerized)
  Total Memory: 24110 MB
2018-05-11 09:44:22.574  INFO 5291 --- [           main] org.testcontainers.DockerClientFactory   : Ryuk started - will monitor and terminate Testcontainers containers on
JVM exit
        ℹ︎ Checking the system...
        ✔ Docker version should be at least 1.6.0
        ✔ Docker environment should have more than 2GB free disk space
        ✔ File should be mountable
2018-05-11 09:44:23.016  INFO 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Pulling docker image: cassandra:3.11.1. Please be patient; this may tak
e some time but only needs to be done once.
2018-05-11 09:44:43.405  INFO 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Creating container for image: cassandra:3.11.1
2018-05-11 09:44:43.566  INFO 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Starting container with ID: 3bb922ee9dd4e342be159b92f851ca1afe73a77fde9
2784a3125c484a2cc7137
2018-05-11 09:44:44.760  INFO 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Container cassandra:3.11.1 is starting: 3bb922ee9dd4e342be159b92f851ca1
afe73a77fde92784a3125c484a2cc7137
2018-05-11 09:45:44.972 ERROR 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Could not start container

org.testcontainers.containers.ContainerLaunchException: Timed out waiting for container port to open (172.17.0.1 ports: [32770] should be listening)
	at org.testcontainers.containers.wait.strategy.HostPortWaitStrategy.waitUntilReady(HostPortWaitStrategy.java:47)
	at org.springframework.boot.testsupport.testcontainers.CassandraContainer$WaitStrategy.waitUntilReady(CassandraContainer.java:57)
	at org.testcontainers.containers.wait.strategy.AbstractWaitStrategy.waitUntilReady(AbstractWaitStrategy.java:32)
	at org.testcontainers.containers.GenericContainer.waitUntilContainerStarted(GenericContainer.java:531)
	at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:258)
	at org.testcontainers.containers.GenericContainer.lambda$start$0(GenericContainer.java:209)
	at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:76)
	at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:207)
	at org.testcontainers.containers.GenericContainer.starting(GenericContainer.java:638)
	at org.testcontainers.containers.FailureDetectingExternalResource$1.evaluate(FailureDetectingExternalResource.java:29)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:379)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:340)
	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:125)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:413)

2018-05-11 09:45:45.006 ERROR 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Container log output (if any) will follow:
…
2018-05-11 09:45:46.148  INFO 5291 --- [iners-netty-1-8] 🐳 [cassandra:3.11.1]                    : STDOUT: INFO  [MigrationStage:1] 2018-05-11 09:45:38,024 ViewManager.ja
va:137 - Not submitting build tasks for views in keyspace system_distributed as storage service is not initialized
2018-05-11 09:45:46.148  INFO 5291 --- [iners-netty-1-8] 🐳 [cassandra:3.11.1]                    : STDOUT: INFO  [MigrationStage:1] 2018-05-11 09:45:38,196 ColumnFamilySt
ore.java:408 - Initializing system_distributed.parent_repair_history
2018-05-11 09:45:46.148  INFO 5291 --- [iners-netty-1-8] 🐳 [cassandra:3.11.1]                    : STDOUT: INFO  [MigrationStage:1] 2018-05-11 09:45:38,613 ColumnFamilySt
ore.java:408 - Initializing system_distributed.repair_history
2018-05-11 09:45:46.148  INFO 5291 --- [iners-netty-1-8] 🐳 [cassandra:3.11.1]                    : STDOUT: INFO  [MigrationStage:1] 2018-05-11 09:45:38,621 ColumnFamilySt
ore.java:408 - Initializing system_distributed.view_build_status
2018-05-11 09:45:46.148  INFO 5291 --- [iners-netty-1-8] 🐳 [cassandra:3.11.1]                    : STDOUT: INFO  [main] 2018-05-11 09:45:38,732 StorageService.java:1442 -
 JOINING: Finish joining ring

And so does the second attempt, but with no container log output this time:

2018-05-11 09:45:46.149  INFO 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Creating container for image: cassandra:3.11.1
2018-05-11 09:45:49.979  INFO 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Starting container with ID: 7f26fb8bdaffea1d9573c88254bf0a596336d48bebb
aa24d5fa81286669f1808
2018-05-11 09:45:54.775  INFO 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Container cassandra:3.11.1 is starting: 7f26fb8bdaffea1d9573c88254bf0a5
96336d48bebbaa24d5fa81286669f1808
2018-05-11 09:46:55.087 ERROR 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Could not start container

org.testcontainers.containers.ContainerLaunchException: Timed out waiting for container port to open (172.17.0.1 ports: [32775] should be listening)
	at org.testcontainers.containers.wait.strategy.HostPortWaitStrategy.waitUntilReady(HostPortWaitStrategy.java:47)
	at org.springframework.boot.testsupport.testcontainers.CassandraContainer$WaitStrategy.waitUntilReady(CassandraContainer.java:57)
	at org.testcontainers.containers.wait.strategy.AbstractWaitStrategy.waitUntilReady(AbstractWaitStrategy.java:32)
	at org.testcontainers.containers.GenericContainer.waitUntilContainerStarted(GenericContainer.java:531)
	at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:258)
	at org.testcontainers.containers.GenericContainer.lambda$start$0(GenericContainer.java:209)
	at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:76)
	at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:207)
	at org.testcontainers.containers.GenericContainer.starting(GenericContainer.java:638)
	at org.testcontainers.containers.FailureDetectingExternalResource$1.evaluate(FailureDetectingExternalResource.java:29)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:379)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:340)
	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:125)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:413)

2018-05-11 09:46:55.467 ERROR 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Container log output (if any) will follow:

The third then fails in a similar fashion:

2018-05-11 09:47:10.299  INFO 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Creating container for image: cassandra:3.11.1
2018-05-11 09:47:30.691  INFO 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Starting container with ID: 06484b44ae48384289006a3af3892777a76cc5c0ac6
2bd0570ed0d325d902c16
2018-05-11 09:47:50.170  INFO 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Container cassandra:3.11.1 is starting: 06484b44ae48384289006a3af389277
7a76cc5c0ac62bd0570ed0d325d902c16
2018-05-11 09:48:50.506 ERROR 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Could not start container

org.testcontainers.containers.ContainerLaunchException: Timed out waiting for container port to open (172.17.0.1 ports: [32780] should be listening)
	at org.testcontainers.containers.wait.strategy.HostPortWaitStrategy.waitUntilReady(HostPortWaitStrategy.java:47)
	at org.springframework.boot.testsupport.testcontainers.CassandraContainer$WaitStrategy.waitUntilReady(CassandraContainer.java:57)
	at org.testcontainers.containers.wait.strategy.AbstractWaitStrategy.waitUntilReady(AbstractWaitStrategy.java:32)
	at org.testcontainers.containers.GenericContainer.waitUntilContainerStarted(GenericContainer.java:531)
	at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:258)
	at org.testcontainers.containers.GenericContainer.lambda$start$0(GenericContainer.java:209)
	at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:76)
	at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:207)
	at org.testcontainers.containers.GenericContainer.starting(GenericContainer.java:638)
	at org.testcontainers.containers.FailureDetectingExternalResource$1.evaluate(FailureDetectingExternalResource.java:29)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273)
	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238)
	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159)
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:379)
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:340)
	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:125)
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:413)

2018-05-11 09:48:51.098 ERROR 5291 --- [           main] 🐳 [cassandra:3.11.1]                    : Container log output (if any) will follow:

This time, however, the failure is then followed by numerous error messages from Docker Java that look like something possibly hasn't been cleaned up properly. Each failure looks like this:

2018-05-11 09:49:16.999 ERROR 5291 --- [iners-netty-1-1] c.g.d.core.async.ResultCallbackTemplate  : Error during callback

com.github.dockerjava.api.exception.InternalServerErrorException: {"message":"Container 06484b44ae48384289006a3af3892777a76cc5c0ac62bd0570ed0d325d902c16 is not running"}

	at com.github.dockerjava.netty.handler.HttpResponseHandler.channelRead0(HttpResponseHandler.java:109)
	at com.github.dockerjava.netty.handler.HttpResponseHandler.channelRead0(HttpResponseHandler.java:33)
	at org.testcontainers.shaded.io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105)
	at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at org.testcontainers.shaded.io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:438)
	at org.testcontainers.shaded.io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:310)
	at org.testcontainers.shaded.io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:284)
	at org.testcontainers.shaded.io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:253)
	at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at org.testcontainers.shaded.io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1342)
	at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at org.testcontainers.shaded.io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:934)
	at org.testcontainers.shaded.io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:979)
	at org.testcontainers.shaded.io.netty.channel.epoll.EpollDomainSocketChannel$EpollDomainUnsafe.epollInReady(EpollDomainSocketChannel.java:138)
	at org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:404)
	at org.testcontainers.shaded.io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:307)
	at org.testcontainers.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
	at org.testcontainers.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
	at java.base/java.lang.Thread.run(Thread.java:844)

Please let me know if I can provide any more information that would help to diagnose the issue.

Beitragsleitfaden

Beitragsleitfaden öffnen

Erste Schritte

  1. Lies das ganze Issue und danach den Beitragsleitfaden des Projekts.
  2. Schreib ins Issue, dass du es übernimmst — das erspart doppelte Arbeit.
  3. Forke das Repository und arbeite in einem Branch.
  4. Öffne einen Pull Request, der die Issue-Nummer nennt.

Rechercherichtung

Beginne mit GenericContainer.start und tryStart und untersuche anschließend HostPortWaitStrategy und CassandraContainer.java, wie im Stacktrace referenziert. Reproduziere den Fehler mithilfe von CassandraDataAutoConfigurationIntegrationTests.java und verfolge, was nach jedem Timeout-Versuch zurückbleibt. Erledigt ist die Aufgabe, wenn ein fehlgeschlagener Container-Start den gemeldeten wiederholten Docker-Client-Fehler bei weiteren Versuchen nicht mehr erzeugt.

Vom Indexierungsmodell aus dem Issue-Text verfasst.

Bewertung

Tech-Stack
docker, java
Bereich
devops, testing
Issue-Typ
Bug
Schwierigkeit
4/5
Geschätzter Aufwand
3-5 Tage
Aktivitätsstatus
Veraltet
Klarheit
Muss geklärt werden
Anfängerfreundlichkeit
32/100

Neue Issues direkt in Ihr Postfach

Eine kurze Übersicht über anfängerfreundliche GitHub-Issues.