Files
summercms/modules/surf/serve_lifecycle_test.go
Jakub Zych c38dc1fe48 feat(surf): serve startup summary, shutdown report and http request log
- serve prints a startup summary on a terminal (version, environment, URL,
  admin, database host and name, pending migrations, plugins, drivers) and
  logs it as a 'startup summary' record plus 'listening on <addr>'
- on SIGINT/SIGTERM serve drains, prints and logs a shutdown report and
  returns nil (exit 0), or the drain errors (exit 1)
- the request log is on by default under diary component http with
  request_id; the route pattern, never the path, is logged
- lagoon.PendingMigrations, conga.Worker.Stats, diary.HideOnTTY,
  bonfire.IsTerminal and bonfire.Details back the summary and report
2026-10-21 12:59:07 +02:00

199 lines
5.4 KiB
Go

package surf
import (
"bytes"
"context"
"fmt"
"net"
"net/http"
"os"
"path/filepath"
"strings"
"sync"
"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/pact"
"git.golem15.com/golem15/summercms/modules/party"
"github.com/testcontainers/testcontainers-go"
"github.com/testcontainers/testcontainers-go/modules/postgres"
)
// lifecyclePlugin serves GET /probe/items/{id}.
type lifecyclePlugin struct{}
func (lifecyclePlugin) ID() string { return "acme.probe" }
func (lifecyclePlugin) Requires() []string { return nil }
func (lifecyclePlugin) Register(*backpack.App) error { return nil }
func (lifecyclePlugin) Boot(*backpack.App) error { return nil }
func (lifecyclePlugin) Routes(r pact.Router) error {
r.Get("/probe/items/{id}", func(w http.ResponseWriter, _ *http.Request) {
_, _ = w.Write([]byte("ok"))
})
return nil
}
// syncBuffer is a bytes.Buffer safe for the log writes of serve's
// goroutines and the test's reads.
type syncBuffer struct {
mu sync.Mutex
buf bytes.Buffer
}
func (b *syncBuffer) Write(p []byte) (int, error) {
b.mu.Lock()
defer b.mu.Unlock()
return b.buf.Write(p)
}
func (b *syncBuffer) String() string {
b.mu.Lock()
defer b.mu.Unlock()
return b.buf.String()
}
// TestServeLifecycle runs serve against Postgres: it binds, logs the
// startup summary and "listening on <addr>", logs a request by its route
// pattern under component http with its request id, and on cancellation
// drains, logs the shutdown report and returns nil (exit 0).
func TestServeLifecycle(t *testing.T) {
if testing.Short() {
t.Skip("requires testcontainers postgres")
}
ctx := t.Context()
ctr, err := postgres.Run(ctx, "postgres:16-alpine",
postgres.WithDatabase("surf"),
postgres.WithUsername("surf"),
postgres.WithPassword("surf-pass"),
postgres.BasicWaitStrategies(),
)
if err != nil {
t.Fatalf("testcontainers postgres: %v", err)
}
t.Cleanup(func() { _ = testcontainers.TerminateContainer(ctr) })
dsn, err := ctr.ConnectionString(ctx, "sslmode=disable")
if err != nil {
t.Fatal(err)
}
ln, err := net.Listen("tcp", "127.0.0.1:0")
if err != nil {
t.Fatal(err)
}
addr := ln.Addr().String()
_ = ln.Close()
dir := t.TempDir()
files := map[string]string{
"app.yaml": "name: probe\n",
"database.yaml": fmt.Sprintf("dsn: %q\n", dsn),
"storage.yaml": fmt.Sprintf("uploads:\n bucket_url: %q\n", "file://"+t.TempDir()),
}
for name, body := range files {
if err := os.WriteFile(filepath.Join(dir, name), []byte(body), 0o644); err != nil {
t.Fatal(err)
}
}
cfg, err := compass.Open(compass.Options{Dir: dir, Env: "development", Environ: []string{"SUMMER_ENV=development"}})
if err != nil {
t.Fatal(err)
}
app := backpack.New(cfg)
plugins := []party.Plugin{lifecyclePlugin{}}
// Migrate first so the in-process worker finds River's tables.
sqlDB, gdb, err := lagoon.Open(ctx, dsn)
if err != nil {
t.Fatal(err)
}
if err := lagoon.Migrate(gdb, plugins); err != nil {
t.Fatal(err)
}
_ = sqlDB.Close()
var logs syncBuffer
diary.Bootstrap(&logs, diary.Options{})
t.Cleanup(diary.Reset)
runCtx, cancel := context.WithCancel(ctx)
defer cancel()
done := make(chan error, 1)
var out bytes.Buffer
go func() {
done <- bonfire.Call(runCtx, []bonfire.Command{ServeCommand(app, plugins)}, "serve", []string{"--addr", addr}, &out)
}()
url := "http://" + addr + "/probe/items/secret-777"
var resp *http.Response
deadline := time.Now().Add(30 * time.Second)
for {
req, _ := http.NewRequest(http.MethodGet, url, nil)
req.Header.Set("X-Request-Id", "lifecycle-1")
resp, err = http.DefaultClient.Do(req)
if err == nil {
break
}
select {
case err := <-done:
t.Fatalf("serve returned before listening: %v\n%s", err, logs.String())
default:
}
if time.Now().After(deadline) {
t.Fatalf("serve did not listen on %s: %v\n%s", addr, err, logs.String())
}
time.Sleep(100 * time.Millisecond)
}
_ = resp.Body.Close()
if resp.StatusCode != http.StatusOK {
t.Fatalf("GET %s = %d", url, resp.StatusCode)
}
cancel()
select {
case err := <-done:
if err != nil {
t.Fatalf("serve returned %v after a graceful stop, want nil\n%s", err, logs.String())
}
case <-time.After(30 * time.Second):
t.Fatal("serve did not stop")
}
got := logs.String()
for _, want := range []string{
"listening on " + addr,
"msg=\"startup summary\"",
"migrations_pending=0",
"msg=\"shutdown report\"",
"served=1",
} {
if !strings.Contains(got, want) {
t.Errorf("logs lack %q:\n%s", want, got)
}
}
var requests []string
for _, line := range strings.Split(got, "\n") {
if strings.Contains(line, "msg=\"http request\"") {
requests = append(requests, line)
}
}
if len(requests) != 1 {
t.Fatalf("want one http request record, got %d:\n%s", len(requests), got)
}
for _, want := range []string{"component=http", "pattern=\"GET /probe/items/{id}\"", "request_id=lifecycle-1", "status=200"} {
if !strings.Contains(requests[0], want) {
t.Errorf("request record lacks %s: %s", want, requests[0])
}
}
if strings.Contains(got, "secret-777") {
t.Fatalf("the request path reached the logs:\n%s", got)
}
if strings.Contains(got, "surf-pass") {
t.Fatalf("the DSN password reached the logs:\n%s", got)
}
}