mirror of
https://github.com/mudler/LocalAI.git
synced 2026-09-12 22:33:54 -04:00
fix(testutil): clear the maintenance timeouts at connection startup
The guard added last commit was circular. It cleared the maintenance database's timeouts by executing SET statement_timeout = 0 on a connection that had already inherited that database's bound, so the statement clearing the bound ran under the bound it was clearing. Under the white-box spec's deliberate 1ms that gave it 1ms, and it failed roughly once in fifty at 8-way concurrency with SQLSTATE 57014. The guard against invisible load-dependent flakes had become one. The clearing is now delivered as a connection startup option, options=-c statement_timeout=0 -c lock_timeout=0 on the maintenance DSN, so there is no statement left to abort. Raising the imposed bound would only have bought headroom and left the circularity in place. pgx puts every URL query parameter into settings, options is absent from notRuntimeParams so it becomes a runtime parameter, and runtime parameters are copied into the startup message (pgconn/config.go:340-378, 606-617; pgconn/pgconn.go:382-388). The spec now discriminates on pg_settings.reset_val, the value in force when the connection started: 0 for a startup option, 1ms for a session SET. A first attempt using a deliberately slow first statement did NOT discriminate, because under the circular design the SET is itself the first statement, so by the time a spec runs anything the session is already unbounded. Reinstating the circular clearing now reddens the spec deterministically rather than intermittently. Assisted-by: Claude Opus 5 [claude-code] Signed-off-by: Ettore Di Giacinto <mudler@localai.io>
This commit is contained in:
1 parent
a816bf9b84
commit
5b7d65e679
2 files changed
+98
-42
No files matched your search
@@ -165,61 +165,70 @@ func SetupTestDB() *gorm.DB {
|
||||
return db
|
||||
}
|
||||
|
||||
// openPool connects to dsn with logging off and with every server-side timeout
|
||||
// disabled on the session. Used for the short-lived maintenance connections
|
||||
// only; the database a spec is handed keeps gorm's silent logger and the
|
||||
// server's defaults, because setting timeouts on it is a thing specs do on
|
||||
// purpose.
|
||||
// maintenanceDSN is dsn with every server-side timeout disabled as a CONNECTION
|
||||
// STARTUP OPTION rather than as a statement.
|
||||
//
|
||||
// The timeouts are cleared because CREATE DATABASE and DROP DATABASE must not
|
||||
// be bounded by anything a spec configured. A spec that sets a short
|
||||
// statement_timeout on ITS database cannot reach this one, but a spec that
|
||||
// names the maintenance database by mistake can, and that is not hypothetical:
|
||||
// two advisory-lock specs did exactly that until this round. The consequence
|
||||
// there is a load-dependent failure in another spec's setup or a silently
|
||||
// swallowed DROP, which is the same invisible single-spec flake this helper was
|
||||
// rewritten to remove.
|
||||
// The timeouts have to go because CREATE DATABASE and DROP DATABASE must not be
|
||||
// bounded by anything a spec configured. A spec that sets a short
|
||||
// statement_timeout on ITS own database cannot reach this connection, but a spec
|
||||
// that names the maintenance database by mistake can, and that is not
|
||||
// hypothetical: two advisory-lock specs did exactly that.
|
||||
//
|
||||
// MaxOpenConns(1) is what makes the SET reach the statement that follows it: a
|
||||
// session setting lives on one connection, and with a single connection in the
|
||||
// pool there is no other one for CREATE or DROP to land on.
|
||||
// Clearing it with `SET statement_timeout = 0` on an already-open connection is
|
||||
// circular and was a real defect here: that connection has already inherited the
|
||||
// database's bound, so the statement that clears the bound runs under it and can
|
||||
// be aborted by it with SQLSTATE 57014. It failed roughly once in fifty at
|
||||
// 8-way concurrency, which is the same invisible load-dependent single-spec
|
||||
// flake this helper exists to remove. A startup option removes the circularity
|
||||
// instead of buying headroom against it: the value is delivered in the startup
|
||||
// packet, so the connection is already unbounded before it can run anything.
|
||||
//
|
||||
// The route is verified in the driver rather than assumed. pgx puts every URL
|
||||
// query parameter into settings (pgconn/config.go:614), `options` is absent from
|
||||
// notRuntimeParams (pgconn/config.go:340-362) so it becomes a runtime parameter
|
||||
// (pgconn/config.go:374-378), and runtime parameters are copied into the startup
|
||||
// message (pgconn/pgconn.go:382-388). PostgreSQL treats `options` as backend
|
||||
// command-line switches, so `-c statement_timeout=0` is applied before the
|
||||
// session accepts a query.
|
||||
func maintenanceDSN(dsn string) (string, error) {
|
||||
u, err := url.Parse(dsn)
|
||||
if err != nil {
|
||||
return "", err
|
||||
}
|
||||
q := u.Query()
|
||||
// Percent-encoded by Encode, and pgx decodes query values before they reach
|
||||
// settings, so the server receives the switches with their spaces intact.
|
||||
q.Set("options", "-c statement_timeout=0 -c lock_timeout=0")
|
||||
u.RawQuery = q.Encode()
|
||||
return u.String(), nil
|
||||
}
|
||||
|
||||
// openPool connects to the maintenance database with logging off and no
|
||||
// server-side timeouts. Used for the short-lived maintenance connections only;
|
||||
// the database a spec is handed keeps gorm's silent logger and the server's
|
||||
// defaults, because setting timeouts on it is a thing specs do on purpose.
|
||||
func openPool(dsn string) *gorm.DB {
|
||||
GinkgoHelper()
|
||||
db, err := gorm.Open(postgres.Open(dsn), &gorm.Config{Logger: logger.Discard})
|
||||
db, err := openTolerantPool(dsn)
|
||||
Expect(err).ToNot(HaveOccurred())
|
||||
|
||||
sqlDB, err := db.DB()
|
||||
Expect(err).ToNot(HaveOccurred())
|
||||
sqlDB.SetMaxOpenConns(1)
|
||||
|
||||
Expect(db.Exec("SET statement_timeout = 0").Error).To(Succeed())
|
||||
Expect(db.Exec("SET lock_timeout = 0").Error).To(Succeed())
|
||||
return db
|
||||
}
|
||||
|
||||
// openTolerantPool is openPool for the cleanup path, which must report a
|
||||
// failure rather than assert one: an assertion here would fail a spec that had
|
||||
// already passed, and bury whatever the next real failure was.
|
||||
//
|
||||
// It carries the same startup options, and the DROP is the statement that most
|
||||
// needs them: FORCE waits on terminating other sessions, measured at up to 169ms
|
||||
// against the 300ms bound that used to leak here, and a DROP aborted mid-way is
|
||||
// swallowed and leaks a database.
|
||||
func openTolerantPool(dsn string) (*gorm.DB, error) {
|
||||
db, err := gorm.Open(postgres.Open(dsn), &gorm.Config{Logger: logger.Discard})
|
||||
maintenance, err := maintenanceDSN(dsn)
|
||||
if err != nil {
|
||||
return nil, err
|
||||
}
|
||||
sqlDB, err := db.DB()
|
||||
db, err := gorm.Open(postgres.Open(maintenance), &gorm.Config{Logger: logger.Discard})
|
||||
if err != nil {
|
||||
closePool(db)
|
||||
return nil, err
|
||||
}
|
||||
sqlDB.SetMaxOpenConns(1)
|
||||
// The DROP below is the statement most likely to be slow, since it waits on
|
||||
// FORCE terminating other sessions, so it is the one a leaked timeout would
|
||||
// abort. Measured at up to 169ms under load, against a 300ms bound.
|
||||
if err := db.Exec("SET statement_timeout = 0").Error; err != nil {
|
||||
closePool(db)
|
||||
return nil, err
|
||||
}
|
||||
if err := db.Exec("SET lock_timeout = 0").Error; err != nil {
|
||||
closePool(db)
|
||||
return nil, err
|
||||
}
|
||||
return db, nil
|
||||
|
||||
@@ -5,6 +5,9 @@ import (
|
||||
|
||||
. "github.com/onsi/ginkgo/v2"
|
||||
. "github.com/onsi/gomega"
|
||||
"gorm.io/driver/postgres"
|
||||
"gorm.io/gorm"
|
||||
gormlogger "gorm.io/gorm/logger"
|
||||
)
|
||||
|
||||
// These are white-box on purpose: the property is about the connection this
|
||||
@@ -45,6 +48,11 @@ var _ = Describe("the maintenance connection", func() {
|
||||
Expect(impose.Exec(fmt.Sprintf("ALTER DATABASE %q SET lock_timeout = '1ms'", maintenance)).Error).To(Succeed())
|
||||
}()
|
||||
|
||||
// The bound is delivered before the first statement, so the check
|
||||
// below is also the connection's first statement. That ordering is the
|
||||
// point: clearing the bound with a SET would be circular, because the
|
||||
// clearing statement inherits the bound it is clearing and can be
|
||||
// aborted by it with 57014. There is no such bootstrap statement now.
|
||||
fresh := openPool(dsn)
|
||||
defer closePool(fresh)
|
||||
var statementTimeout, lockTimeout string
|
||||
@@ -55,9 +63,48 @@ var _ = Describe("the maintenance connection", func() {
|
||||
Expect(lockTimeout).To(Equal("0"),
|
||||
"a lock_timeout on the maintenance database reached the helper's own connection")
|
||||
|
||||
// And the thing the timeouts would actually abort still works while the
|
||||
// bound is in force. A 1ms statement_timeout is far below the 14-26ms a
|
||||
// CREATE DATABASE takes here, so this could not pass by being fast.
|
||||
// A control, and the reason this spec is not a race. Clearing the bound
|
||||
// with a statement is circular: the clearing statement runs on a
|
||||
// connection that has already inherited the bound. Whether that
|
||||
// particular statement exceeds 1ms is a matter of load, which makes the
|
||||
// defect an intermittent one; whether the FIRST statement on a plain
|
||||
// connection is bounded at all is not. So the control asks the
|
||||
// deterministic question, with a first statement that certainly exceeds
|
||||
// the bound.
|
||||
func() {
|
||||
plain, err := gorm.Open(postgres.Open(dsn), &gorm.Config{Logger: gormlogger.Discard})
|
||||
Expect(err).ToNot(HaveOccurred())
|
||||
defer closePool(plain)
|
||||
err = plain.Exec("SELECT pg_sleep(0.05)").Error
|
||||
Expect(err).To(HaveOccurred(),
|
||||
"the imposed bound does not reach a fresh connection's first statement, so this spec's subject is not actually under test")
|
||||
Expect(err.Error()).To(ContainSubstring("57014"),
|
||||
"expected the imposed statement_timeout to abort this, got something else")
|
||||
}()
|
||||
|
||||
// The same first statement on a maintenance connection is unbounded.
|
||||
Expect(fresh.Exec("SELECT pg_sleep(0.05)").Error).To(Succeed())
|
||||
|
||||
// And this is the assertion that says WHY, which is the part a
|
||||
// statement-based clearing cannot satisfy. reset_val is the value the
|
||||
// session would fall back to, that is, the value that was in force when
|
||||
// the connection started, before it could run anything. Clearing the
|
||||
// bound with `SET statement_timeout = 0` leaves reset_val at the
|
||||
// database's 1ms: the session is unbounded only because a statement
|
||||
// said so, and that statement ran under the 1ms bound and can be
|
||||
// aborted by it. Delivering it as a startup option makes the connection
|
||||
// unbounded with no statement in between, which is the difference
|
||||
// between a fix and a wider margin.
|
||||
var resetVal string
|
||||
Expect(fresh.Raw(
|
||||
"SELECT reset_val FROM pg_settings WHERE name = 'statement_timeout'",
|
||||
).Scan(&resetVal).Error).To(Succeed())
|
||||
Expect(resetVal).To(Equal("0"),
|
||||
"the maintenance connection started under a %s bound and cleared it with a statement, so the clearing statement itself runs under the bound it is clearing", resetVal)
|
||||
|
||||
// And the operation the bound would abort still works while it is in
|
||||
// force. 1ms is far below the 14-26ms a CREATE DATABASE takes here, so
|
||||
// this cannot pass by being fast.
|
||||
Expect(SetupTestDB()).ToNot(BeNil())
|
||||
})
|
||||
})
|
||||
Reference in new issue
Block a user