From 9152384fd317e9baacaaf707acee95540af096d6 Mon Sep 17 00:00:00 2001 From: Mechiel Lukkien Date: Fri, 10 May 2024 15:15:56 +0200 Subject: [PATCH] use debug logging in tests by setting the loglevel to debug in package mlog. we restore the "info" logging in main. except for "mox localserve", which still sets debug by default. --- dane/dane_test.go | 2 -- dmarcdb/eval_test.go | 3 --- localserve.go | 32 +++++++++++++++++++++++++++----- main.go | 18 ++++++++++++++---- mlog/log.go | 2 +- mtasts/mtasts_test.go | 2 -- smtpclient/client_test.go | 1 + smtpserver/server_test.go | 1 + tlsrptsend/send_test.go | 3 --- 9 files changed, 44 insertions(+), 20 deletions(-) diff --git a/dane/dane_test.go b/dane/dane_test.go index 42dad3e..df416d9 100644 --- a/dane/dane_test.go +++ b/dane/dane_test.go @@ -12,7 +12,6 @@ import ( "crypto/x509/pkix" "errors" "fmt" - "log/slog" "math/big" "net" "reflect" @@ -36,7 +35,6 @@ func tcheckf(t *testing.T, err error, format string, args ...any) { // Test dialing and DANE TLS verification. func TestDial(t *testing.T) { - mlog.SetConfig(map[string]slog.Level{"": mlog.LevelDebug}) log := mlog.New("dane", nil) // Create fake CA/trusted-anchor certificate. diff --git a/dmarcdb/eval_test.go b/dmarcdb/eval_test.go index bb963c1..e2c5eb8 100644 --- a/dmarcdb/eval_test.go +++ b/dmarcdb/eval_test.go @@ -6,7 +6,6 @@ import ( "encoding/xml" "fmt" "io" - "log/slog" "os" "path/filepath" "reflect" @@ -157,8 +156,6 @@ func TestEvaluations(t *testing.T) { } func TestSendReports(t *testing.T) { - mlog.SetConfig(map[string]slog.Level{"": slog.LevelDebug}) - os.RemoveAll("../testdata/dmarcdb/data") mox.Context = ctxbg mox.ConfigStaticPath = filepath.FromSlash("../testdata/dmarcdb/mox.conf") diff --git a/localserve.go b/localserve.go index 5e19c3f..d10ca5c 100644 --- a/localserve.go +++ b/localserve.go @@ -120,11 +120,14 @@ during those commands instead of during "data". existingConfig = true } - if level, ok := mlog.Levels[loglevel]; loglevel != "" && ok { - mox.Conf.Log[""] = level - mlog.SetConfig(mox.Conf.Log) - } else if loglevel != "" && !ok { - log.Fatal("unknown loglevel", slog.String("loglevel", loglevel)) + // For new configs, we keep the "info" loglevel set by writeLocalConfig until after + // initializing database files, to prevent lots of schema upgrade logging. + fallbackLevel := mox.Conf.Static.LogLevel + if fallbackLevel == "" { + fallbackLevel = "debug" + } + if existingConfig { + loadLoglevel(log, fallbackLevel) } // Initialize receivedid. @@ -158,6 +161,9 @@ during those commands instead of during "data". if err := start(mtastsdbRefresher, sendDMARCReports, sendTLSReports, skipForkExec); err != nil { log.Fatalx("starting mox", err) } + + loadLoglevel(log, fallbackLevel) + golog.Printf("mox, version %s, %s %s/%s", moxvar.Version, runtime.Version(), runtime.GOOS, runtime.GOARCH) golog.Print("") golog.Printf("the default user is mox@localhost, with password moxmoxmox") @@ -471,6 +477,9 @@ func writeLocalConfig(log mlog.Log, dir, ip string) (rerr error) { err = localLoadConfig(log, dir) xcheck(err, "loading config") + // Info so we don't log lots about initializing database. + loadLoglevel(log, "info") + // Set password on account. a, _, err := store.OpenEmail(log, "mox@localhost") xcheck(err, "opening account to set password") @@ -484,6 +493,19 @@ func writeLocalConfig(log mlog.Log, dir, ip string) (rerr error) { return nil } +func loadLoglevel(log mlog.Log, fallback string) { + ll := loglevel + if ll == "" { + ll = fallback + } + if level, ok := mlog.Levels[ll]; ok { + mox.Conf.Log[""] = level + mlog.SetConfig(mox.Conf.Log) + } else { + log.Fatal("unknown loglevel", slog.String("loglevel", loglevel)) + } +} + func localLoadConfig(log mlog.Log, dir string) error { mox.ConfigStaticPath = filepath.Join(dir, "mox.conf") mox.ConfigDynamicPath = filepath.Join(dir, "domains.conf") diff --git a/main.go b/main.go index f80802f..69be656 100644 --- a/main.go +++ b/main.go @@ -416,7 +416,7 @@ func usage(l []cmd, unlisted bool) { os.Exit(2) } -var loglevel string +var loglevel string // Empty will be interpreted as info, except by localserve. var pedantic bool // subcommands that are not "serve" should use this function to load the config, it @@ -424,10 +424,14 @@ var pedantic bool // loglevels from the config file and it does not load files like TLS keys/certs. func mustLoadConfig() { mox.MustLoadConfig(false, false) - if level, ok := mlog.Levels[loglevel]; loglevel != "" && ok { + ll := loglevel + if ll == "" { + ll = "info" + } + if level, ok := mlog.Levels[ll]; ok { mox.Conf.Log[""] = level mlog.SetConfig(mox.Conf.Log) - } else if loglevel != "" && !ok { + } else { log.Fatal("unknown loglevel", slog.String("loglevel", loglevel)) } if pedantic { @@ -486,10 +490,16 @@ func main() { } mox.ConfigDynamicPath = filepath.Join(filepath.Dir(mox.ConfigStaticPath), "domains.conf") - if level, ok := mlog.Levels[loglevel]; ok && loglevel != "" { + ll := loglevel + if ll == "" { + ll = "info" + } + if level, ok := mlog.Levels[ll]; ok { mox.Conf.Log[""] = level mlog.SetConfig(mox.Conf.Log) // note: SetConfig may be called again when subcommands loads config. + } else { + log.Fatalf("unknown loglevel %q", loglevel) } var partial []cmd diff --git a/mlog/log.go b/mlog/log.go index 0c2f685..3434e49 100644 --- a/mlog/log.go +++ b/mlog/log.go @@ -43,7 +43,7 @@ var lowestLevel atomic.Int32 // For quick initial check. var config atomic.Pointer[map[string]slog.Level] // For secondary complete check for match. func init() { - SetConfig(map[string]slog.Level{"": LevelInfo}) + SetConfig(map[string]slog.Level{"": LevelDebug}) } // SetConfig atomically sets the new log levels used by all Log instances. diff --git a/mtasts/mtasts_test.go b/mtasts/mtasts_test.go index 8a3aa62..d0f3558 100644 --- a/mtasts/mtasts_test.go +++ b/mtasts/mtasts_test.go @@ -9,7 +9,6 @@ import ( "errors" "io" golog "log" - "log/slog" "math/big" "net" "net/http" @@ -26,7 +25,6 @@ import ( ) func TestLookup(t *testing.T) { - mlog.SetConfig(map[string]slog.Level{"": mlog.LevelDebug}) log := mlog.New("mtasts", nil) resolver := dns.MockResolver{ diff --git a/smtpclient/client_test.go b/smtpclient/client_test.go index bba0e5f..8b61fcb 100644 --- a/smtpclient/client_test.go +++ b/smtpclient/client_test.go @@ -37,6 +37,7 @@ func TestClient(t *testing.T) { log := mlog.New("smtpclient", nil) mlog.SetConfig(map[string]slog.Level{"": mlog.LevelTrace}) + defer mlog.SetConfig(map[string]slog.Level{"": mlog.LevelDebug}) type options struct { // Server behaviour. diff --git a/smtpserver/server_test.go b/smtpserver/server_test.go index 0d051bf..70b12be 100644 --- a/smtpserver/server_test.go +++ b/smtpserver/server_test.go @@ -1119,6 +1119,7 @@ func TestRatelimitConnectionrate(t *testing.T) { // We'll be creating 300 connections, no TLS and reduce noise. ts.tlsmode = smtpclient.TLSSkip mlog.SetConfig(map[string]slog.Level{"": mlog.LevelInfo}) + defer mlog.SetConfig(map[string]slog.Level{"": mlog.LevelDebug}) // We may be passing a window boundary during this tests. The limit is 300/minute. // So make twice that many connections and hope the tests don't take too long. diff --git a/tlsrptsend/send_test.go b/tlsrptsend/send_test.go index 988e723..bccc08f 100644 --- a/tlsrptsend/send_test.go +++ b/tlsrptsend/send_test.go @@ -4,7 +4,6 @@ import ( "context" "fmt" "io" - "log/slog" "os" "path/filepath" "reflect" @@ -40,8 +39,6 @@ func tcompare(t *testing.T, got, expect any) { } func TestSendReports(t *testing.T) { - mlog.SetConfig(map[string]slog.Level{"": mlog.LevelDebug}) - os.RemoveAll("../testdata/tlsrptsend/data") mox.Context = ctxbg mox.ConfigStaticPath = filepath.FromSlash("../testdata/tlsrptsend/mox.conf")