summercms/modules/surf/summary_test.go

package surf

import (
	"bytes"
	"context"
	"encoding/json"
	"errors"
	"fmt"
	"log/slog"
	"net"
	"net/http"
	"os"
	"path/filepath"
	"strings"
	"testing"
	"time"

	"git.golem15.com/golem15/summercms/modules/backpack"
	"git.golem15.com/golem15/summercms/modules/bonfire"
	"git.golem15.com/golem15/summercms/modules/compass"
	"git.golem15.com/golem15/summercms/modules/diary"
	"git.golem15.com/golem15/summercms/modules/lagoon"
	"git.golem15.com/golem15/summercms/modules/party"
)

// summaryFixture is buildFacts over summaryApp with two plugins, three
// pending migrations and a worker.
func summaryFixture(t *testing.T) summaryFacts {
	t.Helper()
	return buildFacts(summaryApp(t), factInputs{
		addr:        ":8096",
		bin:         "bin/acme",
		plugins:     []party.Plugin{summaryPlugin{id: "acme.user"}, summaryPlugin{id: "acme.blog", req: []string{"acme.user"}}},
		queues:      []string{"default"},
		worker:      true,
		adminPrefix: "/backend",
		mounted:     true,
		admins:      adminsPresent,
		pending: []lagoon.MigrationRef{
			{Plugin: "acme.blog", ID: "0001_posts"},
			{Plugin: "acme.blog", ID: "0002_tags"},
			{Plugin: "summercms.cabana", ID: "0001"},
		},
		version: bonfire.Version{App: "v1.4.0", Framework: "v0.4.0"},
	})
}

// runSummaryProbe prints the summary through a command run with args and
// returns its output.
func runSummaryProbe(t *testing.T, f summaryFacts, args ...string) string {
	t.Helper()
	probe := []bonfire.Command{{Name: "probe:summary", Run: func(_ context.Context, _ bonfire.Input, out bonfire.Output) error {
		printSummary(out, f)
		return nil
	}}}
	var buf bytes.Buffer
	if err := bonfire.Call(context.Background(), probe, "probe:summary", args, &buf); err != nil {
		t.Fatal(err)
	}
	return buf.String()
}

// TestServeSummaryLines: the block at verbosity 0, the per-plugin lines at
// -v, nothing under -q, and never a DSN user or password; the database
// label for URL, keyword, socket, IPv6, empty and unparsable DSNs.
func TestServeSummaryLines(t *testing.T) {
	f := summaryFixture(t)
	plain := runSummaryProbe(t, f)
	for _, want := range []string{
		"SummerCMS acme v1.4.0 (framework v0.4.0)\n",
		"  Environment  staging\n",
		"  URL          http://127.0.0.1:8096/\n",
		"  Admin        http://127.0.0.1:8096/backend\n",
		"  Database     db.internal:5433/acme_prod\n",
		"  Migrations   3 pending — run bin/acme migrate\n",
		"  Plugins      2 (acme.user, acme.blog)\n",
		"  Queue        default (worker in serve)\n",
		"  Scheduler    in serve\n",
	} {
		if !strings.Contains(plain, want) {
			t.Errorf("verbosity 0 block lacks %q:\n%s", want, plain)
		}
	}
	if strings.Contains(plain, "requires") || strings.Contains(plain, "sign in") {
		t.Errorf("verbosity 0 block has per-plugin lines or an admin note with admins present:\n%s", plain)
	}

	verbose := runSummaryProbe(t, f, "-v")
	for _, want := range []string{
		"    acme.user  requires nothing; 0 pending migrations\n",
		"    acme.blog  requires acme.user; 2 pending migrations\n",
	} {
		if !strings.Contains(verbose, want) {
			t.Errorf("-v block lacks %q:\n%s", want, verbose)
		}
	}
	if quiet := runSummaryProbe(t, f, "-q"); quiet != "" {
		t.Errorf("-q printed the block:\n%s", quiet)
	}
	for _, out := range []string{plain, verbose} {
		for _, secret := range []string{"summer_user", "pa55-secret", "postgres://"} {
			if strings.Contains(out, secret) {
				t.Fatalf("summary leaks %q:\n%s", secret, out)
			}
		}
	}

	// The worker off, migrations up to date or unknown.
	off := buildFacts(summaryApp(t), factInputs{addr: "127.0.0.1:80", bin: "bin/acme", version: bonfire.Version{App: "devel"}})
	if off.URL != "http://127.0.0.1/" || !strings.Contains(off.Queue, "queue.work_in_serve is false") || !strings.Contains(off.Scheduler, "run schedule:run") {
		t.Errorf("worker off facts = %+v", off)
	}
	if m, warn := off.migrations(); m != "up to date" || warn {
		t.Errorf("no pending migrations = %q, %v", m, warn)
	}
	unknown := buildFacts(summaryApp(t), factInputs{addr: ":1", pendingErr: errors.New("no history")})
	if m, warn := unknown.migrations(); !strings.HasPrefix(m, "unknown") || !warn || unknown.Pending != -1 {
		t.Errorf("unreadable migrations = %q, %v, %d", m, warn, unknown.Pending)
	}

	for dsn, want := range map[string]string{
		"postgres://u:secret@db.example:5432/app":         "db.example:5432/app",
		"host=db port=6543 dbname=acme user=u password=p": "db:6543/acme",
		"host=/var/run/postgresql dbname=acme user=u":     "socket /var/run/postgresql:5432/acme",
		"postgres://u:p@[::1]:5432/acme":                  "[::1]:5432/acme",
		"":                                                "not configured",
		"postgres://u:p@[::1:bad":                         "configured",
	} {
		if got := lagoon.DatabaseLabel(dsn); got != want {
			t.Errorf("DatabaseLabel(%q) = %q, want %q", dsn, got, want)
		}
	}
}

// TestServeRecords: off a terminal serve logs one "startup summary" record
// with every fact and one record whose message is exactly "listening on
// <addr>"; with HideOnTTY (used only when the block printed) a styled
// console skips both while the daily file keeps them.
func TestServeRecords(t *testing.T) {
	f := summaryFixture(t)
	var logs bytes.Buffer
	logSummary(context.Background(), slog.New(slog.NewJSONHandler(&logs, nil)), f)
	var summary map[string]any
	var messages []string
	for _, line := range strings.Split(strings.TrimSpace(logs.String()), "\n") {
		var rec map[string]any
		if err := json.Unmarshal([]byte(line), &rec); err != nil {
			t.Fatal(err)
		}
		messages = append(messages, rec["msg"].(string))
		if rec["msg"] == summaryMessage {
			summary = rec
		}
	}
	if strings.Join(messages, "|") != "startup summary|listening on :8096" {
		t.Fatalf("records = %q, want the summary and the listening line (no admin note with admins present)", messages)
	}
	keys := []string{"app", "environment", "url", "admin", "database", "migrations_pending", "plugins", "plugin_ids", "queue", "scheduler", "mail", "cache", "realtime", "search"}
	for _, k := range keys {
		if _, ok := summary[k]; !ok {
			t.Errorf("summary record lacks %s: %v", k, summary)
		}
	}
	if summary["app"] != "SummerCMS acme v1.4.0 (framework v0.4.0)" || summary["url"] != "http://127.0.0.1:8096/" {
		t.Errorf("summary record = %v", summary)
	}

	// Admin notes follow, warnings at WARN.
	logs.Reset()
	noAdmins := f
	noAdmins.Admin, noAdmins.AdminNotes = adminStatus(f.URL, "/backend", true, adminsNone)
	logSummary(context.Background(), slog.New(slog.NewJSONHandler(&logs, nil)), noAdmins)
	if !strings.Contains(logs.String(), `"level":"WARN","msg":"no administrators yet`) {
		t.Errorf("admin warning record missing:\n%s", logs.String())
	}

	// HideOnTTY: hidden on a styled console, kept in the daily file.
	root := t.TempDir()
	cfg, err := compass.Open(compass.Options{Dir: t.TempDir(), Environ: []string{"SUMMER_LOG__CHANNELS__DAILY__LEVEL=info"}})
	if err != nil {
		t.Fatal(err)
	}
	var console syncBuffer
	t.Cleanup(diary.Reset)
	now := func() time.Time { return time.Date(2026, 10, 21, 12, 0, 0, 0, time.Local) }
	if err := diary.Setup(cfg, diary.Options{Stderr: &console, Root: root, Color: bonfire.ColorAlways, Environ: []string{}, Now: now}); err != nil {
		t.Fatal(err)
	}
	logSummary(diary.HideOnTTY(context.Background()), serveLog, f)
	if strings.Contains(console.String(), summaryMessage) || strings.Contains(console.String(), "listening on") {
		t.Errorf("styled console shows the hidden records:\n%s", console.String())
	}
	logSummary(context.Background(), serveLog, f)
	if !strings.Contains(console.String(), "listening on :8096") {
		t.Errorf("styled console lacks the records logged without HideOnTTY:\n%s", console.String())
	}
	if err := diary.Close(); err != nil {
		t.Fatal(err)
	}
	daily, err := os.ReadFile(filepath.Join(root, "storage", "logs", "summer-2026-10-21.log"))
	if err != nil {
		t.Fatal(err)
	}
	if n := strings.Count(string(daily), `"msg":"listening on :8096"`); n != 2 {
		t.Errorf("daily file has %d listening records, want 2 (hidden and shown):\n%s", n, daily)
	}
}

// shutdownServer serves handler through a requestCounter on a loopback
// listener and returns the server, the counter and the base URL.
func shutdownServer(t *testing.T, handler http.Handler) (*http.Server, *requestCounter, chan error, string) {
	t.Helper()
	ln, err := net.Listen("tcp", "127.0.0.1:0")
	if err != nil {
		t.Fatal(err)
	}
	counter := newRequestCounter(handler)
	srv := &http.Server{Handler: counter}
	errCh := make(chan error, 1)
	go func() { errCh <- srv.Serve(ln) }()
	return srv, counter, errCh, "http://" + ln.Addr().String()
}

// TestShutdownReportAborted: a request still running at the drain deadline
// is counted as aborted, the drain error is in the report and Err returns
// it, which makes serve exit 1.
func TestShutdownReportAborted(t *testing.T) {
	started, release := make(chan struct{}), make(chan struct{})
	srv, counter, errCh, base := shutdownServer(t, http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
		close(started)
		<-release
		w.WriteHeader(http.StatusOK)
	}))
	defer close(release)
	go func() {
		if resp, err := http.Get(base + "/slow"); err == nil {
			_ = resp.Body.Close()
		}
	}()
	<-started

	report := shutdownReport{Draining: counter.inFlight.Load()}
	ctx, cancel := context.WithTimeout(context.Background(), 50*time.Millisecond)
	defer cancel()
	if err := srv.Shutdown(ctx); err != nil {
		report.Aborted = counter.inFlight.Load()
		_ = srv.Close()
		report.Errors = append(report.Errors, fmt.Errorf("surf: drain requests: %w", err))
	}
	if err := <-errCh; err != http.ErrServerClosed {
		t.Fatalf("Serve returned %v", err)
	}
	report.Served = counter.served.Load()
	if report.Draining != 1 || report.Aborted != 1 || report.Drained() != 0 {
		t.Fatalf("report = %+v, want 1 draining, 1 aborted, 0 drained", report)
	}
	if err := report.Err(); err == nil || !errors.Is(err, context.DeadlineExceeded) {
		t.Fatalf("Err() = %v, want the drain deadline error", err)
	}
	var buf bytes.Buffer
	bonfire.Details(bonfire.NewOutput(strings.NewReader(""), &buf, &buf), "Shutdown report", report.details())
	for _, want := range []string{"0 drained, 1 aborted", "surf: drain requests: context deadline exceeded"} {
		if !strings.Contains(buf.String(), want) {
			t.Errorf("report lacks %q:\n%s", want, buf.String())
		}
	}
}

// TestServeGracefulNil: requests that finish within the deadline drain,
// the report counts them as served and drained, and Err is nil (exit 0).
func TestServeGracefulNil(t *testing.T) {
	started, release := make(chan struct{}), make(chan struct{})
	srv, counter, errCh, base := shutdownServer(t, http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
		if req.URL.Path == "/slow" {
			close(started)
			<-release
		}
		w.WriteHeader(http.StatusOK)
	}))
	for range 3 {
		resp, err := http.Get(base + "/fast")
		if err != nil {
			t.Fatal(err)
		}
		_ = resp.Body.Close()
	}
	slowDone := make(chan int, 1)
	go func() {
		resp, err := http.Get(base + "/slow")
		if err != nil {
			slowDone <- 0
			return
		}
		_ = resp.Body.Close()
		slowDone <- resp.StatusCode
	}()
	<-started

	report := shutdownReport{Draining: counter.inFlight.Load()}
	ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
	defer cancel()
	shut := make(chan error, 1)
	go func() { shut <- srv.Shutdown(ctx) }()
	close(release)
	if err := <-shut; err != nil {
		t.Fatalf("Shutdown: %v", err)
	}
	if err := <-errCh; err != http.ErrServerClosed {
		t.Fatalf("Serve returned %v", err)
	}
	if code := <-slowDone; code != http.StatusOK {
		t.Fatalf("the in-flight request got %d, want 200", code)
	}
	report.Served = counter.served.Load()
	if report.Draining != 1 || report.Aborted != 0 || report.Drained() != 1 || report.Served != 4 {
		t.Fatalf("report = %+v, want 1 draining, 1 drained, 4 served", report)
	}
	if err := report.Err(); err != nil {
		t.Fatalf("Err() = %v, want nil after a graceful stop", err)
	}
}

// TestRouteListJSON: route:list --json prints every route as a JSON array
// with method, pattern, plugin, middleware (never null) and raw, under -q
// too; the table and the admin line are left out.
func TestRouteListJSON(t *testing.T) {
	app := backpack.New(writeHTTPConfig(t, "body_limits:\n  default_bytes: 1024\n  upload_bytes: 1024\n"))
	cmd := RouteListCommand(app, []party.Plugin{blogPostsPlugin{}})
	for _, args := range [][]string{{"--json"}, {"--json", "-q"}} {
		var buf bytes.Buffer
		if err := bonfire.Call(context.Background(), []bonfire.Command{cmd}, "route:list", args, &buf); err != nil {
			t.Fatal(err)
		}
		var routes []map[string]any
		if err := json.Unmarshal(buf.Bytes(), &routes); err != nil {
			t.Fatalf("%v: not a JSON array: %v\n%s", args, err, buf.String())
		}
		if len(routes) != 1 {
			t.Fatalf("%v: routes = %v", args, routes)
		}
		r := routes[0]
		if r["method"] != "GET" || r["pattern"] != "/blog/posts/{id}" || r["plugin"] != "acme.blog" || r["raw"] != false {
			t.Errorf("%v: route = %v", args, r)
		}
		if mw, ok := r["middleware"].([]any); !ok || mw == nil {
			t.Errorf("%v: middleware is not an array: %v", args, r["middleware"])
		}
		if strings.Contains(buf.String(), "admin:") {
			t.Errorf("%v: JSON output carries the admin line:\n%s", args, buf.String())
		}
	}
}