feat(conga,dev): worker and scheduler reports, summer dev runs serve

- queue:work and schedule:run print a startup summary and a shutdown report on a terminal, log them as records otherwise, and return nil after a clean stop - schedule:run --once ends with 'Ran N due entries (M failed)' - summer dev runs bin/<app> serve with the forwarded global options, reports through Output, stops the old server before starting the new one and prints a dev report on Ctrl+C (exit 0) - lagoon.DatabaseLabel describes a DSN without its secrets - Long help and examples for queue:work, schedule:run, dev, docs:serve
2026-10-21 13:04:27 +02:00
parent c38dc1fe48
commit 168d65cd1b
15 changed files with 319 additions and 81 deletions
--- a/modules/conga/README.md
+++ b/modules/conga/README.md
@@ -224,8 +224,8 @@ queues:

 | Command | Arguments and flags | Description |
 |---------|---------------------|-------------|
-| `queue:work` | `--queue <name>`, repeatable | Runs a job worker in the foreground on the named queues (default: every known queue) until SIGINT or SIGTERM, then stops it within 10 seconds. An unknown queue is an error that lists the known ones. |
-| `schedule:run` | `--once` (bare) | Without `--once`: runs a worker on the `scheduled` queue that carries every plugin's periodic jobs, prints `scheduler started` and runs until SIGINT or SIGTERM, then stops within 10 seconds. With `--once`: runs, in-process and without River, every entry due in the current minute of `app.timezone` (a daily entry at its hour and minute; `Every(d)` of a minute or less on every run, a longer one when the minutes since midnight are a multiple of `d`), printing `Running scheduled command: <command> <args>` per entry or `No scheduled commands are ready to run.`. An unregistered command prints a warning and is skipped. The exit status is the first command error, after every due entry ran. There is no overlap lock: two runs in one minute run the due entries twice, as Laravel does. System cron: `* * * * * cd /app && ./bin/app schedule:run --once`. |
+| `queue:work` | `--queue <name>`, repeatable | Runs a job worker in the foreground on the named queues (default: every known queue) until SIGINT or SIGTERM. It prints a startup summary on a terminal (environment, queues with their concurrency, database host, whether the `scheduled` queue runs here) and logs it as a `startup summary` record of component `queue` otherwise. On a signal it stops the worker within 10 seconds, prints and logs a `shutdown report` (jobs done, failed and handed back to the queue, uptime, stop errors) and exits 0, or 1 when the worker fails to stop. An unknown queue is an error that lists the known ones. |
+| `schedule:run` | `--once` (bare) | Without `--once`: runs a worker on the `scheduled` queue that carries every plugin's periodic jobs, prints a startup summary (entry count and the next due entry; a `startup summary` record of component `schedule` off a terminal) and runs until SIGINT or SIGTERM, then stops within 10 seconds, prints a shutdown report (scheduled commands run and failed, uptime) and exits 0. With `--once`: runs, in-process and without River, every entry due in the current minute of `app.timezone` (a daily entry at its hour and minute; `Every(d)` of a minute or less on every run, a longer one when the minutes since midnight are a multiple of `d`), printing `Running scheduled command: <command> <args>` per entry or `No scheduled commands are ready to run.`. An unregistered command prints a warning and is skipped. It ends with `Ran N due entries (M failed)`; the exit status is the first command error, after every due entry ran. There is no overlap lock: two runs in one minute run the due entries twice, as Laravel does. System cron: `* * * * * cd /app && ./bin/app schedule:run --once`. |
 | `queue:clear` | `[queue]` (default `default`) | Deletes the available, scheduled and retryable jobs of one queue in batches until none are left and prints `Cleared N jobs`. Running jobs are never touched. |

 ## Dependencies
--- a/modules/conga/commands.go
+++ b/modules/conga/commands.go
@@ -3,8 +3,10 @@ package conga
 import (
 	"context"
 	"fmt"
+	"log/slog"
 	"os"
 	"os/signal"
+	"slices"
 	"strconv"
 	"strings"
 	"syscall"
@@ -12,6 +14,7 @@ import (

 	"git.golem15.com/golem15/summercms/modules/backpack"
 	"git.golem15.com/golem15/summercms/modules/bonfire"
+	"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"
@@ -30,6 +33,23 @@ func RuntimeCommands(app *backpack.App, plugins []party.Plugin) []bonfire.Comman
 		{
 			Name:        "queue:work",
 			Description: "Run background job workers in the foreground",
+			Long: `Starts one River worker on the shared database pool for every known queue, or
+for the queues named with --queue, and runs jobs until Ctrl+C or SIGTERM. It
+prints a startup summary (environment, queues with their concurrency, database
+host, whether the scheduled queue runs here) on a terminal, and logs it as a
+"startup summary" record of component queue otherwise.
+
+On a signal it stops fetching jobs and waits up to 10 seconds for running
+ones; jobs still running then are cancelled and River retries them later.
+It prints a shutdown report (jobs done, failed, handed back to the queue,
+uptime) and exits 0, or 1 when the worker fails to stop.
+
+serve runs the same worker in-process unless queue.work_in_serve is false;
+run queue:work as a separate process when it is.`,
+			Examples: []bonfire.Example{
+				{Command: "queue:work", Description: "Work every known queue"},
+				{Command: "queue:work --queue mail --queue default", Description: "Work only the mail and default queues"},
+			},
 			Flags: []bonfire.Flag{{
 				Name:        "queue",
 				Description: "Queue to work (repeatable; default all known queues)",
@@ -44,6 +64,19 @@ func RuntimeCommands(app *backpack.App, plugins []party.Plugin) []bonfire.Comman
 		{
 			Name:        "schedule:run",
 			Description: "Run the scheduler in the foreground (or once for system cron)",
+			Long: `Without --once it runs a worker on the scheduled queue that also enqueues every
+plugin's schedule entries, prints a startup summary (entry count, the next
+due entry) and runs until Ctrl+C or SIGTERM, then prints a report (scheduled
+commands run and failed, uptime) and exits 0.
+
+With --once it runs the entries due in the current minute in app.timezone,
+one after another, ends with "Ran N due entries (M failed)" and exits 1 when
+any of them failed. Use it from system cron when no worker runs the
+scheduled queue.`,
+			Examples: []bonfire.Example{
+				{Command: "schedule:run", Description: "Run the scheduler in the foreground"},
+				{Command: "schedule:run --once", Description: "From cron, every minute: run the entries due now and exit"},
+			},
 			Flags: []bonfire.Flag{{
 				Name:        "once",
 				Description: "Run the entries due this minute and exit (for system cron)",
@@ -81,40 +114,151 @@ func RuntimeCommands(app *backpack.App, plugins []party.Plugin) []bonfire.Comman
 	}
 }

+// conga's console loggers: the startup summaries and shutdown reports of
+// queue:work and schedule:run.
+var (
+	queueLog    = diary.For("queue")
+	scheduleLog = diary.For("schedule")
+)
+
+// announce prints rows as a block on a terminal (not under -q) and logs them
+// as one record msg; the record is hidden from a terminal console when the
+// block was printed (diary.HideOnTTY).
+func announce(ctx context.Context, out bonfire.Output, log *slog.Logger, level slog.Level, title, msg string, rows []bonfire.Detail, attrs []slog.Attr) {
+	if bonfire.IsTerminal(out) && !bonfire.IsQuiet(out) {
+		bonfire.Details(out, title, rows)
+		ctx = diary.HideOnTTY(ctx)
+	}
+	log.LogAttrs(ctx, level, msg, attrs...)
+}
+
+// workerReport is the shutdown report of a worker: its job counters, the
+// uptime and the stop error.
+func workerReport(w *Worker, started time.Time, stopErr error) ([]bonfire.Detail, []slog.Attr, slog.Level) {
+	st := w.Stats()
+	errText := "none"
+	level := slog.LevelInfo
+	if stopErr != nil {
+		errText = stopErr.Error()
+		level = slog.LevelError
+	}
+	up := time.Since(started).Round(time.Second)
+	rows := []bonfire.Detail{
+		{Label: "Jobs", Value: fmt.Sprintf("%d done, %d failed, %d handed back to the queue", st.Done, st.Failed, st.HandedBack+st.InFlight), Warn: st.Failed > 0},
+		{Label: "Uptime", Value: up.String()},
+		{Label: "Errors", Value: errText, Warn: stopErr != nil},
+	}
+	attrs := []slog.Attr{
+		slog.Int64("jobs_done", st.Done),
+		slog.Int64("jobs_failed", st.Failed),
+		slog.Int64("jobs_handed_back", st.HandedBack+st.InFlight),
+		slog.Int64("uptime_ms", time.Since(started).Milliseconds()),
+	}
+	if stopErr != nil {
+		attrs = append(attrs, slog.String("errors", errText))
+	}
+	return rows, attrs, level
+}
+
+// queueList is "default (10), mail (2)": each queue with its MaxWorkers.
+func queueList(w *Worker) string {
+	parts := make([]string, 0, len(w.queues))
+	for _, q := range w.queues {
+		parts = append(parts, fmt.Sprintf("%s (%d)", q, w.concurrency[q]))
+	}
+	return strings.Join(parts, ", ")
+}
+
 func work(ctx context.Context, app *backpack.App, plugins []party.Plugin, queues []string, out bonfire.Output) error {
+	started := time.Now()
 	ctx, stop := signal.NotifyContext(ctx, os.Interrupt, syscall.SIGTERM)
 	defer stop()
 	w, err := StartWorker(ctx, app, plugins, WorkerOptions{Queues: queues})
 	if err != nil {
 		return err
 	}
-	out.Info("worker started on queues: " + strings.Join(w.Queues(), ", "))
+	scheduler := "not in this worker (the " + QueueScheduled + " queue is not selected)"
+	if slices.Contains(w.queues, QueueScheduled) {
+		scheduler = "included (the " + QueueScheduled + " queue runs scheduled commands)"
+	}
+	env := "unknown"
+	if app.Config != nil && app.Config.Environment() != "" {
+		env = app.Config.Environment()
+	}
+	db := lagoon.DatabaseLabel(lagoon.DSN(app.Config))
+	announce(ctx, out, queueLog, slog.LevelInfo, "Worker started", "startup summary", []bonfire.Detail{
+		{Label: "Environment", Value: env},
+		{Label: "Queues", Value: queueList(w)},
+		{Label: "Database", Value: db},
+		{Label: "Scheduler", Value: scheduler},
+	}, []slog.Attr{
+		slog.String("environment", env),
+		slog.String("queues", strings.Join(w.queues, ",")),
+		slog.String("database", db),
+		slog.String("scheduler", scheduler),
+	})
 	<-ctx.Done()
 	stopCtx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
 	defer cancel()
-	return w.Stop(stopCtx)
+	stopErr := w.Stop(stopCtx)
+	rows, attrs, level := workerReport(w, started, stopErr)
+	announce(context.WithoutCancel(ctx), out, queueLog, level, "Shutdown report", "shutdown report", rows, attrs)
+	return stopErr
+}
+
+// nextDue is the earliest next run of entries after now, and its command.
+func nextDue(entries []scheduleEntry, now time.Time) (time.Time, string) {
+	var at time.Time
+	var cmd string
+	for _, e := range entries {
+		if e.schedule == nil {
+			continue
+		}
+		if n := e.schedule.Next(now); at.IsZero() || n.Before(at) {
+			at, cmd = n, e.cmd.Command
+		}
+	}
+	return at, cmd
 }

 // runScheduler runs a scheduler-only worker (the scheduled queue plus every
 // plugin's periodic jobs) until SIGINT or SIGTERM.
 func runScheduler(ctx context.Context, app *backpack.App, plugins []party.Plugin, out bonfire.Output) error {
+	started := time.Now()
 	ctx, stop := signal.NotifyContext(ctx, os.Interrupt, syscall.SIGTERM)
 	defer stop()
 	w, err := StartWorker(ctx, app, plugins, WorkerOptions{Queues: []string{QueueScheduled}})
 	if err != nil {
 		return err
 	}
-	out.Info("scheduler started")
+	entries, _ := scheduleEntries(app, plugins)
+	next := "none"
+	if at, cmd := nextDue(entries, time.Now()); cmd != "" {
+		next = cmd + " at " + at.Format("2006-01-02 15:04 MST")
+	}
+	announce(ctx, out, scheduleLog, slog.LevelInfo, "Scheduler started", "startup summary", []bonfire.Detail{
+		{Label: "Entries", Value: fmt.Sprint(len(entries))},
+		{Label: "Next", Value: next},
+	}, []slog.Attr{
+		slog.Int("entries", len(entries)),
+		slog.String("next", next),
+	})
 	<-ctx.Done()
 	stopCtx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
 	defer cancel()
-	return w.Stop(stopCtx)
+	stopErr := w.Stop(stopCtx)
+	st := w.Stats()
+	rows, attrs, level := workerReport(w, started, stopErr)
+	rows[0] = bonfire.Detail{Label: "Runs", Value: fmt.Sprintf("%d scheduled commands (%d failed)", st.Done+st.Failed, st.Failed), Warn: st.Failed > 0}
+	announce(context.WithoutCancel(ctx), out, scheduleLog, level, "Shutdown report", "shutdown report", rows, attrs)
+	return stopErr
 }

 // scheduleRunOnce runs, without River, every schedule entry due in the
 // minute of now in app.timezone (Laravel schedule:run for system cron). An
 // unregistered command is warned about and skipped; the returned error is the
-// first command error, after every due entry ran.
+// first command error, after every due entry ran. It ends with "Ran N due
+// entries (M failed)".
 func scheduleRunOnce(ctx context.Context, app *backpack.App, plugins []party.Plugin, now time.Time, out bonfire.Output) error {
 	entries, err := scheduleEntries(app, plugins)
 	if err != nil {
@@ -138,16 +282,22 @@ func scheduleRunOnce(ctx context.Context, app *backpack.App, plugins []party.Plu
 	return withAppDB(ctx, app, func() error {
 		log := loggerFromApp(app)
 		var first error
+		ran, failed := 0, 0
 		for _, e := range due {
 			if _, ok := scheduledCatalog(app, log, e.cmd.Command); !ok {
 				out.Warning(fmt.Sprintf("Scheduled command %s is not registered; skipping", e.cmd.Command))
 				continue
 			}
 			out.Printf("Running scheduled command: %s\n", strings.Join(append([]string{e.cmd.Command}, e.cmd.Args...), " "))
-			if _, err := callScheduled(ctx, app, log, e.cmd.Command, e.cmd.Args, out); err != nil && first == nil {
-				first = err
+			ran++
+			if _, err := callScheduled(ctx, app, log, e.cmd.Command, e.cmd.Args, out); err != nil {
+				failed++
+				if first == nil {
+					first = err
+				}
 			}
 		}
+		out.Info(fmt.Sprintf("Ran %d due entries (%d failed)", ran, failed))
 		return first
 	})
 }
--- a/modules/conga/worker.go
+++ b/modules/conga/worker.go
@@ -40,6 +40,8 @@ type Worker struct {
 	listener *pgxpool.Pool
 	queues   []string
 	counters *workerCounters
+	// concurrency is each queue's MaxWorkers, for the startup summary.
+	concurrency map[string]int
 }

 // WorkerStats counts the job attempts a worker ran since it started.
@@ -195,7 +197,7 @@ func StartWorker(ctx context.Context, app *backpack.App, plugins []party.Plugin,
 	m.worker = client
 	m.schedule = table
 	m.counters.Store(counters)
-	return &Worker{m: m, client: client, listener: listener, queues: sortedQueueNames(queues), counters: counters}, nil
+	return &Worker{m: m, client: client, listener: listener, queues: sortedQueueNames(queues), counters: counters, concurrency: queues}, nil
 }

 // StartServeWorker starts the in-process worker of the serve command on