db83a14056
- River logs as component river at warn, conga at log.level, -v lets River info through - an app-published logger wins for River and conga - GORM: warn by default, info traces at -vvv, record-not-found ignored, parameterized SQL - gate: the diary, sunscreen, conga and lagoon names in the go stage
84 lines
2.9 KiB
Go
84 lines
2.9 KiB
Go
package lagoon
|
|
|
|
import (
|
|
"bytes"
|
|
"context"
|
|
"errors"
|
|
"strings"
|
|
"testing"
|
|
"time"
|
|
|
|
"git.golem15.com/golem15/summercms/modules/bonfire"
|
|
"git.golem15.com/golem15/summercms/modules/diary"
|
|
"gorm.io/driver/postgres"
|
|
"gorm.io/gorm"
|
|
"gorm.io/gorm/logger"
|
|
)
|
|
|
|
// TestGormLoggerLevels: GORM logs at warn by default and info (SQL traces)
|
|
// at verbosity 3; a record-not-found error is not logged; slow queries and
|
|
// other errors are; and traces carry parameterized SQL, never bound values.
|
|
func TestGormLoggerLevels(t *testing.T) {
|
|
var buf bytes.Buffer
|
|
t.Cleanup(diary.Reset)
|
|
diary.Bootstrap(&buf, diary.Options{Color: bonfire.ColorNever})
|
|
ctx := context.Background()
|
|
trace := func(l logger.Interface, begin time.Time, err error) {
|
|
l.Trace(ctx, begin, func() (string, int64) { return `SELECT * FROM "users" WHERE email = $1`, 1 }, err)
|
|
}
|
|
|
|
l := gormLogger()
|
|
trace(l, time.Now(), nil)
|
|
trace(l, time.Now(), gorm.ErrRecordNotFound)
|
|
if buf.Len() != 0 {
|
|
t.Fatalf("verbosity 0 logged a fast trace or record-not-found:\n%s", buf.String())
|
|
}
|
|
trace(l, time.Now(), errors.New("relation does not exist"))
|
|
trace(l, time.Now().Add(-time.Second), nil)
|
|
out := buf.String()
|
|
for _, want := range []string{"level=ERROR", "relation does not exist", "level=WARN", "component=db", `trace.sql="SELECT * FROM \"users\" WHERE email = $1"`} {
|
|
if !strings.Contains(out, want) {
|
|
t.Errorf("verbosity 0 output lacks %q:\n%s", want, out)
|
|
}
|
|
}
|
|
|
|
buf.Reset()
|
|
diary.SetVerbosity(3, false)
|
|
l = gormLogger()
|
|
trace(l, time.Now(), nil)
|
|
trace(l, time.Now(), gorm.ErrRecordNotFound)
|
|
out = buf.String()
|
|
if strings.Count(out, "SQL executed") != 2 || strings.Contains(out, "record not found") {
|
|
t.Errorf("verbosity 3: want two info traces and no record-not-found error:\n%s", out)
|
|
}
|
|
|
|
// The SQL in a trace keeps its placeholders: GORM asks the logger to
|
|
// filter the parameters, and lagoon's logger drops them.
|
|
filter, ok := l.(gorm.ParamsFilter)
|
|
if !ok {
|
|
t.Fatal("lagoon's GORM logger does not filter parameters")
|
|
}
|
|
if _, params := filter.ParamsFilter(ctx, "SELECT $1", "secret-value"); params != nil {
|
|
t.Errorf("ParamsFilter kept the bound values %v", params)
|
|
}
|
|
|
|
// End to end with a dry-run GORM session (no database is reached).
|
|
buf.Reset()
|
|
db, err := gorm.Open(postgres.New(postgres.Config{DSN: "host=127.0.0.1 port=1 user=nobody dbname=none sslmode=disable"}),
|
|
&gorm.Config{Logger: l, DryRun: true, DisableAutomaticPing: true})
|
|
if err != nil {
|
|
t.Fatalf("dry-run gorm: %v", err)
|
|
}
|
|
var row struct{ ID int }
|
|
db.Table("users").Where("email = ?", "ada@example.test").Where("password = ?", "secret-value").Find(&row)
|
|
out = buf.String()
|
|
if !strings.Contains(out, "SQL executed") || !strings.Contains(out, "$1") || !strings.Contains(out, "$2") {
|
|
t.Errorf("dry-run trace lacks the parameterized SQL:\n%s", out)
|
|
}
|
|
for _, leaked := range []string{"ada@example.test", "secret-value"} {
|
|
if strings.Contains(out, leaked) {
|
|
t.Errorf("dry-run trace leaks the bound value %q:\n%s", leaked, out)
|
|
}
|
|
}
|
|
}
|