Public source validation / validate (push) Failing after 3m8s
563 lines
19 KiB
Go
563 lines
19 KiB
Go
// Package workerruntime is the supervised background runtime of pulse-worker.
|
|
//
|
|
// It owns one scheduling loop that starts a small, fixed set of jobs on
|
|
// independent intervals. Every job is:
|
|
//
|
|
// - database-coordinated: a job run holds a lease row in job_runs keyed by
|
|
// (job_type, job_key, scheduled_at), so two workers never run the same unit
|
|
// of work twice and a worker that dies mid-run has its lease expire instead
|
|
// of blocking the job forever;
|
|
// - idempotent: the lease key is derived from the schedule, and each job's
|
|
// writes use natural-key conflict handling, so repeating a run is safe;
|
|
// - bounded: every run executes under a timeout and there is at most one
|
|
// in-flight run per job, which caps concurrency at the number of jobs;
|
|
// - isolated: a failing or panicking job is recorded, logged and counted, and
|
|
// never stops the other jobs or the process;
|
|
// - observable: per-job last run, duration and outcome are exposed through
|
|
// Status and persisted in job_runs, which is what internal/systemstatus
|
|
// reads instead of hardcoding "not recorded".
|
|
//
|
|
// The scheduling loop itself performs no blocking I/O: jobs run in their own
|
|
// goroutines, so the loop keeps completing iterations and writing the heartbeat
|
|
// file required by docs/operations/WORKER_AGENT_HEALTHCHECK_CONTRACT.md even
|
|
// while a job is stuck against a slow database or network target.
|
|
package workerruntime
|
|
|
|
import (
|
|
"context"
|
|
"errors"
|
|
"fmt"
|
|
"log/slog"
|
|
"os"
|
|
"regexp"
|
|
"sort"
|
|
"strings"
|
|
"sync"
|
|
"time"
|
|
|
|
"github.com/itworx/pulse/internal/systemstatus"
|
|
)
|
|
|
|
const (
|
|
// DefaultTick is the scheduling loop period. The healthcheck contract
|
|
// requires a completed iteration at least every 10 seconds; 5 seconds
|
|
// leaves room for a slow heartbeat write without going stale.
|
|
DefaultTick = 5 * time.Second
|
|
// MaxTick is the largest loop period the healthcheck contract tolerates.
|
|
MaxTick = 10 * time.Second
|
|
// DefaultDrainTimeout bounds how long shutdown waits for in-flight jobs.
|
|
DefaultDrainTimeout = 20 * time.Second
|
|
// DefaultHeartbeatFile matches the healthcheck script's default.
|
|
DefaultHeartbeatFile = "/tmp/healthy"
|
|
|
|
maxJobs = 16
|
|
maxErrorLength = 200
|
|
)
|
|
|
|
// Job outcome statuses recorded per run.
|
|
const (
|
|
StatusCompleted = "completed"
|
|
StatusFailed = "failed"
|
|
StatusSkipped = "skipped"
|
|
StatusDisabled = "disabled"
|
|
StatusRunning = "running"
|
|
)
|
|
|
|
var (
|
|
// ErrInvalidConfig reports a runtime or job definition outside safe bounds.
|
|
ErrInvalidConfig = errors.New("worker runtime configuration is invalid")
|
|
|
|
jobNamePattern = regexp.MustCompile(`^[a-z][a-z0-9-]{1,39}$`)
|
|
)
|
|
|
|
// Outcome is the bounded, structured result of one job run. Counts are recorded
|
|
// in job_runs so an operator can see what a run actually did.
|
|
type Outcome struct {
|
|
// Reason is a stable snake_case code explaining a skipped or disabled run.
|
|
Reason string
|
|
// Counts are small integer result counters, for example processed items.
|
|
Counts map[string]int64
|
|
// Skipped marks a run that intentionally did nothing, for example because
|
|
// another worker held the inner lease.
|
|
Skipped bool
|
|
// Disabled marks a run whose feature is not configured. It is reported as
|
|
// Disabled rather than Healthy so an unconfigured feature never looks green.
|
|
Disabled bool
|
|
}
|
|
|
|
// RunFunc executes one unit of work. It must respect the supplied context.
|
|
type RunFunc func(context.Context) (Outcome, error)
|
|
|
|
// Job is a scheduled unit of background work with a stable key.
|
|
type Job struct {
|
|
// Name is the stable job key. It becomes job_runs.job_key and, prefixed,
|
|
// job_runs.job_type, so it must never change casually.
|
|
Name string
|
|
// Component is the internal/systemstatus component this job reports to.
|
|
Component string
|
|
// Interval is how often the job becomes due. It also defines the lease
|
|
// window: two runs inside one interval are the same unit of work.
|
|
Interval time.Duration
|
|
// Timeout bounds a single run.
|
|
Timeout time.Duration
|
|
// Run performs the work.
|
|
Run RunFunc
|
|
}
|
|
|
|
func (j Job) validate() error {
|
|
if !jobNamePattern.MatchString(j.Name) {
|
|
return fmt.Errorf("%w: job name %q must be a bounded lowercase key", ErrInvalidConfig, j.Name)
|
|
}
|
|
switch j.Component {
|
|
case systemstatus.ComponentWorker, systemstatus.ComponentProbes, systemstatus.ComponentNotifications:
|
|
default:
|
|
return fmt.Errorf("%w: job %s has unknown component %q", ErrInvalidConfig, j.Name, j.Component)
|
|
}
|
|
if j.Interval < time.Second || j.Interval > time.Hour {
|
|
return fmt.Errorf("%w: job %s interval must be between 1s and 1h", ErrInvalidConfig, j.Name)
|
|
}
|
|
if j.Timeout < time.Second || j.Timeout > 5*time.Minute {
|
|
return fmt.Errorf("%w: job %s timeout must be between 1s and 5m", ErrInvalidConfig, j.Name)
|
|
}
|
|
if j.Run == nil {
|
|
return fmt.Errorf("%w: job %s has no run function", ErrInvalidConfig, j.Name)
|
|
}
|
|
return nil
|
|
}
|
|
|
|
// JobType is the job_runs.job_type value used for a job's scheduling lease.
|
|
func (j Job) JobType() string { return "worker-" + j.Name }
|
|
|
|
// MetricSink receives in-process counters and gauges. *observability.Registry
|
|
// satisfies it. The worker binds no network port by design, so these values are
|
|
// a process-local aid; the durable, operator-visible record is job_runs.
|
|
type MetricSink interface {
|
|
IncCounter(name string)
|
|
SetGauge(name string, value float64)
|
|
}
|
|
|
|
// Config configures the runtime loop.
|
|
type Config struct {
|
|
// Owner identifies this worker in job_runs.lease_owner.
|
|
Owner string
|
|
// Tick is the scheduling loop period; DefaultTick is used when zero.
|
|
Tick time.Duration
|
|
// HeartbeatFile is the path written after every completed loop iteration.
|
|
// DefaultHeartbeatFile is used when empty.
|
|
HeartbeatFile string
|
|
// DrainTimeout bounds graceful shutdown; DefaultDrainTimeout when zero.
|
|
DrainTimeout time.Duration
|
|
// Leases coordinates duplicate workers.
|
|
Leases LeaseStore
|
|
// Logger receives structured, secret-free job events.
|
|
Logger *slog.Logger
|
|
// Metrics optionally receives counters and gauges.
|
|
Metrics MetricSink
|
|
// Now is injectable for tests; time.Now is used when nil.
|
|
Now func() time.Time
|
|
}
|
|
|
|
// JobStatus is the observable state of one job.
|
|
type JobStatus struct {
|
|
Name string
|
|
Component string
|
|
Interval time.Duration
|
|
LastStartedAt time.Time
|
|
LastFinishedAt time.Time
|
|
LastSuccessAt time.Time
|
|
LastDuration time.Duration
|
|
LastStatus string
|
|
LastReason string
|
|
LastError string
|
|
Runs uint64
|
|
Successes uint64
|
|
Failures uint64
|
|
Skips uint64
|
|
Running bool
|
|
}
|
|
|
|
type jobState struct {
|
|
job Job
|
|
running bool
|
|
// lastAttemptAt is when the job last became due, which drives scheduling
|
|
// independently of how long the run itself took.
|
|
lastAttemptAt time.Time
|
|
status JobStatus
|
|
}
|
|
|
|
// Runtime supervises the scheduled jobs.
|
|
type Runtime struct {
|
|
config Config
|
|
mu sync.Mutex
|
|
states []*jobState
|
|
wg sync.WaitGroup
|
|
|
|
heartbeatMu sync.Mutex
|
|
heartbeatCount uint64
|
|
heartbeatAt time.Time
|
|
}
|
|
|
|
// New validates the configuration and job set and returns a runtime.
|
|
func New(config Config, jobs ...Job) (*Runtime, error) {
|
|
if strings.TrimSpace(config.Owner) == "" || len(config.Owner) > 120 {
|
|
return nil, fmt.Errorf("%w: owner must be 1-120 characters", ErrInvalidConfig)
|
|
}
|
|
if config.Leases == nil {
|
|
return nil, fmt.Errorf("%w: a lease store is required", ErrInvalidConfig)
|
|
}
|
|
if len(jobs) == 0 || len(jobs) > maxJobs {
|
|
return nil, fmt.Errorf("%w: between 1 and %d jobs are required", ErrInvalidConfig, maxJobs)
|
|
}
|
|
if config.Tick == 0 {
|
|
config.Tick = DefaultTick
|
|
}
|
|
// The floor only guards against a busy loop; the ceiling is what the
|
|
// healthcheck contract requires.
|
|
if config.Tick < 10*time.Millisecond || config.Tick > MaxTick {
|
|
return nil, fmt.Errorf("%w: tick must be between 10ms and %s", ErrInvalidConfig, MaxTick)
|
|
}
|
|
if config.DrainTimeout == 0 {
|
|
config.DrainTimeout = DefaultDrainTimeout
|
|
}
|
|
if config.DrainTimeout < time.Second || config.DrainTimeout > 2*time.Minute {
|
|
return nil, fmt.Errorf("%w: drain timeout must be between 1s and 2m", ErrInvalidConfig)
|
|
}
|
|
if config.HeartbeatFile == "" {
|
|
config.HeartbeatFile = DefaultHeartbeatFile
|
|
}
|
|
if config.Logger == nil {
|
|
config.Logger = slog.New(slog.NewJSONHandler(os.Stdout, nil))
|
|
}
|
|
if config.Now == nil {
|
|
config.Now = time.Now
|
|
}
|
|
seen := make(map[string]struct{}, len(jobs))
|
|
states := make([]*jobState, 0, len(jobs))
|
|
for _, job := range jobs {
|
|
if err := job.validate(); err != nil {
|
|
return nil, err
|
|
}
|
|
if _, duplicate := seen[job.Name]; duplicate {
|
|
return nil, fmt.Errorf("%w: duplicate job name %q", ErrInvalidConfig, job.Name)
|
|
}
|
|
seen[job.Name] = struct{}{}
|
|
states = append(states, &jobState{job: job, status: JobStatus{Name: job.Name, Component: job.Component, Interval: job.Interval}})
|
|
}
|
|
sort.Slice(states, func(i, j int) bool { return states[i].job.Name < states[j].job.Name })
|
|
return &Runtime{config: config, states: states}, nil
|
|
}
|
|
|
|
// Run drives the scheduling loop until ctx is cancelled, then drains in-flight
|
|
// jobs within the configured budget. It returns nil on a clean shutdown and an
|
|
// error only when shutdown could not complete within that budget.
|
|
func (r *Runtime) Run(ctx context.Context) error {
|
|
// The first heartbeat is written before the first blocking call so a slow
|
|
// but healthy cold start is not mistaken for a hang.
|
|
r.writeHeartbeat()
|
|
// In-flight jobs keep a context that outlives cancellation of ctx, so
|
|
// shutdown can drain them instead of tearing them down mid-transaction.
|
|
jobsCtx, cancelJobs := context.WithCancel(context.WithoutCancel(ctx))
|
|
defer cancelJobs()
|
|
timer := time.NewTimer(r.config.Tick)
|
|
defer timer.Stop()
|
|
for {
|
|
r.schedule(jobsCtx)
|
|
// The heartbeat marks a completed loop iteration, including an
|
|
// iteration in which nothing was due.
|
|
r.writeHeartbeat()
|
|
select {
|
|
case <-ctx.Done():
|
|
return r.drain(cancelJobs)
|
|
case <-timer.C:
|
|
timer.Reset(r.config.Tick)
|
|
}
|
|
}
|
|
}
|
|
|
|
// schedule starts every job that is due and not already running.
|
|
func (r *Runtime) schedule(jobsCtx context.Context) {
|
|
now := r.now()
|
|
r.mu.Lock()
|
|
due := make([]*jobState, 0, len(r.states))
|
|
for _, state := range r.states {
|
|
if state.running {
|
|
continue
|
|
}
|
|
if !state.lastAttemptAt.IsZero() && now.Sub(state.lastAttemptAt) < state.job.Interval {
|
|
continue
|
|
}
|
|
state.running = true
|
|
state.lastAttemptAt = now
|
|
state.status.Running = true
|
|
due = append(due, state)
|
|
}
|
|
r.mu.Unlock()
|
|
for _, state := range due {
|
|
r.wg.Add(1)
|
|
go func(state *jobState) {
|
|
defer r.wg.Done()
|
|
r.execute(jobsCtx, state)
|
|
}(state)
|
|
}
|
|
}
|
|
|
|
// drain stops scheduling and waits for in-flight jobs. Jobs that outlast the
|
|
// drain budget are cancelled so shutdown always terminates.
|
|
func (r *Runtime) drain(cancelJobs context.CancelFunc) error {
|
|
done := make(chan struct{})
|
|
go func() { r.wg.Wait(); close(done) }()
|
|
timer := time.NewTimer(r.config.DrainTimeout)
|
|
defer timer.Stop()
|
|
select {
|
|
case <-done:
|
|
r.config.Logger.Info("worker runtime drained", "in_flight", 0)
|
|
return nil
|
|
case <-timer.C:
|
|
}
|
|
r.config.Logger.Warn("worker runtime drain timeout, cancelling in-flight jobs", "drain_timeout", r.config.DrainTimeout.String())
|
|
cancelJobs()
|
|
grace := time.NewTimer(5 * time.Second)
|
|
defer grace.Stop()
|
|
select {
|
|
case <-done:
|
|
return nil
|
|
case <-grace.C:
|
|
return errors.New("worker runtime shutdown left cancelled jobs running")
|
|
}
|
|
}
|
|
|
|
// execute runs one job under its lease and timeout. It never returns an error:
|
|
// a failure is recorded, logged and counted so it stays visible without
|
|
// affecting any other job.
|
|
func (r *Runtime) execute(parent context.Context, state *jobState) {
|
|
job := state.job
|
|
started := r.now()
|
|
runCtx, cancel := context.WithTimeout(parent, job.Timeout)
|
|
defer cancel()
|
|
scheduledAt := started.Truncate(job.Interval)
|
|
lease, acquired, err := r.config.Leases.Acquire(runCtx, job.JobType(), job.Name, scheduledAt, r.config.Owner, started, r.leaseTTL(job))
|
|
if err != nil {
|
|
r.finish(state, started, StatusFailed, "lease_unavailable", err)
|
|
return
|
|
}
|
|
if !acquired {
|
|
// Another worker owns this window. That is coordination working, not a
|
|
// failure, so the previous successful outcome is retained.
|
|
r.finish(state, started, StatusSkipped, "lease_held_elsewhere", nil)
|
|
return
|
|
}
|
|
outcome, runErr := safeRun(runCtx, job)
|
|
status, reason := StatusCompleted, outcome.Reason
|
|
switch {
|
|
case runErr != nil:
|
|
status = StatusFailed
|
|
reason = classifyError(runCtx, runErr)
|
|
case outcome.Disabled:
|
|
status = StatusDisabled
|
|
reason = defaultReason(reason, "not_configured")
|
|
case outcome.Skipped:
|
|
status = StatusSkipped
|
|
reason = defaultReason(reason, "nothing_due")
|
|
}
|
|
// Lease completion must not be skipped because the run context expired, or
|
|
// the row would stay "running" until its lease expires.
|
|
completeCtx, completeCancel := context.WithTimeout(context.WithoutCancel(parent), 5*time.Second)
|
|
completeErr := r.config.Leases.Complete(completeCtx, lease, status, reason, outcome.Counts)
|
|
completeCancel()
|
|
if completeErr != nil && runErr == nil {
|
|
status = StatusFailed
|
|
reason = "lease_completion_failed"
|
|
runErr = completeErr
|
|
} else if completeErr != nil {
|
|
r.config.Logger.Error("worker job lease completion failed", "job", job.Name, "error", boundedError(completeErr))
|
|
}
|
|
r.finish(state, started, status, reason, runErr)
|
|
}
|
|
|
|
// safeRun converts a panicking job into an ordinary error so one broken job
|
|
// cannot take the process down.
|
|
func safeRun(ctx context.Context, job Job) (outcome Outcome, err error) {
|
|
defer func() {
|
|
if recovered := recover(); recovered != nil {
|
|
outcome = Outcome{}
|
|
err = fmt.Errorf("job %s panicked: %v", job.Name, recovered)
|
|
}
|
|
}()
|
|
return job.Run(ctx)
|
|
}
|
|
|
|
func (r *Runtime) finish(state *jobState, started time.Time, status, reason string, runErr error) {
|
|
finished := r.now()
|
|
duration := finished.Sub(started)
|
|
message := boundedError(runErr)
|
|
r.mu.Lock()
|
|
state.running = false
|
|
state.status.Running = false
|
|
state.status.LastStartedAt = started
|
|
state.status.LastFinishedAt = finished
|
|
state.status.LastDuration = duration
|
|
state.status.LastStatus = status
|
|
state.status.LastReason = reason
|
|
state.status.LastError = message
|
|
state.status.Runs++
|
|
switch status {
|
|
case StatusCompleted:
|
|
state.status.Successes++
|
|
state.status.LastSuccessAt = finished
|
|
case StatusFailed:
|
|
state.status.Failures++
|
|
case StatusSkipped, StatusDisabled:
|
|
state.status.Skips++
|
|
}
|
|
name := state.job.Name
|
|
component := state.job.Component
|
|
r.mu.Unlock()
|
|
r.record(name, status, duration)
|
|
attributes := []any{"job", name, "component", component, "status", status, "duration_ms", duration.Milliseconds()}
|
|
if reason != "" {
|
|
attributes = append(attributes, "reason", reason)
|
|
}
|
|
if status == StatusFailed {
|
|
r.config.Logger.Error("worker job failed", append(attributes, "error", message)...)
|
|
return
|
|
}
|
|
r.config.Logger.Info("worker job finished", attributes...)
|
|
}
|
|
|
|
func (r *Runtime) record(name, status string, duration time.Duration) {
|
|
if r.config.Metrics == nil {
|
|
return
|
|
}
|
|
r.config.Metrics.IncCounter("pulse_worker_job_runs_total_" + metricSuffix(name) + "_" + status)
|
|
r.config.Metrics.SetGauge("pulse_worker_job_duration_seconds_"+metricSuffix(name), duration.Seconds())
|
|
}
|
|
|
|
// Status returns a copy of every job's observable state.
|
|
func (r *Runtime) Status() []JobStatus {
|
|
r.mu.Lock()
|
|
defer r.mu.Unlock()
|
|
result := make([]JobStatus, 0, len(r.states))
|
|
for _, state := range r.states {
|
|
result = append(result, state.status)
|
|
}
|
|
return result
|
|
}
|
|
|
|
// JobHealth projects the in-process job status onto the system status model.
|
|
// A job that has never reported is deliberately omitted so the component keeps
|
|
// its "not recorded" Unknown state instead of being invented as healthy.
|
|
func (r *Runtime) JobHealth() []systemstatus.JobHealth {
|
|
statuses := r.Status()
|
|
health := make([]systemstatus.JobHealth, 0, len(statuses))
|
|
for _, status := range statuses {
|
|
if status.LastStatus == "" {
|
|
continue
|
|
}
|
|
health = append(health, systemstatus.JobHealth{
|
|
Component: status.Component, JobKey: status.Name, Status: mapStatus(status.LastStatus),
|
|
Reason: status.LastReason, ErrorCode: errorCodeFor(status), LastRunAt: status.LastFinishedAt,
|
|
LastSuccessAt: status.LastSuccessAt, Duration: status.LastDuration,
|
|
})
|
|
}
|
|
return health
|
|
}
|
|
|
|
// HeartbeatCount reports how many loop iterations completed. Tests use it to
|
|
// assert the heartbeat is driven by the loop rather than by a free-running
|
|
// timer.
|
|
func (r *Runtime) HeartbeatCount() uint64 {
|
|
r.heartbeatMu.Lock()
|
|
defer r.heartbeatMu.Unlock()
|
|
return r.heartbeatCount
|
|
}
|
|
|
|
// LastHeartbeat reports when the loop last wrote the heartbeat file.
|
|
func (r *Runtime) LastHeartbeat() time.Time {
|
|
r.heartbeatMu.Lock()
|
|
defer r.heartbeatMu.Unlock()
|
|
return r.heartbeatAt
|
|
}
|
|
|
|
// writeHeartbeat records loop liveness. A write failure is logged and the loop
|
|
// continues: the healthcheck notices sustained staleness on its own, and
|
|
// crashing on a tmpfs hiccup would be worse than reporting it.
|
|
func (r *Runtime) writeHeartbeat() {
|
|
now := r.now()
|
|
content := now.Format(time.RFC3339) + "\n"
|
|
if err := os.WriteFile(r.config.HeartbeatFile, []byte(content), 0o600); err != nil {
|
|
r.config.Logger.Error("worker heartbeat write failed", "path", r.config.HeartbeatFile, "error", boundedError(err))
|
|
return
|
|
}
|
|
r.heartbeatMu.Lock()
|
|
r.heartbeatCount++
|
|
r.heartbeatAt = now
|
|
r.heartbeatMu.Unlock()
|
|
}
|
|
|
|
func (r *Runtime) leaseTTL(job Job) time.Duration {
|
|
ttl := 2 * job.Timeout
|
|
if ttl < job.Interval {
|
|
ttl = job.Interval + job.Timeout
|
|
}
|
|
if ttl > 10*time.Minute {
|
|
ttl = 10 * time.Minute
|
|
}
|
|
return ttl
|
|
}
|
|
|
|
func (r *Runtime) now() time.Time { return r.config.Now().UTC() }
|
|
|
|
// mapStatus projects a recorded run status onto the system status vocabulary.
|
|
// A skipped run is reported as completed but never updates the last success, so
|
|
// a job that only ever skips can reach Unknown but never Healthy.
|
|
func mapStatus(status string) string {
|
|
switch status {
|
|
case StatusFailed:
|
|
return systemstatus.JobFailed
|
|
case StatusDisabled:
|
|
return systemstatus.JobDisabled
|
|
case StatusRunning:
|
|
return systemstatus.JobRunning
|
|
default:
|
|
return systemstatus.JobCompleted
|
|
}
|
|
}
|
|
|
|
func errorCodeFor(status JobStatus) string {
|
|
if status.LastStatus != StatusFailed {
|
|
return ""
|
|
}
|
|
return defaultReason(status.LastReason, "last_run_failed")
|
|
}
|
|
|
|
func defaultReason(reason, fallback string) string {
|
|
if strings.TrimSpace(reason) == "" {
|
|
return fallback
|
|
}
|
|
return reason
|
|
}
|
|
|
|
func classifyError(ctx context.Context, err error) string {
|
|
switch {
|
|
case errors.Is(err, context.DeadlineExceeded) || errors.Is(ctx.Err(), context.DeadlineExceeded):
|
|
return "timeout"
|
|
case errors.Is(err, context.Canceled) || errors.Is(ctx.Err(), context.Canceled):
|
|
return "canceled"
|
|
default:
|
|
return "run_failed"
|
|
}
|
|
}
|
|
|
|
func boundedError(err error) string {
|
|
if err == nil {
|
|
return ""
|
|
}
|
|
message := strings.ReplaceAll(strings.ReplaceAll(err.Error(), "\n", " "), "\r", " ")
|
|
if len(message) > maxErrorLength {
|
|
return message[:maxErrorLength]
|
|
}
|
|
return message
|
|
}
|
|
|
|
func metricSuffix(name string) string { return strings.ReplaceAll(name, "-", "_") }
|