Add slow SQL query warning

custom/conf/app.example.ini

@@ -412,6 +412,10 @@ USER = root
 ;;
 ;; Whether execute database models migrations automatically
 ;AUTO_MIGRATION = true
+;;
+;; Threshold value (in seconds) beyond which query execution time is logged as a warning in the xorm logger
+;;
+;SLOW_QUERY_THRESHOLD = 5s
 
 ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
 ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;

docs/content/administration/config-cheat-sheet.en-us.md

@@ -458,6 +458,7 @@ The following configuration set `Content-Type: application/vnd.android.package-a
 - `MAX_IDLE_CONNS` **2**: Max idle database connections on connection pool, default is 2 - this will be capped to `MAX_OPEN_CONNS`.
 - `CONN_MAX_LIFETIME` **0 or 3s**: Sets the maximum amount of time a DB connection may be reused - default is 0, meaning there is no limit (except on MySQL where it is 3s - see #6804 & #7071).
 - `AUTO_MIGRATION` **true**: Whether execute database models migrations automatically.
+- `SLOW_QUERY_THRESHOLD` **5s**: Threshold value in seconds beyond which query execution time is logged as a warning in the xorm logger.
 
 [^1]: It may be necessary to specify a hostport even when listening on a unix socket, as the port is part of the socket name. see [#24552](https://github.com/go-gitea/gitea/issues/24552#issuecomment-1681649367) for additional details.
 

models/db/engine.go

@@ -11,10 +11,13 @@ import (
 	"io"
 	"reflect"
 	"strings"
+	"time"
 
+	"code.gitea.io/gitea/modules/log"
 	"code.gitea.io/gitea/modules/setting"
 
 	"xorm.io/xorm"
+	"xorm.io/xorm/contexts"
 	"xorm.io/xorm/names"
 	"xorm.io/xorm/schemas"
 
@@ -143,6 +146,13 @@ func InitEngine(ctx context.Context) error {
 	xormEngine.SetConnMaxLifetime(setting.Database.ConnMaxLifetime)
 	xormEngine.SetDefaultContext(ctx)
 
+	if setting.Database.SlowQueryThreshold > 0 {
+		xormEngine.AddHook(&SlowQueryHook{
+			Threshold: setting.Database.SlowQueryThreshold,
+			Logger:    log.GetLogger("xorm"),
+		})
+	}
+
 	SetDefaultEngine(ctx, xormEngine)
 	return nil
 }
@@ -298,3 +308,24 @@ func SetLogSQL(ctx context.Context, on bool) {
 		sess.Engine().ShowSQL(on)
 	}
 }
+
+type SlowQueryHook struct {
+	Threshold time.Duration
+	Logger    log.Logger
+}
+
+var _ contexts.Hook = &SlowQueryHook{}
+
+func (SlowQueryHook) BeforeProcess(c *contexts.ContextHook) (context.Context, error) {
+	return c.Ctx, nil
+}
+
+func (h *SlowQueryHook) AfterProcess(c *contexts.ContextHook) error {
+	if c.ExecuteTime >= h.Threshold {
+		// 8 is the amount of skips passed to runtime.Caller, so that in the log the correct function
+		// is being displayed (the function that ultimately wants to execute the query in the code)
+		// instead of the function of the slow query hook being called.
+		h.Logger.Log(8, log.WARN, "[Slow SQL Query] %s %v - %v", c.SQL, c.Args, c.ExecuteTime)
+	}
+	return nil
+}

modules/setting/database.go

@@ -25,26 +25,27 @@ var (
 
 	// Database holds the database settings
 	Database = struct {
-		Type              DatabaseType
-		Host              string
-		Name              string
-		User              string
-		Passwd            string
-		Schema            string
-		SSLMode           string
-		Path              string
-		LogSQL            bool
-		MysqlCharset      string
-		CharsetCollation  string
-		Timeout           int // seconds
-		SQLiteJournalMode string
-		DBConnectRetries  int
-		DBConnectBackoff  time.Duration
-		MaxIdleConns      int
-		MaxOpenConns      int
-		ConnMaxLifetime   time.Duration
-		IterateBufferSize int
-		AutoMigration     bool
+		Type               DatabaseType
+		Host               string
+		Name               string
+		User               string
+		Passwd             string
+		Schema             string
+		SSLMode            string
+		Path               string
+		LogSQL             bool
+		MysqlCharset       string
+		CharsetCollation   string
+		Timeout            int // seconds
+		SQLiteJournalMode  string
+		DBConnectRetries   int
+		DBConnectBackoff   time.Duration
+		MaxIdleConns       int
+		MaxOpenConns       int
+		ConnMaxLifetime    time.Duration
+		IterateBufferSize  int
+		AutoMigration      bool
+		SlowQueryThreshold time.Duration
 	}{
 		Timeout:           500,
 		IterateBufferSize: 50,
@@ -87,6 +88,7 @@ func loadDBSetting(rootCfg ConfigProvider) {
 	Database.DBConnectRetries = sec.Key("DB_RETRIES").MustInt(10)
 	Database.DBConnectBackoff = sec.Key("DB_RETRY_BACKOFF").MustDuration(3 * time.Second)
 	Database.AutoMigration = sec.Key("AUTO_MIGRATION").MustBool(true)
+	Database.SlowQueryThreshold = sec.Key("SLOW_QUERY_THRESHOLD").MustDuration(5 * time.Second)
 }
 
 // DBConnStr returns database connection string