testcontainers / testcontainers/testcontainers-java

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

Abierto
#687 1 comentario 0 reacciones 0 asignados Ver en GitHub

Nadie ha tomado este issue todavía.

resolution/acknowledged
Lenguaje dominante
Java
Estrellas
8.7k
Forks
1.9k
Merge medio
2 d 17 h
PR fusionados (30 d)
9

Descripción

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.

Guía de contribución

Abrir la guía de contribución

Primeros pasos

  1. Lee el issue completo y luego la guía de contribución del proyecto.
  2. Comenta en el issue que vas a ocuparte — evita que dos personas hagan lo mismo.
  3. Haz un fork del repositorio y trabaja en una rama.
  4. Abre un pull request que haga referencia al número del issue.

Línea de trabajo

Comienza con GenericContainer.start y tryStart; después, inspecciona HostPortWaitStrategy y CassandraContainer.java, tal como se hace referencia a ellos en el stack trace. Reproduce el fallo usando CassandraDataAutoConfigurationIntegrationTests.java y rastrea qué queda después de cada intento agotado por tiempo. Se considera completado cuando el inicio fallido de un contenedor ya no produce el error repetido del cliente de Docker reportado entre reintentos.

Escrito por el modelo de indexación a partir del texto del issue.

Evaluación

Stack tecnológico
docker, java
Área
devops, testing
Tipo de issue
Error
Dificultad
4/5
Tiempo estimado
3-5 días
Estado de actividad
Estancado
Claridad
Necesita aclaración
Aptitud para principiantes
32/100

Recibe los nuevos issues en tu correo

Un resumen breve de issues de GitHub para principiantes.