package gormlog_test import ( "context" "database/sql" "os" "path/filepath" "testing" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" "go.uber.org/fx" "go.uber.org/fx/fxtest" _ "modernc.org/sqlite" // Pure Go SQLite driver. "sneak.berlin/go/webhooker/internal/config" "sneak.berlin/go/webhooker/internal/database" "sneak.berlin/go/webhooker/internal/globals" "sneak.berlin/go/webhooker/internal/logger" "sneak.berlin/go/webhooker/internal/session" ) // argon2Prefix opens every encoded Argon2id hash this service // produces. It is asserted on separately from the hash itself, so that // a change to the password encoding cannot quietly turn the hash // assertion into a comparison against a string the log never held. const argon2Prefix = "$argon2id$" // settingsInsert and usersInsert are the two statements a first boot // runs that carry a secret. The sqlite dialector quotes identifiers // with backticks. const ( settingsInsert = "INSERT INTO `settings`" usersInsert = "INSERT INTO `users`" ) // captureStdoutToFile redirects os.Stdout into a file for the rest of // the test and returns a function that reads back everything written // to it. // // A file rather than a pipe: internal/logger writes synchronously to // whatever os.Stdout is when it builds its handler, so once fx's start // returns, every byte the boot produced is already in the file and no // draining goroutine is needed to prove it. Redirecting the variable // before the application is built is what puts the service logger — // and therefore the GORM adapter, which writes through it — into the // capture. // // The redirect also decides the handler: a regular file is not a // character device, so internal/logger installs its JSON handler, the // one it installs in production under a log collector. func captureStdoutToFile(t *testing.T) func() string { t.Helper() path := filepath.Join(t.TempDir(), "stdout.log") //nolint:gosec // The path is this test's own t.TempDir(). f, err := os.Create(path) require.NoError(t, err) orig := os.Stdout os.Stdout = f t.Cleanup(func() { os.Stdout = orig _ = f.Close() }) return func() string { require.NoError(t, f.Sync()) //nolint:gosec // As above. b, readErr := os.ReadFile(path) require.NoError(t, readErr) return string(b) } } // firstBootSecrets are the two values a first boot generates and // stores, read back out of the database. type firstBootSecrets struct { sessionKey string passwordHash string } // readFirstBootSecrets reads those two secrets straight out of the // SQLite file with database/sql rather than through GORM, so that // reading them cannot itself add a line to the log under test. func readFirstBootSecrets( t *testing.T, dataDir string, ) firstBootSecrets { t.Helper() db, err := sql.Open("sqlite", filepath.Join( dataDir, "webhooker.db", )) require.NoError(t, err) defer func() { require.NoError(t, db.Close()) }() ctx := context.Background() var got firstBootSecrets require.NoError(t, db.QueryRowContext( ctx, `SELECT value FROM settings WHERE key = 'session_key'`, ).Scan(&got.sessionKey)) require.NoError(t, db.QueryRowContext( ctx, `SELECT password FROM users WHERE username = 'admin'`, ).Scan(&got.passwordHash)) require.NotEmpty(t, got.sessionKey) require.Contains(t, got.passwordHash, argon2Prefix) return got } // bootAtDebug starts and stops the real application graph against // dataDir with DEBUG=true, and returns everything it wrote to standard // output. // // config.New reads DEBUG from the environment exactly as the binary // does, internal/logger builds the handler it builds in production, // database.New runs the migrations and creates the admin user, and // session.New takes the session key. Those four are the whole of the // path that writes either secret. func bootAtDebug(t *testing.T, dataDir string) string { t.Helper() t.Setenv("DEBUG", "true") t.Setenv("DATA_DIR", dataDir) read := captureStdoutToFile(t) var sess *session.Session app := fxtest.New( t, fx.Provide( globals.New, logger.New, config.New, database.New, session.New, ), fx.Populate(&sess), ) app.RequireStart() app.RequireStop() return read() } // requireFirstBootWasLogged is the non-vacuity half of the test below. // Without it a build that logged no SQL at all, or that never reached // DEBUG, would satisfy every absence assertion. func requireFirstBootWasLogged(t *testing.T, out string) { t.Helper() require.Contains( t, out, `"level":"DEBUG"`, "DEBUG=true did not reach the logger", ) require.Contains( t, out, settingsInsert, "the session key INSERT was not logged, so its absence "+ "proves nothing", ) require.Contains( t, out, usersInsert, "the admin user INSERT was not logged, so its absence "+ "proves nothing", ) } // TestFirstBootAtDebug_LogsNeitherSecret is the definition of done. // // A first boot is the only boot that writes either secret. The // settings INSERT carries the base64 session encryption key, which is // the whole of the session security model: anyone holding it can forge // an authenticated session cookie. The users INSERT carries the admin // account's Argon2id hash. Under interpolated statement logging both // landed in the log an operator diagnosing a startup problem pastes // into an issue. // // The secrets are read back out of the database file afterwards, so // the assertions are made against the values this boot actually // generated rather than against a pattern that might not match them. // // What this test does not cover: the initial admin password itself, // which internal/database logs once in the clear, on purpose, because // that line is the only place an operator ever sees it. That is a // separate decision from the SQL log, and it is documented in the // README rather than asserted here. // // Not parallel: it redirects os.Stdout and sets environment variables, // both process-global. // //nolint:paralleltest // Deliberately sequential; see above. func TestFirstBootAtDebug_LogsNeitherSecret(t *testing.T) { dataDir := t.TempDir() // An empty DATA_DIR is what makes this a first boot: with a // database already in place neither INSERT runs. entries, err := os.ReadDir(dataDir) require.NoError(t, err) require.Empty(t, entries, "DATA_DIR was not empty") out := bootAtDebug(t, dataDir) requireFirstBootWasLogged(t, out) secrets := readFirstBootSecrets(t, dataDir) assert.NotContains( t, out, secrets.sessionKey, "the session encryption key reached the debug log", ) assert.NotContains( t, out, secrets.passwordHash, "the admin password hash reached the debug log", ) assert.NotContains( t, out, argon2Prefix, "an encoded Argon2id hash reached the debug log", ) }