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

Spring Boot 3.4-M3: application container does not start when TestContainer beans depend on each other #42607

Closed
nilshartmann opened this issue Oct 13, 2024 · 3 comments
Labels
status: duplicate A duplicate of another issue

Comments

@nilshartmann
Copy link
Contributor

After upgrading a Spring Boot 3.3.4 project to Spring Boot 3.4-M3 i encountered a changed behaviour when defining two TestContainer beans that depend on each other and using a third (ServletFilter) Bean that (indirectly) consumes the application's DataSource.

Reproducible setup

  • I'm creating two testcontainer Container beans in my @TestConfiguration class. One of them providing the ServiceConnection for my DataSource.
  • One has the @DependsOn annotation to mark a dependency on the other container:
@TestConfiguration(proxyBeanMethods = false)
class TestcontainersConfiguration {
  @Bean
  @ServiceConnection
  PostgreSQLContainer<?> postgresContainer() { /* ... */ }

  @Bean
  @DependsOn("postgresContainer")
  GenericContainer<?> nginxContainer() { /* ... */ }
}
  • Also I have an own @Bean method that registeres a ServletFilter-Bean. The methods expects a JdbcClient as parameter
  • Note that the JdbcClient is not really used here (as opposed to my real application), but it's enough just to add it here as a method param to make the application start failing
@Configuration
public class MyFilterConfig {

    // using jdbcClient here makes this application in Spring Boot 3.4 fail
    @Bean
    public MyFilter filterOne(JdbcClient jdbcClient) {
        // MyFilter is a OncePerRequestFilter subclass with no other dependecies
        return new MyFilter();
    }
}

Changed Behaviour

  • Running this test in Spring Boot 3.3 the application container starts
  • Running the same test with the same code, but in Spring Boot 3.4-M3, the application container fails to start with this error:
Caused by: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'filterOne' defined in class path resource [org/example/testcontainerexample/MyFilterConfig.class]: Unsatisfied dependency expressed through method 'filterOne' parameter 0: Error creating bean with name 'dataSourceScriptDatabaseInitializer' defined in class path resource [org/springframework/boot/autoconfigure/sql/init/DataSourceInitializationConfiguration.class]: Unsatisfied dependency expressed through method 'dataSourceScriptDatabaseInitializer' parameter 0: Error creating bean with name 'dataSource' defined in class path resource [org/springframework/boot/autoconfigure/jdbc/DataSourceConfiguration$Hikari.class]: Failed to instantiate [com.zaxxer.hikari.HikariDataSource]: Factory method 'dataSource' threw exception with message: Mapped port can only be obtained after the container is started
	at org.springframework.beans.factory.support.ConstructorResolver.createArgumentArray(ConstructorResolver.java:804)
	at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:546)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1351)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1181)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:563)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:523)
	at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:336)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:288)
	at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:334)
	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:204)
	at org.springframework.boot.web.servlet.ServletContextInitializerBeans.getOrderedBeansOfType(ServletContextInitializerBeans.java:211)
	at org.springframework.boot.web.servlet.ServletContextInitializerBeans.addAsRegistrationBean(ServletContextInitializerBeans.java:174)
	at org.springframework.boot.web.servlet.ServletContextInitializerBeans.addAsRegistrationBean(ServletContextInitializerBeans.java:169)
	at org.springframework.boot.web.servlet.ServletContextInitializerBeans.addAdaptableBeans(ServletContextInitializerBeans.java:154)
	at org.springframework.boot.web.servlet.ServletContextInitializerBeans.<init>(ServletContextInitializerBeans.java:87)
	at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.getServletContextInitializerBeans(ServletWebServerApplicationContext.java:266)
	at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.selfInitialize(ServletWebServerApplicationContext.java:240)
	at org.springframework.boot.web.embedded.tomcat.TomcatStarter.onStartup(TomcatStarter.java:52)
	at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:4412)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:164)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1203)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1193)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
	at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
	at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:145)
	at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:749)
	at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:772)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:164)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1203)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1193)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
	at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
	at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:145)
	at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:749)
	at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:203)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:164)
	at org.apache.catalina.core.StandardService.startInternal(StandardService.java:415)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:164)
	at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:870)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:164)
	at org.apache.catalina.startup.Tomcat.start(Tomcat.java:437)
	at org.springframework.boot.web.embedded.tomcat.TomcatWebServer.initialize(TomcatWebServer.java:128)
	... 38 more

I have created a repository with two versions of the same application for Spring Boot 3.3 and 3.4. The only difference is the pom.xml-file: https://github.com/nilshartmann/testcontainer-example

You can see the problem when running the TestcontainerExampleApplicationTests in both 3_3 and 3_4 subfolders.

If you either remove the @DependsOn annotation or remove the JdbcClient from the filterOne method the application starts (unfortunately in my real application I cannot remove one of this two...).

Thanks for any help!

@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged label Oct 13, 2024
@wilkinsona
Copy link
Member

Thanks for the sample. I can reproduce the problem with 3.4.0-M3 but not with 3.4.0-SNAPSHOT. I suspect that's due to some of the changes that were made in #41996 where the container lifecycle management was simplified.

For reference, here's the log with 3.4.0-SNAPSHOT when the test starts the app successfully:

[INFO] Running org.example.testcontainerexample.TestcontainerExampleApplicationTests
07:54:30.869 [main] INFO org.springframework.test.context.support.AnnotationConfigContextLoaderUtils -- Could not detect default configuration classes for test class [org.example.testcontainerexample.TestcontainerExampleApplicationTests]: TestcontainerExampleApplicationTests does not declare any static, non-private, non-final, nested classes annotated with @Configuration.
07:54:31.021 [main] INFO org.springframework.boot.test.context.SpringBootTestContextBootstrapper -- Found @SpringBootConfiguration org.example.testcontainerexample.Application for test class org.example.testcontainerexample.TestcontainerExampleApplicationTests

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/

 :: Spring Boot ::       (v3.4.0-SNAPSHOT)

2024-10-14T07:54:31.398+01:00  INFO 86168 --- [3_4] [           main] e.t.TestcontainerExampleApplicationTests : Starting TestcontainerExampleApplicationTests using Java 21.0.2 with PID 86168 (started by awilkinson in /Users/awilkinson/dev/temp/testcontainer-example/3_4)
2024-10-14T07:54:31.399+01:00  INFO 86168 --- [3_4] [           main] e.t.TestcontainerExampleApplicationTests : No active profile set, falling back to 1 default profile: "default"
2024-10-14T07:54:31.959+01:00  INFO 86168 --- [3_4] [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2024-10-14T07:54:31.983+01:00  INFO 86168 --- [3_4] [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 13 ms. Found 0 JPA repository interfaces.
2024-10-14T07:54:32.486+01:00  INFO 86168 --- [3_4] [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port 0 (http)
2024-10-14T07:54:32.501+01:00  INFO 86168 --- [3_4] [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2024-10-14T07:54:32.501+01:00  INFO 86168 --- [3_4] [           main] o.apache.catalina.core.StandardEngine    : Starting Servlet engine: [Apache Tomcat/10.1.30]
2024-10-14T07:54:32.560+01:00  INFO 86168 --- [3_4] [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2024-10-14T07:54:32.561+01:00  INFO 86168 --- [3_4] [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1148 ms
2024-10-14T07:54:32.622+01:00  INFO 86168 --- [3_4] [           main] org.testcontainers.images.PullPolicy     : Image pull policy will be performed by: DefaultPullPolicy()
2024-10-14T07:54:32.625+01:00  INFO 86168 --- [3_4] [           main] o.t.utility.ImageNameSubstitutor         : Image name substitution will be performed by: DefaultImageNameSubstitutor (composite of 'ConfigurationFileImageNameSubstitutor' and 'PrefixingImageNameSubstitutor')
2024-10-14T07:54:32.669+01:00  INFO 86168 --- [3_4] [           main] org.testcontainers.DockerClientFactory   : Testcontainers version: 1.20.1
2024-10-14T07:54:32.883+01:00  INFO 86168 --- [3_4] [           main] o.t.d.DockerClientProviderStrategy       : Loaded org.testcontainers.dockerclient.UnixSocketClientProviderStrategy from ~/.testcontainers.properties, will try it first
2024-10-14T07:54:32.932+01:00  WARN 86168 --- [3_4] [           main] o.t.d.DockerClientProviderStrategy       : DOCKER_HOST tcp://127.0.0.1:53248 is not listening
2024-10-14T07:54:33.183+01:00  INFO 86168 --- [3_4] [           main] o.t.d.DockerClientProviderStrategy       : Found Docker environment with local Unix socket (unix:///var/run/docker.sock)
2024-10-14T07:54:33.184+01:00  INFO 86168 --- [3_4] [           main] org.testcontainers.DockerClientFactory   : Docker host IP address is localhost
2024-10-14T07:54:33.204+01:00  INFO 86168 --- [3_4] [           main] org.testcontainers.DockerClientFactory   : Connected to docker: 
  Server Version: 20.10.24
  API Version: 1.41
  Operating System: Docker Desktop
  Total Memory: 7959 MB
2024-10-14T07:54:33.334+01:00  INFO 86168 --- [3_4] [           main] tc.testcontainers/ryuk:0.8.1             : Creating container for image: testcontainers/ryuk:0.8.1
2024-10-14T07:54:33.975+01:00  INFO 86168 --- [3_4] [           main] tc.testcontainers/ryuk:0.8.1             : Container testcontainers/ryuk:0.8.1 is starting: bc7aaa894ce2099b30363aa25a6e4c80c782016184de2aa0cf60b0be1231a6b5
2024-10-14T07:54:34.549+01:00  INFO 86168 --- [3_4] [           main] tc.testcontainers/ryuk:0.8.1             : Container testcontainers/ryuk:0.8.1 started in PT1.215459S
2024-10-14T07:54:34.555+01:00  INFO 86168 --- [3_4] [           main] o.t.utility.RyukResourceReaper           : Ryuk started - will monitor and terminate Testcontainers containers on JVM exit
2024-10-14T07:54:34.555+01:00  INFO 86168 --- [3_4] [           main] org.testcontainers.DockerClientFactory   : Checking the system...
2024-10-14T07:54:34.555+01:00  INFO 86168 --- [3_4] [           main] org.testcontainers.DockerClientFactory   : ✔︎ Docker server version should be at least 1.6.0
2024-10-14T07:54:34.556+01:00  INFO 86168 --- [3_4] [           main] tc.postgres:16.1-alpine                  : Creating container for image: postgres:16.1-alpine
2024-10-14T07:54:34.607+01:00  INFO 86168 --- [3_4] [           main] tc.postgres:16.1-alpine                  : Container postgres:16.1-alpine is starting: 44ece9b6beef3537fc0ce3599f735f0d466cd8eed40a53834e94fffc1bd1088b
2024-10-14T07:54:36.649+01:00  INFO 86168 --- [3_4] [           main] tc.postgres:16.1-alpine                  : Container postgres:16.1-alpine started in PT2.093555S
2024-10-14T07:54:36.650+01:00  INFO 86168 --- [3_4] [           main] tc.postgres:16.1-alpine                  : Container is started (JDBC URL: jdbc:postgresql://localhost:65434/test?loggerLevel=OFF)
2024-10-14T07:54:36.705+01:00  INFO 86168 --- [3_4] [           main] o.example.testcontainerexample.MyFilter  : MyFilter CREATED
2024-10-14T07:54:36.786+01:00  INFO 86168 --- [3_4] [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2024-10-14T07:54:36.984+01:00  INFO 86168 --- [3_4] [           main] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Added connection org.postgresql.jdbc.PgConnection@5ae66c98
2024-10-14T07:54:36.985+01:00  INFO 86168 --- [3_4] [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2024-10-14T07:54:37.050+01:00  INFO 86168 --- [3_4] [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2024-10-14T07:54:37.115+01:00  INFO 86168 --- [3_4] [           main] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 6.6.1.Final
2024-10-14T07:54:37.148+01:00  INFO 86168 --- [3_4] [           main] o.h.c.internal.RegionFactoryInitiator    : HHH000026: Second-level cache disabled
2024-10-14T07:54:37.432+01:00  INFO 86168 --- [3_4] [           main] o.s.o.j.p.SpringPersistenceUnitInfo      : No LoadTimeWeaver setup: ignoring JPA class transformer
2024-10-14T07:54:37.511+01:00  INFO 86168 --- [3_4] [           main] org.hibernate.orm.connections.pooling    : HHH10001005: Database info:
	Database JDBC URL [Connecting through datasource 'HikariDataSource (HikariPool-1)']
	Database driver: undefined/unknown
	Database version: 16.1
	Autocommit mode: undefined/unknown
	Isolation level: undefined/unknown
	Minimum pool size: undefined/unknown
	Maximum pool size: undefined/unknown
2024-10-14T07:54:37.798+01:00  INFO 86168 --- [3_4] [           main] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000489: No JTA platform available (set 'hibernate.transaction.jta.platform' to enable JTA platform integration)
2024-10-14T07:54:37.803+01:00  INFO 86168 --- [3_4] [           main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2024-10-14T07:54:37.808+01:00  INFO 86168 --- [3_4] [           main] tc.nginx:1.27.2-alpine                   : Creating container for image: nginx:1.27.2-alpine
2024-10-14T07:54:37.882+01:00  INFO 86168 --- [3_4] [           main] tc.nginx:1.27.2-alpine                   : Container nginx:1.27.2-alpine is starting: 1490bf03187d1488e63287e48afa82042aef5a41b69378e31796e61c84f1c198
2024-10-14T07:54:38.362+01:00  INFO 86168 --- [3_4] [           main] tc.nginx:1.27.2-alpine                   : Container nginx:1.27.2-alpine started in PT0.553572S
2024-10-14T07:54:38.409+01:00  WARN 86168 --- [3_4] [           main] JpaBaseConfiguration$JpaWebConfiguration : spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning
2024-10-14T07:54:38.793+01:00  INFO 86168 --- [3_4] [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port 65445 (http) with context path '/'
2024-10-14T07:54:38.801+01:00  INFO 86168 --- [3_4] [           main] e.t.TestcontainerExampleApplicationTests : Started TestcontainerExampleApplicationTests in 7.648 seconds (process running for 8.854)

Please given 3.4.0-SNAPSHOT (available from https://repo.spring.io/snapshot) a try and let us know if it works in your actual application as well as the sample.

@wilkinsona wilkinsona added the status: waiting-for-feedback We need additional information before we can continue label Oct 14, 2024
@nilshartmann
Copy link
Contributor Author

Hi @wilkinsona ,

thanks for getting back so quickly! Indeed my test works with 3.4.0-SNAPSHOT 🥳.

Anyway, may I ask you a question if this (dummy) code is the correct way to got when setting up containers with dependencies and also using dynamic properties from the containers for the application context? I found a lot of different ways, but that one would look like the most "spring-ish" way to me:

@TestConfiguration
public class MyContainerConfig {

    @Bean
    Network dockerNetwork() {
        return Network.newNetwork();
    }

    @Bean
    @ServiceConnection
    @Primary
    PostgreSQLContainer<?> postgresContainer(Network network) {
        return new PostgreSQLContainer<>(DockerImageName.parse("postgres:16-alpine"))
            // ... more options ...
            ;
    }

    @Bean
    @DependsOn({"postgresContainer"})
    KeycloakContainer keycloakContainer(Network network) {
        return new KeycloakContainer()
            // ... more options ...
            ;
    }

    @Bean
    DynamicPropertyRegistrar keycloakPropertiesRegistrar(KeycloakContainer container) {
        return registry -> {
            // add dynamic keycloak properties to application context
            registry.add("my.keycloak-admin.url", container::getAuthServerUrl);
            
            // ... more properties ...
        };
    }
}

@spring-projects-issues spring-projects-issues added status: feedback-provided Feedback has been provided and removed status: waiting-for-feedback We need additional information before we can continue labels Oct 14, 2024
@wilkinsona
Copy link
Member

Yes, as of 3.4 (only in 3.4.0-SNAPSHOT at the moment), that's the preferred way to do it. Specifically, when containers are defined as beans, using a DynamicPropertyRegistrar bean that injects any containers that will provide property values is the right way to go as it eliminates some possible lifecycle problems. If you haven't already seen it, there some info about this in the release notes.

Thanks very much for trying out the snapshot and letting us know things are working again. I'll close this one as a duplicate of #41996.

@wilkinsona wilkinsona closed this as not planned Won't fix, can't repro, duplicate, stale Oct 14, 2024
@wilkinsona wilkinsona added status: duplicate A duplicate of another issue and removed status: waiting-for-triage An issue we've not yet triaged status: feedback-provided Feedback has been provided labels Oct 14, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
status: duplicate A duplicate of another issue
Projects
None yet
Development

No branches or pull requests

3 participants