Jaymr/new-api
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

fix: 慢查询/错误 SQL 日志参数化 (#6493)

Browse Source 
* fix: parameterize slow/error SQL logs to avoid leaking credentials

* fix: validate SQL_SLOW_THRESHOLD_MS range

* fix: sanitize database driver error messages in SQL logs

* refactor: sanitize at gorm log writer seam to keep caller attribution
This commit is contained in:
feitianbubu
2026-07-27 22:21:31 +08:00
committed by GitHub
parent f01c13b086
commit c3db41407d
5 changed files with 202 additions and 20 deletions
Download Patch File Download Diff File Expand all files Collapse all files
.env.example
+2
View File
@@ -33,6 +33,8 @@
# SQL_MAX_OPEN_CONNS=1000
# 数据库连接最大生命周期（秒）
# SQL_MAX_LIFETIME=60
# 慢查询日志阈值（毫秒），0 表示关闭慢查询日志，超出 0-3600000 范围回退默认值 200
# SQL_SLOW_THRESHOLD_MS=200
# 缓存相关配置
go.mod
+7 -5
View File
@@ -67,7 +67,6 @@ require (
require (
github.com/ClickHouse/ch-go v0.65.0 // indirect
github.com/ClickHouse/clickhouse-go/v2 v2.32.0 // indirect
github.com/bmatcuk/doublestar/v4 v4.6.1 // indirect
github.com/casbin/govaluate v1.10.0 // indirect
github.com/go-faster/city v1.0.1 // indirect
@@ -107,13 +106,13 @@ require (
github.com/fxamacker/cbor/v2 v2.9.0 // indirect
github.com/gabriel-vasile/mimetype v1.4.3 // indirect
github.com/gin-contrib/sse v0.1.0 // indirect
github.com/glebarez/go-sqlite v1.21.2 // indirect
github.com/glebarez/go-sqlite v1.21.2
github.com/go-audio/audio v1.0.0 // indirect
github.com/go-audio/riff v1.0.0 // indirect
github.com/go-ole/go-ole v1.2.6 // indirect
github.com/go-playground/locales v0.14.1 // indirect
github.com/go-playground/universal-translator v0.18.1 // indirect
github.com/go-sql-driver/mysql v1.7.0 // indirect
github.com/go-sql-driver/mysql v1.7.0
github.com/go-webauthn/x v0.1.25 // indirect
github.com/goccy/go-json v0.10.2 // indirect
github.com/google/go-tpm v0.9.5 // indirect
@@ -121,7 +120,7 @@ require (
github.com/icza/bitio v1.1.0 // indirect
github.com/jackc/pgpassfile v1.0.0 // indirect
github.com/jackc/pgservicefile v0.0.0-20240606120523-5a60cdf6a761 // indirect
github.com/jackc/pgx/v5 v5.9.2 // indirect
github.com/jackc/pgx/v5 v5.9.2
github.com/jackc/puddle/v2 v2.2.2 // indirect
github.com/jfreymuth/vorbis v1.0.2 // indirect
github.com/jinzhu/inflection v1.0.0 // indirect
@@ -163,6 +162,9 @@ require (
modernc.org/sqlite v1.40.1 // indirect
)
require github.com/QuantumNous/new-api/relaykit v0.0.0
require (
github.com/ClickHouse/clickhouse-go/v2 v2.32.0
github.com/QuantumNous/new-api/relaykit v0.0.0
)
replace github.com/QuantumNous/new-api/relaykit => ./relaykit
model/gorm_logger.go
+86
View File
@@ -0,0 +1,86 @@
package model
import (
"errors"
"fmt"
"io"
"log"
"os"
"time"
"github.com/ClickHouse/clickhouse-go/v2/lib/proto"
"github.com/QuantumNous/new-api/common"
sqlitedriver "github.com/glebarez/go-sqlite"
"github.com/go-sql-driver/mysql"
"github.com/jackc/pgx/v5/pgconn"
"gorm.io/gorm"
"gorm.io/gorm/logger"
)
const (
defaultSlowThresholdMs = 200
maxSlowThresholdMs = 60 * 60 * 1000
)
func newGormConfig(prepareStmt bool) *gorm.Config {
return &gorm.Config{
PrepareStmt: prepareStmt,
Logger: newGormLogger(os.Stdout),
}
}
func newGormLogger(w io.Writer) logger.Interface {
slowThresholdMs := common.GetEnvOrDefault("SQL_SLOW_THRESHOLD_MS", defaultSlowThresholdMs)
if slowThresholdMs < 0 || slowThresholdMs > maxSlowThresholdMs {
common.SysError(fmt.Sprintf("invalid SQL_SLOW_THRESHOLD_MS %d (allowed 0-%d, 0 disables slow query log), using default %d", slowThresholdMs, maxSlowThresholdMs, defaultSlowThresholdMs))
slowThresholdMs = defaultSlowThresholdMs
}
// 在 Writer 层脱敏而非包装 logger.Interface:后者会让 gorm 的 FileWithLineNum
// 把所有 SQL 日志的调用点归因到包装层自身,且需转发 ParamsFilter 类型断言。
return logger.New(&sanitizedLogWriter{delegate: log.New(w, "\r\n", log.LstdFlags)}, logger.Config{
SlowThreshold: time.Duration(slowThresholdMs) * time.Millisecond,
LogLevel: logger.Warn,
IgnoreRecordNotFoundError: true,
ParameterizedQueries: !common.DebugEnabled,
Colorful: true,
})
}
// ParameterizedQueries 只过滤 SQL 字符串,驱动错误消息(如 MySQL 1062)同样会
// 内联数据值,在这里收敛为错误码;DEBUG=true 保留原文。
type sanitizedLogWriter struct {
delegate *log.Logger
}
func (s *sanitizedLogWriter) Printf(format string, args ...interface{}) {
if !common.DebugEnabled {
for i, arg := range args {
if err, ok := arg.(error); ok {
args[i] = sanitizeDBError(err)
}
}
}
s.delegate.Printf(format, args...)
}
// 只收敛数据库服务端生成的驱动错误(消息可能内联数据值);网络/上下文等
// 其它错误不含查询数据,原样保留以便排障。
func sanitizeDBError(err error) error {
var mysqlErr *mysql.MySQLError
if errors.As(err, &mysqlErr) {
return fmt.Errorf("mysql error %d", mysqlErr.Number)
}
var pgErr *pgconn.PgError
if errors.As(err, &pgErr) {
return fmt.Errorf("postgres error SQLSTATE %s", pgErr.Code)
}
var chErr *proto.Exception
if errors.As(err, &chErr) {
return fmt.Errorf("clickhouse error %d", chErr.Code)
}
var sqliteErr *sqlitedriver.Error
if errors.As(err, &sqliteErr) {
return fmt.Errorf("sqlite error %d", sqliteErr.Code())
}
return err
}
model/gorm_logger_test.go
+102
View File
@@ -0,0 +1,102 @@
package model
import (
"bytes"
"fmt"
"testing"
"github.com/ClickHouse/clickhouse-go/v2/lib/proto"
"github.com/QuantumNous/new-api/common"
"github.com/glebarez/sqlite"
"github.com/go-sql-driver/mysql"
"github.com/jackc/pgx/v5/pgconn"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"gorm.io/gorm"
)
// 保护契约:数据库驱动错误消息可能内联数据值,非 DEBUG 下日志只保留错误码。
func TestSanitizeDBErrorStripsDriverMessage(t *testing.T) {
tests := []struct {
name string
err error
want string
leaked string
}{
{
name: "mysql duplicate entry",
err: &mysql.MySQLError{Number: 1062, Message: "Duplicate entry 'secret-value' for key 'users.idx'"},
want: "mysql error 1062",
leaked: "secret-value",
},
{
name: "postgres unique violation",
err: &pgconn.PgError{Code: "23505", Message: "duplicate key value", Detail: "Key (k)=(secret-value) already exists."},
want: "postgres error SQLSTATE 23505",
leaked: "secret-value",
},
{
name: "clickhouse exception",
err: &proto.Exception{Code: 241, Message: "Memory limit exceeded while processing 'secret-value'"},
want: "clickhouse error 241",
leaked: "secret-value",
},
{
name: "wrapped driver error",
err: fmt.Errorf("exec failed: %w", &mysql.MySQLError{Number: 1064, Message: "syntax error near 'secret-value'"}),
want: "mysql error 1064",
leaked: "secret-value",
},
}
for _, tc := range tests {
t.Run(tc.name, func(t *testing.T) {
got := sanitizeDBError(tc.err)
require.Error(t, got)
assert.Equal(t, tc.want, got.Error())
assert.NotContains(t, got.Error(), tc.leaked)
})
}
}
func TestSanitizeDBErrorSQLiteDriver(t *testing.T) {
db, err := gorm.Open(sqlite.Open(":memory:"), &gorm.Config{})
require.NoError(t, err)
execErr := db.Exec("INSERT INTO missing_table (k) VALUES (?)", "secret-value").Error
require.Error(t, execErr)
got := sanitizeDBError(execErr)
assert.Regexp(t, `^sqlite error \d+$`, got.Error())
assert.NotContains(t, got.Error(), "secret-value")
}
func TestSanitizeDBErrorKeepsNonDriverErrors(t *testing.T) {
err := fmt.Errorf("dial tcp 127.0.0.1:3306: connect: connection refused")
assert.Equal(t, err, sanitizeDBError(err))
}
// 保护契约:经 gorm 真实链路,错误日志同时满足 SQL 参数化、驱动错误脱敏、
// 调用点归因到业务代码;DEBUG=true 恢复参数值与错误原文。
func TestGormLoggerEndToEndSanitizedOutput(t *testing.T) {
previousDebug := common.DebugEnabled
t.Cleanup(func() { common.DebugEnabled = previousDebug })
execQuery := func() string {
var buf bytes.Buffer
db, err := gorm.Open(sqlite.Open(":memory:"), &gorm.Config{Logger: newGormLogger(&buf)})
require.NoError(t, err)
db.Exec("SELECT * FROM missing_table WHERE k = ?", "secret-value")
return buf.String()
}
common.DebugEnabled = false
out := execQuery()
assert.Contains(t, out, "k = ?")
assert.NotContains(t, out, "secret-value")
assert.Contains(t, out, "sqlite error")
assert.Contains(t, out, "gorm_logger_test.go")
common.DebugEnabled = true
debugOut := execQuery()
assert.Contains(t, debugOut, "secret-value")
assert.Contains(t, debugOut, "no such table")
}
model/main.go
+5 -15
View File
@@ -132,9 +132,7 @@ func chooseDB(envName string, isLog bool) (*gorm.DB, common.DatabaseType, error)
return nil, "", fmt.Errorf("%s does not support ClickHouse; use SQLite, MySQL, or PostgreSQL for the primary database and LOG_SQL_DSN for ClickHouse logs", envName)
}
common.SysLog("using ClickHouse as log database")
db, err := gorm.Open(clickhouse.Open(normalizeClickHouseDSN(dsn)), &gorm.Config{
PrepareStmt: false,
})
db, err := gorm.Open(clickhouse.Open(normalizeClickHouseDSN(dsn)), newGormConfig(false))
return db, common.DatabaseTypeClickHouse, err
}
if strings.HasPrefix(dsn, "postgres://") || strings.HasPrefix(dsn, "postgresql://") {
@@ -143,16 +141,12 @@ func chooseDB(envName string, isLog bool) (*gorm.DB, common.DatabaseType, error)
db, err := gorm.Open(postgres.New(postgres.Config{
DSN: dsn,
PreferSimpleProtocol: true, // disables implicit prepared statement usage
}), &gorm.Config{
PrepareStmt: true, // precompile SQL
})
}), newGormConfig(true))
return db, common.DatabaseTypePostgreSQL, err
}
if strings.HasPrefix(dsn, "local") {
common.SysLog("SQL_DSN not set, using SQLite as database")
db, err := gorm.Open(sqlite.Open(common.SQLitePath), &gorm.Config{
PrepareStmt: true, // precompile SQL
})
db, err := gorm.Open(sqlite.Open(common.SQLitePath), newGormConfig(true))
return db, common.DatabaseTypeSQLite, err
}
// Use MySQL
@@ -165,16 +159,12 @@ func chooseDB(envName string, isLog bool) (*gorm.DB, common.DatabaseType, error)
dsn += "?parseTime=true"
}
}
db, err := gorm.Open(mysql.Open(dsn), &gorm.Config{
PrepareStmt: true, // precompile SQL
})
db, err := gorm.Open(mysql.Open(dsn), newGormConfig(true))
return db, common.DatabaseTypeMySQL, err
}
// Use SQLite
common.SysLog("SQL_DSN not set, using SQLite as database")
db, err := gorm.Open(sqlite.Open(common.SQLitePath), &gorm.Config{
PrepareStmt: true, // precompile SQL
})
db, err := gorm.Open(sqlite.Open(common.SQLitePath), newGormConfig(true))
return db, common.DatabaseTypeSQLite, err
}