Merge pull request '[GITEA] Log SQL queries when the database return error' (#2140) from gusted/forgejo-error-sql-query into forgejo-dependency

Reviewed-on: https://codeberg.org/forgejo/forgejo/pulls/2140
Reviewed-by: Earl Warren <earl-warren@noreply.codeberg.org>

models/db/engine.go

@@ -153,6 +153,9 @@ func InitEngine(ctx context.Context) error {
 			Logger:   log.GetLogger("xorm"),
 		})
 	}
+	xormEngine.AddHook(&ErrorQueryHook{
+		Logger: log.GetLogger("xorm"),
+	})
 
 	SetDefaultEngine(ctx, xormEngine)
 	return nil
@@ -325,3 +328,20 @@ func (h *SlowQueryHook) AfterProcess(c *contexts.ContextHook) error {
 	}
 	return nil
 }
+
+type ErrorQueryHook struct {
+	Logger log.Logger
+}
+
+var _ contexts.Hook = &ErrorQueryHook{}
+
+func (ErrorQueryHook) BeforeProcess(c *contexts.ContextHook) (context.Context, error) {
+	return c.Ctx, nil
+}
+
+func (h *ErrorQueryHook) AfterProcess(c *contexts.ContextHook) error {
+	if c.Err != nil {
+		h.Logger.Log(8, log.ERROR, "[Error SQL Query] %s %v - %v", c.SQL, c.Args, c.Err)
+	}
+	return nil
+}

models/db/engine_test.go

@@ -123,3 +123,31 @@ func TestSlowQuery(t *testing.T) {
 	_, stopped = lc.Check(100 * time.Millisecond)
 	assert.True(t, stopped)
 }
+
+func TestErrorQuery(t *testing.T) {
+	lc, cleanup := test.NewLogChecker("error-query")
+	lc.StopMark("[Error SQL Query]")
+	defer cleanup()
+
+	e := db.GetEngine(db.DefaultContext)
+	engine, ok := e.(*xorm.Engine)
+	assert.True(t, ok)
+
+	// It's not possible to clean this up with XORM, but it's luckily not harmful
+	// to leave around.
+	engine.AddHook(&db.ErrorQueryHook{
+		Logger: log.GetLogger("error-query"),
+	})
+
+	// Valid query.
+	e.Exec("SELECT 1 WHERE false;")
+
+	_, stopped := lc.Check(100 * time.Millisecond)
+	assert.False(t, stopped)
+
+	// Table doesn't exist.
+	e.Exec("SELECT column FROM table;")
+
+	_, stopped = lc.Check(100 * time.Millisecond)
+	assert.True(t, stopped)
+}