quarkusio / quarkus

Quarkus: Supersonic Subatomic Java.
https://quarkus.io
Apache License 2.0
13.42k stars 2.58k forks source link

Dev services Testcontainer & Postgres connection refused on pipeline #31403

Open Serkan80 opened 1 year ago

Serkan80 commented 1 year ago

Describe the bug

I've a unit test where I start up a Postgres database via devservices, which work totally fine on my local machine. But when I run the same test on our (Gitlab) pipeline, it seems that it has problems connecting to localhost:5435 (which is the postgres port I defined, see also below).

I get a connection refused error.

And the strange thing is that I see that devservices starts up the Docker containers properly, see also below.

Expected behavior

No response

Actual behavior

Here is the log:

2023-02-24 15:03:09,691 INFO  [org.tes.DockerClientFactory] (build-30) βœ”οΈŽ Docker server version should be at least 1.6.0
2023-02-24 15:03:09,733 INFO  [🐳 .io/postgres:14]] (build-30) Pulling docker image: docker.io/postgres:14. Please be patient; this may take some time but only needs to be done once.
2023-02-24 15:03:09,739 INFO  [org.tes.uti.RegistryAuthLocator] (build-30) Failure when attempting to lookup auth config. Please ignore if you don't have images in an authenticated registry. Details: (dockerImageName: docker.io/postgres:latest, configFile: /root/.docker/config.json. Falling back to docker-java default behaviour. Exception message: /root/.docker/config.json (No such file or directory)
2023-02-24 15:03:10,693 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Starting to pull image
2023-02-24 15:03:10,881 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending,  0 downloaded,  0 extracted, (0 bytes/0 bytes)
2023-02-24 15:03:10,889 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers: 12 pending,  1 downloaded,  0 extracted, (48 KB/? MB)
2023-02-24 15:03:10,891 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers: 11 pending,  2 downloaded,  0 extracted, (4 MB/? MB)
2023-02-24 15:03:10,893 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers: 10 pending,  3 downloaded,  0 extracted, (6 MB/? MB)
2023-02-24 15:03:10,901 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  9 pending,  4 downloaded,  0 extracted, (15 MB/? MB)
2023-02-24 15:03:10,912 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  8 pending,  5 downloaded,  0 extracted, (15 MB/? MB)
2023-02-24 15:03:10,928 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  7 pending,  6 downloaded,  0 extracted, (15 MB/? MB)
2023-02-24 15:03:10,987 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  6 pending,  7 downloaded,  0 extracted, (18 MB/? MB)
2023-02-24 15:03:10,995 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  5 pending,  8 downloaded,  0 extracted, (25 MB/? MB)
2023-02-24 15:03:11,005 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  4 pending,  9 downloaded,  0 extracted, (25 MB/? MB)
2023-02-24 15:03:11,029 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  3 pending, 10 downloaded,  0 extracted, (25 MB/? MB)
2023-02-24 15:03:11,033 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  2 pending, 11 downloaded,  0 extracted, (25 MB/? MB)
2023-02-24 15:03:11,109 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  1 pending, 12 downloaded,  0 extracted, (40 MB/? MB)
2023-02-24 15:03:11,643 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending, 13 downloaded,  0 extracted, (115 MB/131 MB)
2023-02-24 15:03:12,173 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending, 13 downloaded,  1 extracted, (118 MB/131 MB)
2023-02-24 15:03:12,314 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending, 13 downloaded,  2 extracted, (119 MB/131 MB)
2023-02-24 15:03:12,371 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending, 13 downloaded,  3 extracted, (119 MB/131 MB)
2023-02-24 15:03:12,454 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending, 13 downloaded,  4 extracted, (119 MB/131 MB)
2023-02-24 15:03:12,697 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending, 13 downloaded,  5 extracted, (122 MB/131 MB)
2023-02-24 15:03:12,785 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending, 13 downloaded,  6 extracted, (122 MB/131 MB)
2023-02-24 15:03:12,838 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending, 13 downloaded,  7 extracted, (122 MB/131 MB)
2023-02-24 15:03:12,891 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending, 13 downloaded,  8 extracted, (122 MB/131 MB)
2023-02-24 15:03:14,715 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending, 13 downloaded,  9 extracted, (131 MB/131 MB)
2023-02-24 15:03:14,773 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending, 13 downloaded, 10 extracted, (131 MB/131 MB)
2023-02-24 15:03:14,832 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending, 13 downloaded, 11 extracted, (131 MB/131 MB)
2023-02-24 15:03:14,893 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending, 13 downloaded, 12 extracted, (131 MB/131 MB)
2023-02-24 15:03:14,950 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pulling image layers:  0 pending, 13 downloaded, 13 extracted, (131 MB/131 MB)
2023-02-24 15:03:14,963 INFO  [🐳 .io/postgres:14]] (docker-java-stream--933788147) Pull complete. 13 layers, pulled in 4s (downloaded 131 MB at 32 MB/s)
2023-02-24 15:03:14,997 INFO  [🐳 .io/postgres:14]] (build-30) Creating container for image: docker.io/postgres:14
2023-02-24 15:03:15,505 INFO  [🐳 .io/postgres:14]] (build-30) Container docker.io/postgres:14 is starting: 2b7c8a22d51413453604ffbd1cd9c510300c14c1b42a3010c537292c7629d0ea
2023-02-24 15:03:16,900 INFO  [🐳 .io/postgres:14]] (build-30) Container docker.io/postgres:14 started in PT7.203347776S
2023-02-24 15:03:16,904 INFO  [org.tes.ext.ScriptUtils] (build-30) Executing database script from init-db.sql
2023-02-24 15:03:17,247 INFO  [org.tes.ext.ScriptUtils] (build-30) Executed database script from init-db.sql in 343 ms.
2023-02-24 15:03:17,247 INFO  [io.qua.dev.pos.dep.PostgresqlDevServicesProcessor] (build-30) Dev Services for PostgreSQL started.
2023-02-24 15:03:17,249 INFO  [io.qua.dat.dep.dev.DevServicesDatasourceProcessor] (build-30) Dev Services for the default datasource (postgresql) started - container ID is 2b7c8a22d514
2023-02-24 15:03:17,252 INFO  [🐳 .io/postgres:14]] (build-30) Creating container for image: docker.io/postgres:14
2023-02-24 15:03:17,327 INFO  [🐳 .io/postgres:14]] (build-30) Container docker.io/postgres:14 is starting: bd3ed0153eb958a06641a271cbe8738f078bc635c8f8d1d94d31a2e3061280db
2023-02-24 15:03:18,727 INFO  [🐳 .io/postgres:14]] (build-30) Container docker.io/postgres:14 started in PT1.475494285S
2023-02-24 15:03:18,727 INFO  [org.tes.ext.ScriptUtils] (build-30) Executing database script from init-db.sql
2023-02-24 15:03:18,805 INFO  [org.tes.ext.ScriptUtils] (build-30) Executed database script from init-db.sql in 77 ms.
2023-02-24 15:03:18,806 INFO  [io.qua.dev.pos.dep.PostgresqlDevServicesProcessor] (build-30) Dev Services for PostgreSQL started.
2023-02-24 15:03:18,806 INFO  [io.qua.dat.dep.dev.DevServicesDatasourceProcessor] (build-30) Dev Services for  datasource 'lei-in-hr' (postgresql) started - container ID is bd3ed0153eb9
2023-02-24 15:03:18,810 INFO  [io.qua.hib.orm.dep.HibernateOrmProcessor] (build-43) Setting quarkus.hibernate-orm.database.generation=drop-and-create to initialize Dev Services managed database
2023-02-24 15:03:19,493 INFO  [org.ecl.jet.uti.log] (pool-3-thread-1) Logging initialized @18450ms to org.eclipse.jetty.util.log.Slf4jLog
2023-02-24 15:03:19,594 INFO  [org.ecl.jet.ser.Server] (pool-3-thread-1) jetty-9.4.48.v20220622; built: 2022-06-21T20:42:25.880Z; git: 6b67c5719d1f4371b33655ff2d047d24e171e49a; jvm 17.0.5+8
2023-02-24 15:03:19,609 INFO  [org.ecl.jet.ser.han.ContextHandler] (pool-3-thread-1) Started o.e.j.s.ServletContextHandler@7c469f0c{/__admin,null,AVAILABLE}
2023-02-24 15:03:19,616 INFO  [org.ecl.jet.ser.han.Con.ROOT] (pool-3-thread-1) RequestHandlerClass from context returned com.github.tomakehurst.wiremock.http.StubRequestHandler. Normalized mapped under returned 'null'
2023-02-24 15:03:19,616 INFO  [org.ecl.jet.ser.han.ContextHandler] (pool-3-thread-1) Started o.e.j.s.ServletContextHandler@2d81fbfa{/,null,AVAILABLE}
2023-02-24 15:03:19,627 INFO  [org.ecl.jet.ser.AbstractConnector] (pool-3-thread-1) Started NetworkTrafficServerConnector@4f8eb79a{HTTP/1.1, (http/1.1, h2c)}{0.0.0.0:8080}
2023-02-24 15:03:19,628 INFO  [org.ecl.jet.ser.Server] (pool-3-thread-1) Started @18585ms
2023-02-24 15:03:20,459 INFO  (main) Initializing Debezium Embedded Engines...
2023-02-24 15:03:20,460 INFO  (main) Debezium Embedded Engine for 'MyEngine-2' disabled, skipping...
2023-02-24 15:03:20,512 WARN  [org.apa.kaf.con.run.WorkerConfig] (main) Variables cannot be used in the 'plugin.path' property, since the property is used by plugin scanning before the config providers that replace the variables are initialized. The raw value 'null' was used for plugin scanning, as opposed to the transformed value 'null', and this may cause unexpected results.
2023-02-24 15:03:20,532 INFO  (main) Debezium Embedded Engine for 'My-Engine-1' started...
2023-02-24 15:03:20,642 ERROR [io.deb.con.pos.PostgresConnector] (executor-thread-0) Failed testing connection for jdbc:postgresql://localhost:5435/quarkus with user 'quarkus': org.postgresql.util.PSQLException: Connection to localhost:5435 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.

Caused by: java.net.ConnectException: Connection refused
# DEV SERVICES
quarkus.datasource.db-kind=postgresql
quarkus.datasource.devservices.port=5435
quarkus.datasource.devservices.command=postgres -c wal_level=logical
quarkus.datasource.devservices.init-script-path=init-db.sql

# DEBEZIUM
debezium.database.hostname=localhost
debezium.database.port=5435
debezium.database.dbname=quarkus
debezium.database.user=quarkus
debezium.database.password=quarkus

I've also tried the following config, but that didn't help either:

debezium.database.hostname=0.0.0.0

And this is the output of docker ps in the pipeline right after when the unit test fails:

CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES bd3ed0153eb9 postgres:14 "docker-entrypoint.s…" 15 seconds ago Up 15 seconds 0.0.0.0:5436->5432/tcp nervous_booth 2b7c8a22d514 postgres:14 "docker-entrypoint.s…" 17 seconds ago Up 17 seconds 0.0.0.0:5435->5432/tcp sad_herschel

How to Reproduce?

No response

Output of uname -a or ver

Windows

Output of java -version

JDK 17 Temurin

GraalVM version (if different from Java)

No response

Quarkus version or git rev

2.16.3.Final

Build tool (ie. output of mvnw --version or gradlew --version)

Maven 3.8.x

Additional information

No response

quarkus-bot[bot] commented 1 year ago

/cc @geoand (devservices), @stuartwdouglas (devservices)

Siedlerchr commented 1 year ago

I encountered the same recently with the Keycloack-testcontainer on an azure devops pipeline

Serkan80 commented 1 year ago

I ended up with disabling dev services for datasources, and started up my databases with Testcontainers manually and plumped everything together. Now it is working.

I'm completley lost why plain Testcontainer just works and dev services, which I assume also uses Testcontainers under the hood, doesn't work.

stuartwdouglas commented 1 year ago

Can you remove some of the custom config and see if that makes a difference? I.e. try without the 'port' and 'command' config and see if either of those is causing the issue.

Serkan80 commented 1 year ago

I think the issue is with podman 3.x. When I upgraded to podman 4.x the problem was solved.

Podman 3.x requires root rights so that your ports are accessible when the container has started up. In podman 4.x they fixed this issue.

holly-cummins commented 1 year ago

Should we document that we require Podman 4.x and then close this?

geoand commented 1 year ago

πŸ‘Œ