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

Postgress integration test flaky #11292

Closed
sspaink opened this issue Jun 13, 2022 · 1 comment · Fixed by #11309
Closed

Postgress integration test flaky #11292

sspaink opened this issue Jun 13, 2022 · 1 comment · Fixed by #11309
Assignees
Labels
area/postgresql bug unexpected problem or unintended behavior help wanted Request for community participation, code, contribution

Comments

@sspaink
Copy link
Contributor

sspaink commented Jun 13, 2022

Example failure: https://app.circleci.com/pipelines/github/influxdata/telegraf/11009/workflows/f1aff207-4b36-4054-bfa5-f00e3585c951/jobs/180427

Snippet:

waiting for server to shut down....2022-06-13 12:09:30.756 UTC [39] LOG:  received fast shutdown request
2022-06-13 12:09:30.771 UTC [39] LOG:  aborting any active transactions
2022-06-13 12:09:30.773 UTC [39] LOG:  background worker "logical replication launcher" (PID 46) exited with exit code 1
2022-06-13 12:09:30.773 UTC [41] LOG:  shutting down
2022-06-13 12:09:30.819 UTC [39] LOG:  database system is shut down
 done
server stopped

PostgreSQL init process complete; ready for start up.

2022-06-13 12:09:30.870 UTC [1] LOG:  starting PostgreSQL 14.3 on x86_64-pc-linux-musl, compiled by gcc (Alpine 11.2.1_git20220219) 11.2.1 20220219, 64-bit
2022-06-13 12:09:30.870 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-06-13 12:09:30.870 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2022-06-13 12:09:30.890 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-06-13 12:09:30.904 UTC [74] LOG:  database system was shut down at 2022-06-13 12:09:30 UTC
--- Container Logs End ---
--- FAIL: TestPostgresqlDatabaseBlacklistTestIntegration (2.46s)
    postgresql_test.go:295: 
        	Error Trace:	postgresql_test.go:295
        	Error:      	Received unexpected error:
        	            	failed to connect to `host=localhost user=postgres database=`: server error (FATAL: the database system is starting up (SQLSTATE 57P03))
        	Test:       	TestPostgresqlDatabaseBlacklistTestIntegration
FAIL
FAIL	github.com/influxdata/telegraf/plugins/inputs/postgresql	39.955s
@sspaink sspaink added the bug unexpected problem or unintended behavior label Jun 13, 2022
@powersj powersj self-assigned this Jun 13, 2022
@powersj
Copy link
Contributor

powersj commented Jun 13, 2022

Looking at the postgres logs, the message we are waiting for occurs twice:

2022-06-13 18:34:33.398 UTC [37] LOG:  database system is ready to accept connections
 done
server started

/usr/local/bin/docker-entrypoint.sh: ignoring /docker-entrypoint-initdb.d/*

waiting for server to shut down....2022-06-13 18:34:33.492 UTC [37] LOG:  received fast shutdown request
2022-06-13 18:34:33.492 UTC [37] LOG:  aborting any active transactions
2022-06-13 18:34:33.493 UTC [37] LOG:  background worker "logical replication launcher" (PID 44) exited with exit code 1
2022-06-13 18:34:33.493 UTC [39] LOG:  shutting down
2022-06-13 18:34:33.504 UTC [37] LOG:  database system is shut down
 done
server stopped

PostgreSQL init process complete; ready for start up.

2022-06-13 18:34:33.601 UTC [1] LOG:  starting PostgreSQL 14.3 on x86_64-pc-linux-musl, compiled by gcc (Alpine 11.2.1_git20220219) 11.2.1 20220219, 64-bit
2022-06-13 18:34:33.601 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-06-13 18:34:33.601 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2022-06-13 18:34:33.603 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-06-13 18:34:33.605 UTC [49] LOG:  database system was shut down at 2022-06-13 18:34:33 UTC
2022-06-13 18:34:33.607 UTC [1] LOG:  database system is ready to accept connections

First, the image starts up, then the docker entry point is hit, and the server is shutdown and the init process completes, and then a second time the message shows up.

next steps: 1) review the messages for a better option and/or 2) look to see if there is a configuration or setting to avoid needing to have the service come up and down on DockerHub readme

@powersj powersj added the help wanted Request for community participation, code, contribution label Jun 13, 2022
powersj added a commit to powersj/telegraf that referenced this issue Jun 15, 2022
The postgres docker image will start up and immediately shutdown the
service will the docker entrypoint starts configuration. This results in
the expected ready to accept connections log message to show up twice.
This generally happens within a tenth of a second, but in CI this can
get hit and the test will fail as the database is not yet up.

fixes: influxdata#11292
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/postgresql bug unexpected problem or unintended behavior help wanted Request for community participation, code, contribution
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants