`PostgresNIO ` precondition failure: "How can an error occur if the connection is already closed?"

I'm testing a method that inserts a new user into a Postgres DB:

internal static func insert(new user: Endpoint.Signup.User) throws {
    let timestamp: Date = .init()
    let salt: UUID = .init()
    let hashedPassword: Array<UInt8>=try PKCS5.PBKDF2(
        password: user.password.bytes, salt: salt.bytes, iterations: 4096,
        keyLength: 32, variant: .sha2(.sha256)
    ).calculate()
    let verificationId: UUID = .init()
    let connection=try API.shared.pools.requestConnection().wait()
    defer {
        API.shared.pools.releaseConnection(connection)
    }
    do {
        let _=try connection.simpleQuery("BEGIN").wait()
        let _=try connection.everyUserInsert(user.id, email: user.email, username: user.username, timestamp, .beginningEmailUser).wait()
        let _=try connection.populatedUserInsert(user.id, user, timestamp).forEach({ let _=try $0.wait() })
        let _=try connection.beginningEmailUserInsert(id: user.id, hashedPassword, salt: salt, verificationId: verificationId).wait()
        let _=try connection.simpleQuery("COMMIT").wait()
    } catch {
        
        // if `ROLLBACK` also fails, log both errors
        do {
            let _=try connection.simpleQuery("ROLLBACK").wait()
        } catch let rollbackError {
            throw LoggedError(statusCode: .internalServerError, displayedMessage: "Server error", loggedMessage: """
                Transaction Error: \(error)
                Rollback Error: \(rollbackError)
                """
            )
        }
        
        throw error
    }
}

This method operates as expected.

Then in the test method — after the above method returns — I run another query to ensure the insertion was successful:

// ensure user is there
let db=API.shared.pools.database(logger: .init(label: "APITests"))
var select: String="SELECT from \(BeginningEmailUser.tableName) WHERE \(BeginningEmailUser.Column.id)=$1"
var rows=try db.query(select, [.init(uuid: user.id)]).wait()
XCTAssert(rows.count == 1, "Unexpected insertion result")

This also runs successfully.

The problem occurs when I uncomment the next line that's meant to delete the test user:

// clean up
let _=try db.query("DELETE from \(BeginningEmailUser.tableName) WHERE \(BeginningEmailUser.Column.id)=$1", [.init(uuid: user.id)]).wait()

That's when I experience the precondition failure:

"How can an error occur if the connection is already closed?"

This is issued from PostgresNIO.ConnectionStateMachine.closeAndCleanup(_:). Does anyone see any obvious issue with what I'm doing here that could forgo me having to put together a minimal reproducible example? If not, please share and I'll put one together.

1 Like

@chrisbia this looks very much like a bug. There might be a server-error at play, but this shouldn't crash the operation. The preconditionFailure which you are running into is way to aggressive. Would you mind creating a GitHub issue in PostgresNIO and adding a repro? Thanks!

2 Likes

Will do, but I'm a little busy right now. May be two weeks before I put it together.

Hey @fabianfett,

I delayed addressing this until I tested on my new Mac. My previous Mac was a late 2013 MBP and I never ended up getting the test function to work on it. My new Mac is a 2021 iMac M1, and can confirm that the test function is successful when ran on it.

This sounds a bit like test flakiness we’ve seen across x86/Linux and arm64/macOS where machine speed influenced test success/failure. I’d raised an issue in the Vapor project regarding this a while back: Tests crashing with `Assertion failed: PostgresConnection deinitialized before being closed.` · Issue #2810 · vapor/vapor · GitHub