I-003: job timeout reaper closes AwaitingCSR/AwaitingApproval gap

Add 11th always-on scheduler loop that transitions jobs stuck in
AwaitingCSR (default 24h TTL) or AwaitingApproval (default 168h TTL)
to Failed. I-001's retry loop then auto-promotes eligible Failed jobs
back to Pending. No new status enum, no schema migration.

- JobRepository.ListTimedOutAwaitingJobs with per-status cutoff WHERE
- JobService.ReapTimedOutJobs mirrors RetryFailedJobs structure
- Scheduler jobTimeoutLoop with atomic.Bool idempotency guard, 2m
  per-tick context, WaitGroup shutdown drain
- Config: CERTCTL_JOB_TIMEOUT_INTERVAL (10m), CERTCTL_JOB_AWAITING_CSR_TIMEOUT
  (24h), CERTCTL_JOB_AWAITING_APPROVAL_TIMEOUT (168h)
- Audit event per transition: actor=system, actorType=System,
  action=job_timeout, details={old_status, new_status, timeout_reason,
  age_hours}
- 14 new tests: 3 config, 7 service, 4 scheduler
This commit is contained in:
Shankar
2026-04-19 01:04:56 +00:00
parent 0d7d933e91
commit c17ea577e7
12 changed files with 1020 additions and 14 deletions
+76
View File
@@ -1,6 +1,7 @@
package service
import (
"time"
"context"
"errors"
"fmt"
@@ -236,6 +237,81 @@ func (s *JobService) RetryFailedJobs(ctx context.Context, maxRetries int) error
return nil
}
// ReapTimedOutJobs transitions jobs stuck in AwaitingCSR or AwaitingApproval
// to Failed if they've exceeded their TTL. I-001's retry loop then auto-promotes
// eligible Failed jobs back to Pending (closes coverage gap I-003).
func (s *JobService) ReapTimedOutJobs(ctx context.Context, csrTTL, approvalTTL time.Duration) error {
s.logger.Debug("reaping timed-out jobs", "csr_ttl", csrTTL, "approval_ttl", approvalTTL)
now := time.Now()
csrCutoff := now.Add(-csrTTL)
approvalCutoff := now.Add(-approvalTTL)
timedOutJobs, err := s.jobRepo.ListTimedOutAwaitingJobs(ctx, csrCutoff, approvalCutoff)
if err != nil {
return fmt.Errorf("failed to fetch timed-out jobs: %w", err)
}
var reaped int
for _, job := range timedOutJobs {
oldStatus := job.Status
var (
newErrMsg string
reason string
ttl time.Duration
)
switch job.Status {
case domain.JobStatusAwaitingCSR:
ttl = csrTTL
reason = "csr_timeout"
newErrMsg = fmt.Sprintf("timed out in %s after %s", oldStatus, csrTTL)
case domain.JobStatusAwaitingApproval:
ttl = approvalTTL
reason = "approval_timeout"
newErrMsg = fmt.Sprintf("timed out in %s after %s", oldStatus, approvalTTL)
default:
continue
}
_ = ttl
job.Status = domain.JobStatusFailed
job.LastError = &newErrMsg
if err := s.jobRepo.Update(ctx, job); err != nil {
s.logger.Error("failed to transition timed-out job",
"job_id", job.ID,
"old_status", oldStatus,
"error", err)
continue
}
if s.auditService != nil {
ageHours := time.Since(job.CreatedAt).Hours()
if auditErr := s.auditService.RecordEvent(ctx, "system", domain.ActorTypeSystem,
"job_timeout", "job", job.ID,
map[string]interface{}{
"old_status": string(oldStatus),
"new_status": string(domain.JobStatusFailed),
"timeout_reason": reason,
"age_hours": ageHours,
}); auditErr != nil {
s.logger.Error("failed to record job timeout audit event",
"job_id", job.ID,
"error", auditErr)
}
}
reaped++
}
s.logger.Info("job timeout reaper completed",
"reaped", reaped,
"total_timed_out", len(timedOutJobs))
return nil
}
// GetJobStatus returns the current status of a job.
func (s *JobService) GetJobStatus(ctx context.Context, jobID string) (*domain.Job, error) {
job, err := s.jobRepo.Get(ctx, jobID)
+355
View File
@@ -6,6 +6,8 @@ import (
"errors"
"log/slog"
"os"
"strings"
"sync"
"testing"
"time"
@@ -576,3 +578,356 @@ func TestJobService_RetryFailedJobs_NoAuditServiceOK(t *testing.T) {
t.Errorf("expected status Pending after retry, got %s", got)
}
}
// =============================================================================
// ReapTimedOutJobs Tests (I-003 coverage closure)
// =============================================================================
func TestJobService_ReapTimedOutJobs_AwaitingCSRTransitionsAndAudits(t *testing.T) {
ctx := context.Background()
now := time.Now()
job := &domain.Job{
ID: "job-reap-csr-1",
Type: domain.JobTypeRenewal,
CertificateID: "cert-001",
Status: domain.JobStatusAwaitingCSR,
CreatedAt: now.Add(-36 * time.Hour), // 36 hours old
ScheduledAt: now,
}
jobRepo := &mockJobRepo{
Jobs: map[string]*domain.Job{job.ID: job},
StatusUpdates: make(map[string]domain.JobStatus),
}
svc, auditRepo := newTestJobServiceWithAudit(jobRepo)
if err := svc.ReapTimedOutJobs(ctx, 24*time.Hour, 168*time.Hour); err != nil {
t.Fatalf("ReapTimedOutJobs failed: %v", err)
}
// Check the job was updated by retrieving from the mock's Jobs map
updatedJob := jobRepo.Jobs[job.ID]
if updatedJob.Status != domain.JobStatusFailed {
t.Fatalf("expected job %s status Failed after timeout, got %s", job.ID, updatedJob.Status)
}
// LastError should be set
if job.LastError == nil || !strings.Contains(*job.LastError, "timed out in AwaitingCSR after 24h") {
t.Errorf("expected LastError containing 'timed out in AwaitingCSR after 24h', got %v", job.LastError)
}
// Audit event should be recorded
if len(auditRepo.Events) != 1 {
t.Fatalf("expected 1 audit event, got %d", len(auditRepo.Events))
}
ev := auditRepo.Events[0]
if ev.Action != "job_timeout" {
t.Errorf("expected action job_timeout, got %s", ev.Action)
}
if ev.Actor != "system" {
t.Errorf("expected actor system, got %s", ev.Actor)
}
if ev.ActorType != domain.ActorTypeSystem {
t.Errorf("expected actor type System, got %s", ev.ActorType)
}
if ev.ResourceType != "job" {
t.Errorf("expected resource type job, got %s", ev.ResourceType)
}
if ev.ResourceID != job.ID {
t.Errorf("expected resource ID %s, got %s", job.ID, ev.ResourceID)
}
// Verify audit details
var details map[string]interface{}
if err := json.Unmarshal(ev.Details, &details); err != nil {
t.Fatalf("failed to decode audit event details: %v", err)
}
if got, want := details["old_status"], string(domain.JobStatusAwaitingCSR); got != want {
t.Errorf("expected details.old_status=%s, got %v", want, got)
}
if got, want := details["new_status"], string(domain.JobStatusFailed); got != want {
t.Errorf("expected details.new_status=%s, got %v", want, got)
}
if got, want := details["timeout_reason"], "csr_timeout"; got != want {
t.Errorf("expected details.timeout_reason=%s, got %v", want, got)
}
ageHours, ok := details["age_hours"].(float64)
if !ok {
t.Errorf("expected details.age_hours to be float64, got %T", details["age_hours"])
} else if ageHours < 35 {
t.Errorf("expected age_hours > 35, got %f", ageHours)
}
}
func TestJobService_ReapTimedOutJobs_AwaitingApprovalTransitionsAndAudits(t *testing.T) {
ctx := context.Background()
now := time.Now()
job := &domain.Job{
ID: "job-reap-approval-1",
Type: domain.JobTypeRenewal,
CertificateID: "cert-002",
Status: domain.JobStatusAwaitingApproval,
CreatedAt: now.Add(-200 * time.Hour), // 200 hours old
ScheduledAt: now,
}
jobRepo := &mockJobRepo{
Jobs: map[string]*domain.Job{job.ID: job},
StatusUpdates: make(map[string]domain.JobStatus),
}
svc, auditRepo := newTestJobServiceWithAudit(jobRepo)
if err := svc.ReapTimedOutJobs(ctx, 24*time.Hour, 168*time.Hour); err != nil {
t.Fatalf("ReapTimedOutJobs failed: %v", err)
}
// Check the job was updated
updatedJob := jobRepo.Jobs[job.ID]
if updatedJob.Status != domain.JobStatusFailed {
t.Fatalf("expected job %s status Failed after timeout, got %s", job.ID, updatedJob.Status)
}
// LastError should be set
if updatedJob.LastError == nil || !strings.Contains(*updatedJob.LastError, "timed out in AwaitingApproval after 168h") {
t.Errorf("expected LastError containing 'timed out in AwaitingApproval after 168h', got %v", updatedJob.LastError)
}
// Audit event details
if len(auditRepo.Events) != 1 {
t.Fatalf("expected 1 audit event, got %d", len(auditRepo.Events))
}
ev := auditRepo.Events[0]
var details map[string]interface{}
if err := json.Unmarshal(ev.Details, &details); err != nil {
t.Fatalf("failed to decode audit event details: %v", err)
}
if got, want := details["timeout_reason"], "approval_timeout"; got != want {
t.Errorf("expected details.timeout_reason=%s, got %v", want, got)
}
ageHours, ok := details["age_hours"].(float64)
if !ok {
t.Errorf("expected details.age_hours to be float64, got %T", details["age_hours"])
} else if ageHours < 199 {
t.Errorf("expected age_hours > 199, got %f", ageHours)
}
}
func TestJobService_ReapTimedOutJobs_SkipsJobsWithinTTL(t *testing.T) {
ctx := context.Background()
now := time.Now()
job := &domain.Job{
ID: "job-within-ttl",
Type: domain.JobTypeRenewal,
CertificateID: "cert-003",
Status: domain.JobStatusAwaitingCSR,
CreatedAt: now.Add(-1 * time.Hour), // Only 1 hour old (within 24h TTL)
ScheduledAt: now,
}
jobRepo := &mockJobRepo{
Jobs: map[string]*domain.Job{job.ID: job},
StatusUpdates: make(map[string]domain.JobStatus),
}
svc, auditRepo := newTestJobServiceWithAudit(jobRepo)
if err := svc.ReapTimedOutJobs(ctx, 24*time.Hour, 168*time.Hour); err != nil {
t.Fatalf("ReapTimedOutJobs failed: %v", err)
}
// Job should NOT transition (still AwaitingCSR)
if job.Status != domain.JobStatusAwaitingCSR {
t.Fatalf("expected job status to remain AwaitingCSR, got %s", job.Status)
}
// No audit events should be recorded
if len(auditRepo.Events) != 0 {
t.Fatalf("expected 0 audit events, got %d", len(auditRepo.Events))
}
}
func TestJobService_ReapTimedOutJobs_HandlesBothStatusesInOneSweep(t *testing.T) {
ctx := context.Background()
now := time.Now()
csr := &domain.Job{
ID: "job-sweep-csr",
Type: domain.JobTypeRenewal,
CertificateID: "cert-csr",
Status: domain.JobStatusAwaitingCSR,
CreatedAt: now.Add(-36 * time.Hour),
ScheduledAt: now,
}
approval := &domain.Job{
ID: "job-sweep-approval",
Type: domain.JobTypeRenewal,
CertificateID: "cert-approval",
Status: domain.JobStatusAwaitingApproval,
CreatedAt: now.Add(-200 * time.Hour),
ScheduledAt: now,
}
jobRepo := &mockJobRepo{
Jobs: map[string]*domain.Job{
csr.ID: csr,
approval.ID: approval,
},
StatusUpdates: make(map[string]domain.JobStatus),
}
svc, auditRepo := newTestJobServiceWithAudit(jobRepo)
if err := svc.ReapTimedOutJobs(ctx, 24*time.Hour, 168*time.Hour); err != nil {
t.Fatalf("ReapTimedOutJobs failed: %v", err)
}
// Both jobs should transition to Failed
csrUpdated := jobRepo.Jobs[csr.ID]
if csrUpdated.Status != domain.JobStatusFailed {
t.Fatalf("expected CSR job status Failed, got %s", csrUpdated.Status)
}
approvalUpdated := jobRepo.Jobs[approval.ID]
if approvalUpdated.Status != domain.JobStatusFailed {
t.Fatalf("expected approval job status Failed, got %s", approvalUpdated.Status)
}
// Two audit events should be recorded
if len(auditRepo.Events) != 2 {
t.Fatalf("expected 2 audit events, got %d", len(auditRepo.Events))
}
// Verify each event has the correct timeout_reason
for _, ev := range auditRepo.Events {
var details map[string]interface{}
if err := json.Unmarshal(ev.Details, &details); err != nil {
t.Fatalf("failed to decode details: %v", err)
}
if ev.ResourceID == csr.ID && details["timeout_reason"] != "csr_timeout" {
t.Errorf("CSR job: expected timeout_reason=csr_timeout, got %v", details["timeout_reason"])
}
if ev.ResourceID == approval.ID && details["timeout_reason"] != "approval_timeout" {
t.Errorf("approval job: expected timeout_reason=approval_timeout, got %v", details["timeout_reason"])
}
}
}
func TestJobService_ReapTimedOutJobs_NoAuditServiceOK(t *testing.T) {
ctx := context.Background()
now := time.Now()
job := &domain.Job{
ID: "job-no-audit",
Type: domain.JobTypeRenewal,
CertificateID: "cert-004",
Status: domain.JobStatusAwaitingCSR,
CreatedAt: now.Add(-36 * time.Hour),
ScheduledAt: now,
}
jobRepo := &mockJobRepo{
Jobs: map[string]*domain.Job{job.ID: job},
StatusUpdates: make(map[string]domain.JobStatus),
}
// Create service WITHOUT calling SetAuditService
svc := newTestJobService(jobRepo)
// Should not panic and should still transition the job
if err := svc.ReapTimedOutJobs(ctx, 24*time.Hour, 168*time.Hour); err != nil {
t.Fatalf("ReapTimedOutJobs failed without audit service: %v", err)
}
// Job should still transition to Failed
updatedJob := jobRepo.Jobs[job.ID]
if updatedJob.Status != domain.JobStatusFailed {
t.Fatalf("expected job status Failed without audit service, got %s", updatedJob.Status)
}
}
func TestJobService_ReapTimedOutJobs_ContinuesOnIndividualUpdateFailure(t *testing.T) {
ctx := context.Background()
now := time.Now()
jobA := &domain.Job{
ID: "job-fail-update-a",
Type: domain.JobTypeRenewal,
CertificateID: "cert-a",
Status: domain.JobStatusAwaitingCSR,
CreatedAt: now.Add(-36 * time.Hour),
ScheduledAt: now,
}
jobB := &domain.Job{
ID: "job-fail-update-b",
Type: domain.JobTypeRenewal,
CertificateID: "cert-b",
Status: domain.JobStatusAwaitingCSR,
CreatedAt: now.Add(-48 * time.Hour),
ScheduledAt: now,
}
jobRepo := &mockJobRepo{
Jobs: map[string]*domain.Job{
jobA.ID: jobA,
jobB.ID: jobB,
},
StatusUpdates: make(map[string]domain.JobStatus),
UpdateErrorByID: make(map[string]error),
UpdateErrorByIDMu: sync.Mutex{},
}
// Make Update fail only for jobA
jobRepo.UpdateErrorByIDMu.Lock()
jobRepo.UpdateErrorByID[jobA.ID] = errors.New("db connection lost")
jobRepo.UpdateErrorByIDMu.Unlock()
svc, auditRepo := newTestJobServiceWithAudit(jobRepo)
// Should not propagate individual Update errors
if err := svc.ReapTimedOutJobs(ctx, 24*time.Hour, 168*time.Hour); err != nil {
t.Fatalf("ReapTimedOutJobs should not propagate individual errors, got: %v", err)
}
// Both jobs have their status modified in memory (the service modifies before Update),
// so both will be Failed. What matters is that jobA's audit failed, so only jobB audited.
jobAAfter := jobRepo.Jobs[jobA.ID]
jobBAfter := jobRepo.Jobs[jobB.ID]
if jobAAfter.Status != domain.JobStatusFailed || jobBAfter.Status != domain.JobStatusFailed {
t.Fatalf("expected both jobs status Failed (modified before Update), got A=%s B=%s",
jobAAfter.Status, jobBAfter.Status)
}
// Only one audit event (from jobB, since jobA's Update failed and thus no audit for it)
if len(auditRepo.Events) != 1 {
t.Fatalf("expected 1 audit event (only jobB succeeded), got %d", len(auditRepo.Events))
}
if auditRepo.Events[0].ResourceID != jobB.ID {
t.Errorf("expected audit event for jobB, got event for %s", auditRepo.Events[0].ResourceID)
}
}
func TestJobService_ReapTimedOutJobs_RepoErrorPropagates(t *testing.T) {
ctx := context.Background()
jobRepo := &mockJobRepo{
Jobs: make(map[string]*domain.Job),
ListTimedOutErr: errors.New("database down"),
StatusUpdates: make(map[string]domain.JobStatus),
UpdateErrorByIDMu: sync.Mutex{},
}
svc, auditRepo := newTestJobServiceWithAudit(jobRepo)
err := svc.ReapTimedOutJobs(ctx, 24*time.Hour, 168*time.Hour)
if err == nil {
t.Fatalf("expected ReapTimedOutJobs to propagate repo error, got nil")
}
if !strings.Contains(err.Error(), "database down") {
t.Errorf("expected error to contain 'database down', got: %v", err)
}
// No audit events should be recorded when repo fails
if len(auditRepo.Events) != 0 {
t.Fatalf("expected 0 audit events after repo error, got %d", len(auditRepo.Events))
}
}
+45 -11
View File
@@ -156,17 +156,20 @@ func (m *mockCertRepo) AddCert(cert *domain.ManagedCertificate) {
// mockJobRepo is a test implementation of JobRepository
type mockJobRepo struct {
mu sync.Mutex
Jobs map[string]*domain.Job
StatusUpdates map[string]domain.JobStatus
CreateErr error
UpdateErr error
UpdateStatusErr error
GetErr error
ListErr error
ListByStatusErr error
DeleteErr error
Updated []*domain.Job
mu sync.Mutex
Jobs map[string]*domain.Job
StatusUpdates map[string]domain.JobStatus
CreateErr error
UpdateErr error
UpdateErrorByID map[string]error
UpdateErrorByIDMu sync.Mutex
UpdateStatusErr error
GetErr error
ListErr error
ListByStatusErr error
DeleteErr error
ListTimedOutErr error
Updated []*domain.Job
}
func (m *mockJobRepo) List(ctx context.Context) ([]*domain.Job, error) {
@@ -211,6 +214,13 @@ func (m *mockJobRepo) Update(ctx context.Context, job *domain.Job) error {
if m.UpdateErr != nil {
return m.UpdateErr
}
// Check per-ID error injection
m.UpdateErrorByIDMu.Lock()
idErr, ok := m.UpdateErrorByID[job.ID]
m.UpdateErrorByIDMu.Unlock()
if ok && idErr != nil {
return idErr
}
m.Jobs[job.ID] = job
m.Updated = append(m.Updated, job)
return nil
@@ -352,6 +362,30 @@ func (m *mockJobRepo) ClaimPendingByAgentID(ctx context.Context, agentID string)
return result, nil
}
// ListTimedOutAwaitingJobs returns jobs stuck in AwaitingCSR/AwaitingApproval past the
// respective cutoffs. I-003 coverage-gap closure.
func (m *mockJobRepo) ListTimedOutAwaitingJobs(ctx context.Context, csrCutoff, approvalCutoff time.Time) ([]*domain.Job, error) {
m.mu.Lock()
defer m.mu.Unlock()
if m.ListTimedOutErr != nil {
return nil, m.ListTimedOutErr
}
var jobs []*domain.Job
for _, j := range m.Jobs {
switch j.Status {
case domain.JobStatusAwaitingCSR:
if j.CreatedAt.Before(csrCutoff) {
jobs = append(jobs, j)
}
case domain.JobStatusAwaitingApproval:
if j.CreatedAt.Before(approvalCutoff) {
jobs = append(jobs, j)
}
}
}
return jobs, nil
}
func (m *mockJobRepo) AddJob(job *domain.Job) {
m.mu.Lock()
defer m.mu.Unlock()
+4
View File
@@ -77,6 +77,10 @@ func (m *mockVerificationJobRepo) ClaimPendingByAgentID(ctx context.Context, age
return nil, nil
}
func (m *mockVerificationJobRepo) ListTimedOutAwaitingJobs(ctx context.Context, csrCutoff, approvalCutoff time.Time) ([]*domain.Job, error) {
return nil, nil
}
// newVerificationTestService creates a VerificationService wired with test doubles.
func newVerificationTestService(jobs map[string]*domain.Job, jobRepoErr error) (*VerificationService, *mockVerificationJobRepo, *mockAuditRepo) {
jobRepo := &mockVerificationJobRepo{jobs: jobs, err: jobRepoErr}