minstrel/internal/audit/audit_test.go

package audit_test

import (
	"bytes"
	"context"
	"log/slog"
	"os"
	"strings"
	"testing"

	"github.com/jackc/pgx/v5/pgtype"
	"github.com/jackc/pgx/v5/pgxpool"

	"git.fabledsword.com/bvandeusen/minstrel/internal/audit"
)

func newTestPool(t *testing.T) *pgxpool.Pool {
	t.Helper()
	url := os.Getenv("MINSTREL_TEST_DATABASE_URL")
	if url == "" {
		t.Skip("MINSTREL_TEST_DATABASE_URL not set")
	}
	pool, err := pgxpool.New(context.Background(), url)
	if err != nil {
		t.Fatalf("connect: %v", err)
	}
	t.Cleanup(pool.Close)
	// Reset audit_log so each test runs against a known state.
	if _, err := pool.Exec(context.Background(), `DELETE FROM audit_log`); err != nil {
		t.Fatalf("reset audit_log: %v", err)
	}
	return pool
}

func TestWrite_NoMetadata(t *testing.T) {
	pool := newTestPool(t)
	// Use NULL FKs (Valid: false) — the column is nullable.
	var nilUUID pgtype.UUID
	if err := audit.Write(context.Background(), pool, nilUUID, nilUUID, audit.ActionRegister, nil); err != nil {
		t.Fatalf("Write: %v", err)
	}
	var count int
	if err := pool.QueryRow(context.Background(),
		`SELECT count(*) FROM audit_log WHERE action = 'register' AND metadata IS NULL`,
	).Scan(&count); err != nil {
		t.Fatalf("count: %v", err)
	}
	if count != 1 {
		t.Errorf("count = %d, want 1", count)
	}
}

func TestWrite_WithMetadata(t *testing.T) {
	pool := newTestPool(t)
	var nilUUID pgtype.UUID
	if err := audit.Write(context.Background(), pool, nilUUID, nilUUID, audit.ActionPromoteAdmin, map[string]any{
		"reason":      "test",
		"first_admin": true,
	}); err != nil {
		t.Fatalf("Write: %v", err)
	}
	var meta string
	if err := pool.QueryRow(context.Background(),
		`SELECT metadata::text FROM audit_log WHERE action = 'promote_admin' LIMIT 1`,
	).Scan(&meta); err != nil {
		t.Fatalf("read metadata: %v", err)
	}
	// Postgres jsonb::text renders a space after ':' and ',', e.g.
	// {"reason": "test", "first_admin": true}.
	if !contains(meta, `"first_admin": true`) || !contains(meta, `"reason": "test"`) {
		t.Errorf("metadata = %q, expected first_admin + reason fields", meta)
	}
}

func contains(s, sub string) bool {
	return len(s) >= len(sub) && (func() bool {
		for i := 0; i+len(sub) <= len(s); i++ {
			if s[i:i+len(sub)] == sub {
				return true
			}
		}
		return false
	})()
}

// TestWriteOrLog_Success exercises the happy path — when Write
// succeeds, no log line is emitted. Skipped unless a test DB is
// configured (no fixtures harness exists in this package beyond the
// env-driven pool above).
func TestWriteOrLog_Success(t *testing.T) {
	pool := newTestPool(t)
	var buf bytes.Buffer
	logger := slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelWarn}))
	var nilUUID pgtype.UUID
	audit.WriteOrLog(context.Background(), pool, logger, nilUUID, nilUUID, audit.ActionRegister, nil)
	if buf.Len() != 0 {
		t.Errorf("expected no log output on success, got %q", buf.String())
	}
}

// TestWriteOrLog_DBFailure_Logs forces Write to fail by passing a
// closed pool, and asserts the logger captured a Warn record with
// action + err keys.
func TestWriteOrLog_DBFailure_Logs(t *testing.T) {
	url := os.Getenv("MINSTREL_TEST_DATABASE_URL")
	if url == "" {
		t.Skip("MINSTREL_TEST_DATABASE_URL not set")
	}
	pool, err := pgxpool.New(context.Background(), url)
	if err != nil {
		t.Fatalf("connect: %v", err)
	}
	pool.Close() // force subsequent ops to fail

	var buf bytes.Buffer
	logger := slog.New(slog.NewTextHandler(&buf, &slog.HandlerOptions{Level: slog.LevelWarn}))
	var nilUUID pgtype.UUID
	audit.WriteOrLog(context.Background(), pool, logger, nilUUID, nilUUID, audit.ActionRegister, nil)

	out := buf.String()
	if out == "" {
		t.Fatal("expected a Warn log line on failure, got none")
	}
	if !strings.Contains(out, "level=WARN") {
		t.Errorf("expected level=WARN in log line, got %q", out)
	}
	if !strings.Contains(out, "action=register") {
		t.Errorf("expected action=register key in log line, got %q", out)
	}
	if !strings.Contains(out, "err=") {
		t.Errorf("expected err= key in log line, got %q", out)
	}
}

// TestWriteOrLog_NilLogger ensures a nil logger + failing pool does
// not panic. Uses a closed pool to force the failure branch.
func TestWriteOrLog_NilLogger(t *testing.T) {
	url := os.Getenv("MINSTREL_TEST_DATABASE_URL")
	if url == "" {
		t.Skip("MINSTREL_TEST_DATABASE_URL not set")
	}
	pool, err := pgxpool.New(context.Background(), url)
	if err != nil {
		t.Fatalf("connect: %v", err)
	}
	pool.Close()

	var nilUUID pgtype.UUID
	// Must not panic.
	audit.WriteOrLog(context.Background(), pool, nil, nilUUID, nilUUID, audit.ActionRegister, nil)
}

func TestWrite_AllActionConstantsArePersisted(t *testing.T) {
	pool := newTestPool(t)
	var nilUUID pgtype.UUID
	actions := []audit.Action{
		audit.ActionRegister,
		audit.ActionPromoteAdmin,
		audit.ActionDemoteAdmin,
		audit.ActionInviteCreate,
		audit.ActionInviteRedeem,
		audit.ActionInviteRevoke,
		audit.ActionCreateUserAdmin,
		audit.ActionDeleteUser,
		audit.ActionPasswordResetAdmin,
		audit.ActionAutoApproveToggle,
		audit.ActionPasswordChangeSelf,
		audit.ActionTokenRegenerate,
		audit.ActionForgotPasswordInit,
		audit.ActionPasswordResetByEmail,
		audit.ActionDuplicateMerge,
		audit.ActionDuplicateDismiss,
		audit.ActionDuplicateWrongFile,
		audit.ActionSubsonicPasswordSet,
		audit.ActionSubsonicPasswordClear,
	}
	for _, a := range actions {
		if err := audit.Write(context.Background(), pool, nilUUID, nilUUID, a, nil); err != nil {
			t.Errorf("action %q: Write: %v", a, err)
		}
	}
	var count int
	if err := pool.QueryRow(context.Background(), `SELECT count(*) FROM audit_log`).Scan(&count); err != nil {
		t.Fatalf("count: %v", err)
	}
	if count != len(actions) {
		t.Errorf("count = %d, want %d", count, len(actions))
	}
}