@@ 25,7 25,7 @@ import (
"context"
"errors"
"fmt"
- "log"
+ "log/slog"
"os"
"path/filepath"
@@ 35,7 35,10 @@ import (
_ "github.com/lib/pq" // registers the "postgres" database/sql driver
"github.com/vaughan0/go-ini"
+ "go.bigb.es/auxilia/scribe"
+
"sourcecraft.dev/bigbes/sr-ht-core/config"
+ "sourcecraft.dev/bigbes/sr-ht-ecore/logging"
)
const (
@@ 101,15 104,16 @@ func main() {
}
conf := config.LoadConfig()
+ log := installLogger(conf)
if a.Auto && !config.GetBool(conf, serviceName, "migrate-on-upgrade", false) {
- log.Printf("%s: [%s]migrate-on-upgrade disabled, exiting", progName, serviceName)
+ log.Info(fmt.Sprintf("[%s]migrate-on-upgrade disabled, exiting", serviceName))
return
}
dsn, err := resolveDSN(conf, a.DataSourceName)
if err != nil {
- log.Fatalf("%s: %v", progName, err)
+ fatal(log, err)
}
a.DataSourceName = dsn
@@ 118,14 122,14 @@ func main() {
a.Driver = &drv
if err := resolvePaths(conf, a); err != nil {
- log.Fatalf("%s: %v", progName, err)
+ fatal(log, err)
}
- log.Printf("%s: loading migrations from %s", progName, a.Directory)
+ log.Info("loading migrations", "dir", a.Directory)
if a.Init != nil {
- log.Printf("%s: initializing schema from %s", progName, a.Init.Schema)
+ log.Info("initializing schema", "schema", a.Init.Schema)
if err := initDatabase(a); err != nil {
- log.Fatalf("%s: init failed: %v", progName, err)
+ fatal(log, fmt.Errorf("init failed: %w", err))
}
return
}
@@ 133,6 137,62 @@ func main() {
cli.RunWithArgs(&a.Args)
}
+// installLogger installs the process-wide slog handler, and it is the daemon's:
+// cmd/specsrht's installLogger builds the same scribe handler over the same
+// sr-ht-ecore policy, so a migration and the daemon that starts after it are
+// read the same way in the same journal.
+//
+// Installing it at all is the point rather than the tidiness. brant reports a
+// migration directory it cannot open with
+// `slog.Error("failed to create provider", "datasource", a.DataSourceName, ...)`
+// — the connection string, password and all, at ERR level, on the ordinary path
+// an installed package takes before its first migration ships. Without this call
+// that record goes to Go's built-in stderr handler, which knows no mask list, so
+// the redaction sr-ht-ecore maintains never gets a chance to run. It was the
+// install that was missing here, not the list.
+//
+// One thing no mask list can fix: brant's own cli.initLogger runs inside
+// ProviderFromArgs, ahead of that record, and under --json it calls
+// slog.SetDefault with a plain JSON handler of its own — which throws this one
+// away and prints the DSN again. Nothing here passes --json and nothing should
+// start; the default branch only redirects the std log package and leaves the
+// installed handler alone, which is why the masking holds.
+//
+// The verbosity comes from DefaultsWithoutDebugFlag rather than the daemon's
+// Defaults, and that is the one place the two differ: ecore reads a standalone
+// -d out of os.Args as SourceHut's debug flag, while here -d is brant's
+// --dialect and takes a value, so `specsrht-migrate -d postgres up` would
+// silently ask for debug logging as well. $LOG_LEVEL and [spec.sr.ht]log-level
+// still resolve, which is what an operator debugging an upgrade hook reaches
+// for.
+func installLogger(conf ini.File) *slog.Logger {
+ opts := logging.DefaultsWithoutDebugFlag(conf, serviceName)
+ return logging.Install(scribe.NewTintHandler(
+ scribe.WithWriter(os.Stderr),
+ scribe.WithLevel(opts.Level),
+ scribe.WithSource(opts.AddSource),
+ scribe.WithTimeFormat(opts.TimeFormat),
+ scribe.WithNoColor(!opts.Color),
+ scribe.WithMaskKeys(opts.MaskKeys...),
+ scribe.WithMask(opts.MaskPattern, opts.MaskReplacement),
+ ))
+}
+
+// fatal reports why this binary is stopping and stops it. It replaces
+// log.Fatalf, which slog has no equivalent of on purpose: os.Exit runs no
+// deferred function, so "say why and die" is a decision only main may take.
+//
+// The error is the record's message rather than an attribute, and the progName
+// prefix every one of these lines used to carry is gone. Both follow from the
+// reader: these are whole sentences written for the operator watching an upgrade
+// — "no [spec.sr.ht]connection-string configured" is the entire report — and an
+// attribute would quote and escape it behind a key, while the unit name and the
+// source position the handler already stamps say what the prefix used to.
+func fatal(log *slog.Logger, err error) {
+ log.Error(err.Error())
+ os.Exit(1)
+}
+
// resolveDSN picks the connection string: an explicit --dsn (or BRANT_DSN) wins,
// otherwise [spec.sr.ht]connection-string. A missing or empty configured value
// is an error rather than a silent connection attempt against a default DSN.
@@ 161,7 221,7 @@ func resolvePaths(conf ini.File, a *Args) error {
return fmt.Errorf("checking ./migrations: %w", err)
}
if err == nil && info.IsDir() {
- log.Printf("%s: found ./migrations, using it", progName)
+ slog.Info("found ./migrations, using it")
return nil
}
@@ 1,21 1,112 @@
package main
import (
+ "bytes"
"context"
"crypto/rand"
"database/sql"
"encoding/hex"
+ "errors"
"net/url"
"os"
+ "os/exec"
"path/filepath"
"strings"
"testing"
"git.sr.ht/~bitfehler/brant/cli"
"github.com/alexflint/go-arg"
+ "github.com/stretchr/testify/assert"
+ "github.com/stretchr/testify/require"
"github.com/vaughan0/go-ini"
)
+// testArgvEnv turns a re-executed copy of this test binary into the migrate
+// binary itself: TestMain sees it, replaces os.Args with its whitespace-split
+// value and calls main().
+//
+// Running main() in a subprocess is the only way to observe what main() does.
+// It reads the config off the filesystem through config.LoadConfig, the record
+// under test is written by a library past every seam a unit test could reach,
+// and the run ends in os.Exit — which takes the process with it. What is under
+// test is what an operator finds in the upgrade log, so the test has to read
+// that log.
+const testArgvEnv = "SPECSRHT_MIGRATE_TEST_ARGV"
+
+func TestMain(m *testing.M) {
+ if argv, ok := os.LookupEnv(testArgvEnv); ok {
+ os.Args = append([]string{progName}, strings.Fields(argv)...)
+ main()
+ os.Exit(0)
+ }
+ os.Exit(m.Run())
+}
+
+// runMain runs main() in a subprocess whose working directory is empty — no
+// config.ini, no ./migrations — and returns everything the process wrote and the
+// status it exited with.
+//
+// Stdout and stderr are interleaved into one buffer because that is how a
+// package manager's upgrade log shows them, and the question this asks is what
+// an operator finds there.
+func runMain(t *testing.T, argv string) (output string, code int) {
+ t.Helper()
+
+ exe, err := os.Executable()
+ require.NoError(t, err, "locate the test binary to re-execute")
+
+ cmd := exec.Command(exe)
+ cmd.Dir = t.TempDir()
+ cmd.Env = append(os.Environ(), testArgvEnv+"="+argv)
+ var buf bytes.Buffer
+ cmd.Stdout = &buf
+ cmd.Stderr = &buf
+
+ err = cmd.Run()
+ var exit *exec.ExitError
+ switch {
+ case err == nil:
+ code = 0
+ case errors.As(err, &exit):
+ code = exit.ExitCode()
+ default:
+ require.NoError(t, err, "run %s %s", exe, argv)
+ }
+ return buf.String(), code
+}
+
+// testPassword is a fake credential no configuration on this instance holds. It
+// is written into the DSN the test passes and looked for in everything the
+// process wrote; a real one would put the thing under test into the test log.
+const testPassword = "HUNTER2SECRET"
+
+// TestMainDoesNotPrintTheConnectionString pins the reason main() installs a
+// logger at all.
+//
+// brant reports a migration directory it cannot open with
+// `slog.Error("failed to create provider", "datasource", a.DataSourceName, ...)`
+// — the connection string, password and all, at ERR level. A missing directory
+// is not an exotic state: it is what an installed package is in until its first
+// migration ships. Two things have to hold for the password not to reach the
+// journal, and this asserts through both: the key "datasource" must be in the
+// instance's mask list (sr-ht-ecore's, which did not know that spelling until it
+// was added), and a handler carrying that list must be slog's default by the
+// time brant writes, or the record goes to Go's built-in stderr handler and no
+// list of any kind applies.
+func TestMainDoesNotPrintTheConnectionString(t *testing.T) {
+ out, code := runMain(t,
+ "up --dir /nonexistent --dsn postgresql://u:"+testPassword+"@localhost/x")
+
+ // The run must actually reach brant and fail there, or the assertions below
+ // would pass over an empty log.
+ assert.NotZero(t, code, "the missing directory must still be a failed run: %s", out)
+ assert.Contains(t, out, "failed to create provider",
+ "the leaking record must have been written at all: %s", out)
+
+ assert.NotContains(t, out, testPassword, "the DSN reached the log in the clear: %s", out)
+ assert.Contains(t, out, "datasource=***", "%s", out)
+}
+
// testParse parses argv the way main() does, except that the environment is
// ignored: BRANT_DSN / BRANT_MIGRATION_DIR / BRANT_DIALECT in a developer's
// shell would otherwise silently change the defaults under test.