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

OpenTelemetryMetricsContainerConnectionDetailsFactoryIntegrationTests fails locally with container start error #38176

Closed
philwebb opened this issue Nov 2, 2023 · 4 comments
Labels
type: task A general task
Milestone

Comments

@philwebb
Copy link
Member

philwebb commented Nov 2, 2023


java.lang.IllegalStateException: Mapped port can only be obtained after the container is started
	at org.testcontainers.shaded.com.google.common.base.Preconditions.checkState(Preconditions.java:512)
	at org.testcontainers.containers.ContainerState.getMappedPort(ContainerState.java:161)
	at org.springframework.boot.testcontainers.service.connection.otlp.OpenTelemetryMetricsContainerConnectionDetailsFactory$OpenTelemetryMetricsContainerConnectionDetails.getUrl(OpenTelemetryMetricsContainerConnectionDetailsFactory.java:58)
	at org.springframework.boot.actuate.autoconfigure.metrics.export.otlp.OtlpPropertiesConfigAdapter.lambda$0(OtlpPropertiesConfigAdapter.java:67)
	at org.springframework.boot.actuate.autoconfigure.metrics.export.properties.PropertiesConfigAdapter.get(PropertiesConfigAdapter.java:53)
	at org.springframework.boot.actuate.autoconfigure.metrics.export.otlp.OtlpPropertiesConfigAdapter.url(OtlpPropertiesConfigAdapter.java:67)
	at io.micrometer.registry.otlp.OtlpMeterRegistry.publish(OtlpMeterRegistry.java:161)
	at io.micrometer.core.instrument.push.PushMeterRegistry.publishSafely(PushMeterRegistry.java:67)
	at io.micrometer.core.instrument.push.PushMeterRegistry.close(PushMeterRegistry.java:135)
	at io.micrometer.registry.otlp.OtlpMeterRegistry.close(OtlpMeterRegistry.java:260)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at org.springframework.beans.factory.support.DisposableBeanAdapter.invokeCustomDestroyMethod(DisposableBeanAdapter.java:316)
	at org.springframework.beans.factory.support.DisposableBeanAdapter.destroy(DisposableBeanAdapter.java:249)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroyBean(DefaultSingletonBeanRegistry.java:587)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingleton(DefaultSingletonBeanRegistry.java:559)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingleton(DefaultListableBeanFactory.java:1200)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingletons(DefaultSingletonBeanRegistry.java:520)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingletons(DefaultListableBeanFactory.java:1193)
	at org.springframework.context.support.AbstractApplicationContext.destroyBeans(AbstractApplicationContext.java:1125)
	at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:1086)
	at org.springframework.context.support.AbstractApplicationContext$1.run(AbstractApplicationContext.java:1019)
@philwebb
Copy link
Member Author

philwebb commented Nov 2, 2023

Possibly related to the testcontainers startup changes.

@philwebb philwebb added the type: task A general task label Nov 2, 2023
@philwebb philwebb added this to the 3.2.x milestone Nov 2, 2023
@philwebb
Copy link
Member Author

philwebb commented Nov 2, 2023

The failure doesn't always make the test fail because OtlpMeterRegistry logs it as a warning. The container in question is otel/opentelemetry-collector-contrib:0.75.0. Here's a build that failed and here is the test history

@philwebb
Copy link
Member Author

philwebb commented Nov 2, 2023

The problem seems to be caused because of a lifecycle mismatch. The container is managed by the @Testcontainers annotation and is closed when the test ends. The ApplicationContext is managed by Spring and because of context caching remains open until the shutdown hook is is run.

@xak2000
Copy link
Contributor

xak2000 commented Jan 30, 2024

@philwebb You mentioned some changes in #38176 (comment). Can you clarify please what changes exactly you had in mind? I can't find any changes to shutdown lifecycle in the changelog. Is it possible to return the old behavior with some configuration property maybe?

I have related problem in a project. With Spring Boot 3.1.6 tests worked fine, but now with Spring Boot 3.2.2, TestContainers are shutting down in parallel with Spring Application Context, that makes e.g. all DB connections in the HikariPool invalid.

E.g. Spring Integration executes DefaultLockRepository.close() method on shutdown. This method executes an SQL query, so it expects a connection in the pool to be available. Previously it was working. Now it is not.

Part of the log:

18:50:37.650 DEBUG [Thread-23] o.t.s.c.g.d.core.command.AbstrDockerCmd  : Cmd: f94f01e87a0b6b1b237df68cccb625131e7acab3270818edc6b93becf0365ad0,SIGTERM
...
18:50:37.655  INFO [SpringApplicationShutdownHook] o.s.i.endpoint.EventDrivenConsumer       : stopped bean '_org.springframework.integration.errorLogger'
18:50:38.672 DEBUG [SpringApplicationShutdownHook] o.s.jdbc.support.JdbcTransactionManager  : Creating new transaction with name [null]: PROPAGATION_REQUIRES_NEW,ISOLATION_DEFAULT
18:50:38.673  WARN [SpringApplicationShutdownHook] com.zaxxer.hikari.pool.PoolBase          : HikariPool-1 - Failed to validate connection org.testcontainers.jdbc.ConnectionWrapper@78c91d2a (No operations allowed after connection closed.). Possibly consider using a shorter maxLifetime value.
...
18:50:38.709  INFO [HikariPool-1 connection adder] tc.mysql:5.7                             : Creating container for image: mysql:5.7
...
18:50:38.780 ERROR [HikariPool-1 connection adder] tc.mysql:5.7                             : Could not start container

java.lang.IllegalStateException: Shutdown in progress
	at java.base/java.lang.ApplicationShutdownHooks.add(ApplicationShutdownHooks.java:66)
...
18:51:08.783  WARN [SpringApplicationShutdownHook] o.s.b.f.support.DisposableBeanAdapter    : Invocation of close method failed on bean with name 'lockRepository': org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction
18:51:08.786  INFO [SpringApplicationShutdownHook] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
18:51:08.983  INFO [SpringApplicationShutdownHook] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.

As you can see the container is already shutting down, so the Hiraki can't provide the connection. Moreover, it tries to create a new one (TestContainers JDBC URL Scheme is used to create the container), that also failed, but even if it was not, there is no sense in this operation as an empty DB (that missing the Liquibase migrations) will not help anyway.

I want to find a solution that doesn't involve @DirtiesContext. Otherwise I will be forced to mark each and every method with @DirtiesContext that will make all tests to be running forever. The Liquibase migrations alone are running 10 seconds on an empty DB.

Basically, the ordering of shutdown of Spring Application Context and TestContainers should be guaranteed. TestContainers should always shut down last.

I'm not sure where (in what project) I should create the issue. I'm not even sure what changes exactly affect this behavior. Maybe it's some changes in TestContainers itself that is 1.19.3 now.

Edit
Can it be caused by testcontainers/testcontainers-java#7717?
If previously ryuk was stopped only after 10 sec after shutdown, and now it is stopping right on shutdown, this could probably be the reason. Previously Spring Context Shutdown hooks were able to execute during this 10 sec.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type: task A general task
Projects
None yet
Development

No branches or pull requests

2 participants