Sporadic failures/hangs using pgtemp across many tests

[hoxxep]

I am using pgtemp across many unit tests and I'm a big fan. I am also using cargo nextest, spinning up many of these in parallel. I occasionally run into two issues which I believe may be related to each other and to issue #9

1. Database still starting error: This is the following diesel error that I occasionally get from tests, where pgtemp believes it's initialised slightly sooner than it really has.

   PoolError(Backend(ConnectionError(CouldntSetupConfiguration(DatabaseError(Unknown, "the database system is starting up")))))

2. Database hangs on shutdown: I also occasionally experience 60s hangs at the end of tests while dropping tempdb, potentially the same as issue Shutdown (without persist) hangs in Github actions #9.

These happen locally and on Github CI, and infrequently enough that it's hard to figure out why. I am using postgres 14 and initialising via let _tempdb = pgtemp::PgTempDBBuilder::new().start_async().await, relying on the _tempdb variable to be dropped at the end of the test to shut down the temporary postgres instance.

My working hypothesis is that either pgtemp or postgres has a race condition when starting up multiple databases at the same time, perhaps picking up the wrong process ID or file somewhere? However, I can't artificially reproduce it with the test attached below. I'll add more information if some extra traces I've collected help.

The hang often happens to the same test (on 1 in every 10 test runs), and occasionally happens to other tests that start around the same time (on 1 in every 100 test runs). It's definitely the dropping of pgtemp that's hanging, which makes me think the order/timing that tests are started is having an impact.

This attempt to recreate it doesn't work though...

#[tokio::test]
async fn test_spinning_up_many_pgtemp_instances() {
    // function to create and destroy many tempdbs sequentially, to simulate a single test thread
    // running many tests sequentially
    async fn sequential_create_destroy() {
        for _ in 0..50 {
            let start = std::time::Instant::now();

            // create new tempdb
            let temp = pgtemp::PgTempDBBuilder::new().start_async().await;
            let mut pg_conn = sqlx::postgres::PgConnection::connect(
                temp.connection_uri().as_str()
            ).await.unwrap();

            // add some data
            pg_conn.execute("CREATE SCHEMA test").await.unwrap();
            pg_conn.execute("CREATE DATABASE test").await.unwrap();
            pg_conn.execute("CREATE TABLE test.test_table (id INT)").await.unwrap();
            pg_conn.execute("INSERT INTO test.test_table VALUES (1)").await.unwrap();
            pg_conn.execute("INSERT INTO test.test_table VALUES (2)").await.unwrap();

            // drop DB with an active connection
            drop(temp);
            let duration = start.elapsed();
            if duration.as_secs() > 10 {
                panic!("Creating and destroying a PgTempDB took too long: {:?}", duration);
            }
        }
    }

    // run many instances in parallel to simulate test runner threads
    let mut instances = vec![];
    for _ in 0..20 {
        instances.push(sequential_create_destroy());
    }

    futures::future::join_all(instances).await;
}

[boustrophedon]

I took a look at the code for 1 again. It looks like we're only sleeping for 100ms if the dbname is set to the default ("postgres"), so there's a good chance that's the issue. It's likely simply taking more than 100ms to start up, but we're not checking that. This can be fixed.

For 2 are you using any kind of connection pool in your actual tests? With async it's likely possible that a task to clean up a thread pool connection could not be run due to pgtemp's blocking drop, and in the meantime postgres is waiting on the connection to disconnect or something similar to that.

The docs for fast shutdown mode seems to be mostly the same for pg14 and 16 (which is being run in CI for the project) https://www.postgresql.org/docs/14/server-shutdown.html but it's also possible something could have changed there.

One thing to try would be switching to SIGQUIT and seeing if that makes a difference. Would it be possible for you to point your pgtemp dependency to be pgtemp = {git = "https://github.com/boustrophedon/pgtemp", branch = "force-shutdown" } and see if your tests still break? (I'm not sure off the top of my head if cargo will update your Cargo.lock for this - just double check it picked up the new dep, I added an extra debugging print statement on shutdown)

[hoxxep]

Upgrading to Postgres 18 appears to have resolved all of the 60s hangs on shutdown (issue 2). Postgres 14 and 16 both saw the same issue even on the SIGQUIT force-shutdown branch; but I can't reproduce the bug on Postgres 18 on either branch. (Also confirmed it updated the Cargo.lock to your git branch).

Issue 1 still occasionally crops up. Would spinning to check for successful startup be a reasonable approach (wait 20ms, try a connection, if it fails wait 20ms and try again, up to 1 second total)?

[tv42]

I'm seeing pgtemp cause flaky tests with v0.7.1. It seems the retry logic from #20 is not enough. I don't quite see how, but the symptoms are hard to argue with.

This comes from deadpool_postgres pool.get().await.unwrap() pointed at a let temp_db = PgTempDB::builder().start_async().await, after that has completed:

    called `Result::unwrap()` on an `Err` value: Backend(Error { kind: Db, cause: Some(DbError { severity: "FATAL", parsed_severity: Some(Fatal), code: SqlState(E57P03), message: "the database system is starting up", detail: None, hint: None, position: None, where_: None, schema: None, table: None, column: None, datatype: None, constraint: None, file: Some("backend_startup.c"), line: Some(309), routine: Some("BackendInitialize") }) })

https://www.postgresql.org/docs/current/app-createdb.html