Use max_statement_time for timeouts. (#2263)

This means that we get a more useful log message for slow queries, and don't
need to close the MySQL connection. It also means that the query is actually
killed on the MySQL side, rather than just timing out and returning on the
client side.

We set the max_statement_time to 95% of the `readTimeout`.

Also set the `long_query_time` to 80% of the `readTimeout`, so that queries that are
close to timing out will be logged by MySQL's slow query logging.
This commit is contained in:
Jacob Hoffman-Andrews 2016-10-20 07:29:29 -07:00 committed by Daniel McCarney
parent 46306b07b9
commit 5f1919b40f
2 changed files with 37 additions and 1 deletions

View File

@ -67,10 +67,25 @@ func NewDbMapFromConfig(config *mysql.Config, maxOpenConns int) (*gorp.DbMap, er
dbmap := &gorp.DbMap{Db: db, Dialect: dialect, TypeConverter: BoulderTypeConverter{}}
initTables(dbmap)
_, err = dbmap.Exec("SET sql_mode = 'STRICT_ALL_TABLES';")
_, err = dbmap.Exec("SET SESSION sql_mode = 'STRICT_ALL_TABLES';")
if err != nil {
return nil, err
}
// If a read timeout is set, we set max_statement_time to 95% of that, and
// long_query_time to 80% of that. That way we get logs of queries that are
// close to timing out but not yet doing so, and our queries get stopped by
// max_statement_time before timing out the read. This generates clearer
// errors, and avoids unnecessary reconnects.
if config.ReadTimeout != 0 {
// In MariaDB, max_statement_time and long_query_time are both seconds.
// Note: in MySQL (which we don't use), max_statement_time is millis.
readTimeout := config.ReadTimeout.Seconds()
_, err := dbmap.Exec("SET SESSION max_statement_time = ?, long_query_time = ?;",
readTimeout*0.95, readTimeout*0.80)
if err != nil {
return nil, err
}
}
return dbmap, err
}

View File

@ -73,3 +73,24 @@ func TestStrictness(t *testing.T) {
t.Fatalf("Got wrong type of error: %s", err)
}
}
func TestTimeouts(t *testing.T) {
dbMap, err := NewDbMap(vars.DBConnSA+"?readTimeout=100ms", 1)
if err != nil {
t.Fatal("Error setting up DB:", err)
}
// SLEEP is defined to return 1 if it was interrupted, but we want to actually
// get an error to simulate what would happen with a slow query. So we wrap
// the SLEEP in a subselect.
_, err = dbMap.Exec(`SELECT 1 FROM (SELECT SLEEP(1)) as subselect;`)
if err == nil {
t.Fatal("Expected error when running slow query, got none.")
}
// We expect to get:
// Error 1969: Query execution was interrupted (max_statement_time exceeded)
// https://mariadb.com/kb/en/mariadb/mariadb-error-codes/
if !strings.Contains(err.Error(), "Error 1969") {
t.Fatalf("Got wrong type of error: %s", err)
}
}