testcontainers / testcontainers/testcontainers-java

[Bug]: PostgreSQL startup times out of logs can't be tailed

Open
#5,670 3 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

type/bug
Dominant language
Java
Stars
8.7k
Forks
1.9k
Avg merge
2d 17h
Merged PRs (30d)
9

Description

Module

PostgreSQL

Testcontainers version

1.17.3

Using the latest Testcontainers version?

Yes

Host OS

Linux

Host Arch

x86_64

Docker version
Docker version 20.10.16, build aa7e414
What happened?

I am trying to run our testsuite in a loop to catch a race condition. However I see that in about 1 out of 10 cases the test fails due to timing out when waiting for the PostgreSQL container to start up. The logs suggest that the line it is waiting for is actually printed as expected; checking the code I suspect that the OutputFrame does not contain the full line and therefore the expression does not match. Is this possible?

Relevant log output
2022-08-02 13:26:09,614 ERROR [🐳 [postgres:12]] (pool-146-thread-1) Could not start container: org.testcontainers.containers.ContainerLaunchException: Timed out waiting for log output matching '.*database system is ready to accept connections.*\s'
	at org.testcontainers.containers.wait.strategy.LogMessageWaitStrategy.waitUntilReady(LogMessageWaitStrategy.java:49)
	at org.testcontainers.containers.wait.strategy.AbstractWaitStrategy.waitUntilReady(AbstractWaitStrategy.java:51)
	at org.testcontainers.containers.PostgreSQLContainer.waitUntilContainerStarted(PostgreSQLContainer.java:139)
	at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:480)
	at org.testcontainers.containers.GenericContainer.lambda$doStart$0(GenericContainer.java:340)
	at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:81)
	at org.testcontainers.containers.GenericContainer.doStart(GenericContainer.java:338)
	at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:326)
	at io.hyperfoil.tools.horreum.test.PostgresResource.start(PostgresResource.java:18)
	at io.quarkus.test.common.TestResourceManager$TestResourceEntryRunnable.run(TestResourceManager.java:452)
	at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1736)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)

2022-08-02 13:26:09,674 ERROR [🐳 [postgres:12]] (pool-146-thread-1) Log output from the failed container:
The files belonging to this database system will be owned by user "postgres".
This user must also own the server process.
The database cluster will be initialized with locale "en_US.utf8".
The default database encoding has accordingly been set to "UTF8".
The default text search configuration will be set to "english".
Data page checksums are disabled.
fixing permissions on existing directory /var/lib/postgresql/data ... ok
creating subdirectories ... ok
selecting dynamic shared memory implementation ... posix
selecting default max_connections ... 100
selecting default shared_buffers ... 128MB
selecting default time zone ... Etc/UTC
creating configuration files ... ok
running bootstrap script ... ok
performing post-bootstrap initialization ... ok
syncing data to disk ... ok
initdb: warning: enabling "trust" authentication for local connections
You can change this by editing pg_hba.conf or using the option -A, or
--auth-local and --auth-host, the next time you run initdb.
Success. You can now start the database server using:
    pg_ctl -D /var/lib/postgresql/data -l logfile start
waiting for server to start....2022-08-02 11:25:10.351 UTC [47] LOG:  starting PostgreSQL 12.8 (Debian 12.8-1.pgdg100+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6) 8.3.0, 64-bit
2022-08-02 11:25:10.351 UTC [47] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-08-02 11:25:10.360 UTC [48] LOG:  database system was shut down at 2022-08-02 11:25:10 UTC
2022-08-02 11:25:10.367 UTC [47] LOG:  database system is ready to accept connections
 done
server started
CREATE DATABASE
/usr/local/bin/docker-entrypoint.sh: ignoring /docker-entrypoint-initdb.d/*
2022-08-02 11:25:10.571 UTC [47] LOG:  received fast shutdown request
2022-08-02 11:25:10.571 UTC [47] LOG:  aborting any active transactions
waiting for server to shut down....2022-08-02 11:25:10.572 UTC [47] LOG:  background worker "logical replication launcher" (PID 54) exited with exit code 1
2022-08-02 11:25:10.572 UTC [49] LOG:  shutting down
2022-08-02 11:25:10.576 UTC [47] LOG:  database system is shut down
 done
server stopped
PostgreSQL init process complete; ready for start up.
2022-08-02 11:25:10.683 UTC [1] LOG:  starting PostgreSQL 12.8 (Debian 12.8-1.pgdg100+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.3.0-6) 8.3.0, 64-bit
2022-08-02 11:25:10.683 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-08-02 11:25:10.684 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2022-08-02 11:25:10.684 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-08-02 11:25:10.693 UTC [75] LOG:  database system was shut down at 2022-08-02 11:25:10 UTC
2022-08-02 11:25:10.697 UTC [1] LOG:  database system is ready to accept connections
Additional Information

No response

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start by reading LogMessageWaitStrategy.java, AbstractWaitStrategy.java, and the OutputFrame handling involved in GenericContainer startup. Reproduce the PostgreSQL startup loop and determine whether readiness output can be split across frames; done means the readiness wait reliably matches the logged line and the relevant test or reproduction no longer times out.

Written by the indexing model from the issue text.

Assessment

Tech stack
docker, java, postgresql
Domain
databases, devops, testing-qa
Issue type
Bug
Difficulty
3/5
Estimated time
1-2 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.