testcontainers / testcontainers/testcontainers-java

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

Aperta
#687 1 commento 0 reazioni 0 assegnatari Vedi su GitHub

Nessuno ha ancora preso questa issue.

resolution/acknowledged
Lingua principale
Java
Stelle
8.7k
Fork
1.9k
Merge medio
2g 17h
PR unite (30g)
9

Descrizione

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.

Guida per i contributori

Apri la guida per i contributori

Come iniziare

  1. Leggi tutta la issue e poi la guida ai contributi del progetto.
  2. Commenta sulla issue per dire che te ne occupi tu — evita che due persone facciano lo stesso lavoro.
  3. Fai un fork del repository e lavora su un branch.
  4. Apri una pull request che faccia riferimento al numero della issue.

Direzione di ricerca

Inizia con GenericContainer.start e tryStart, quindi ispeziona HostPortWaitStrategy e CassandraContainer.java, come indicato dallo stack trace. Riproduci il problema usando CassandraDataAutoConfigurationIntegrationTests.java e verifica cosa rimane dopo ogni tentativo scaduto. Il lavoro è completato quando l’avvio non riuscito di un container non produce più l’errore ripetuto del client Docker segnalato tra i tentativi.

Scritto dal modello di indicizzazione a partire dal testo della issue.

Valutazione

Stack tecnologico
docker, java
Ambito
devops, testing
Tipo di issue
Bug
Difficoltà
4/5
Tempo stimato
3-5 giorni
Stato di attività
Ferma
Chiarezza
Da chiarire
Idoneità per principianti
32/100

Ricevi le nuove issue nella tua casella

Un breve riepilogo di issue GitHub adatte ai principianti.