PR review; naming in the comments, added comments for SQL, less verbo…

…se logging
coder · ibetitsmike · May 20, 2025 · Apr 1, 2025 · May 9, 2025 · May 9, 2025
commit a15bd1cff30f2916ffbfd07c5b34623e2e1a52fb
diff --git a/coderd/database/dbauthz/dbauthz.go b/coderd/database/dbauthz/dbauthz.go
@@ -3542,12 +3542,7 @@ func (q *querier) InsertPresetParameters(ctx context.Context, arg database.Inser
 
 func (q *querier) InsertProvisionerJob(ctx context.Context, arg database.InsertProvisionerJobParams) (database.ProvisionerJob, error) {
 	// TODO: Remove this once we have a proper rbac check for provisioner jobs.
-	// Currently ProvisionerJobs are not associated with a user, so we can't
-	// check for a user's permissions. We'd need to check for the associated workspace
-	// and verify ownership through that.
-	// if err := q.authorizeContext(ctx, policy.ActionCreate, rbac.ResourceProvisionerJobs); err != nil {
-	// 	return database.ProvisionerJob{}, err
-	// }
+	// Details in https://github.com/coder/coder/issues/16160
 	return q.db.InsertProvisionerJob(ctx, arg)
 }
 

diff --git a/coderd/database/dbmem/dbmem.go b/coderd/database/dbmem/dbmem.go
@@ -8,6 +8,7 @@
 	"errors"
 	"fmt"
 	"math"
+	"math/rand/v2"
 	"reflect"
 	"regexp"
 	"slices"
@@ -4883,11 +4884,14 @@
 				provisionerJob.Tags = maps.Clone(provisionerJob.Tags)
 				hungJobs = append(hungJobs, provisionerJob)
 				if len(hungJobs) >= int(maxJobs) {
-					return hungJobs, nil
+					break
 				}
 			}
 		}
 	}
+	rand.Shuffle(len(hungJobs), func(i, j int) {
+		hungJobs[i], hungJobs[j] = hungJobs[j], hungJobs[i]
+	})
 	return hungJobs, nil
 }
 
@@ -10955,8 +10959,8 @@
 		job.CompletedAt = arg.CompletedAt
 		job.Error = arg.Error
 		job.ErrorCode = arg.ErrorCode
-		job.JobStatus = provisionerJobStatus(job)
 		job.StartedAt = arg.StartedAt
+		job.JobStatus = provisionerJobStatus(job)
 		q.provisionerJobs[index] = job
 		return nil
 	}

diff --git a/coderd/database/queries/provisionerjobs.sql b/coderd/database/queries/provisionerjobs.sql
@@ -299,6 +299,7 @@ WHERE
 		AND started_at IS NOT NULL
 		AND completed_at IS NULL
 	)
+-- To avoid repeatedly attempting to reap the same jobs, we randomly order and limit to @max_jobs.
 ORDER BY random()
 LIMIT @max_jobs;
 

diff --git a/coderd/jobreaper/detector.go b/coderd/jobreaper/detector.go
@@ -20,12 +20,12 @@ import (
 )
 
 const (
-	// HungJobDuration is the duration of time since the last update to a job
-	// before it is considered hung.
+	// HungJobDuration is the duration of time since the last update
+	// to a RUNNING job before it is considered hung.
 	HungJobDuration = 5 * time.Minute
 
-	// PendingJobDuration is the duration of time since the last update to a job
-	// before it is considered hung.
+	// PendingJobDuration is the duration of time since last update
+	// to a PENDING job before it is considered dead.
 	PendingJobDuration = 30 * time.Minute
 
 	// HungJobExitTimeout is the duration of time that provisioners should allow
@@ -42,7 +42,7 @@ const (
 )
 
 // jobLogMessages are written to provisioner job logs when a job is reaped
-func jobLogMessages(reapType ReapType, threshold time.Duration) []string {
+func JobLogMessages(reapType ReapType, threshold time.Duration) []string {
 	return []string{
 		"",
 		"====================",
@@ -110,9 +110,9 @@ type Stats struct {
 	Error error
 }
 
-// New returns a new hang detector.
+// New returns a new job reaper.
 func New(ctx context.Context, db database.Store, pub pubsub.Pubsub, log slog.Logger, tick <-chan time.Time) *Detector {
-	//nolint:gocritic // Hang detector has a limited set of permissions.
+	//nolint:gocritic // Job reaper has a limited set of permissions.
 	ctx, cancel := context.WithCancel(dbauthz.AsJobReaper(ctx))
 	d := &Detector{
 		ctx:    ctx,
@@ -224,7 +224,7 @@ func (d *Detector) run(t time.Time) Stats {
 		err := reapJob(ctx, log, d.db, d.pubsub, job)
 		if err != nil {
 			if !(xerrors.As(err, &acquireLockError{}) || xerrors.As(err, &jobIneligibleError{})) {
-				log.Error(ctx, fmt.Sprintf("error forcefully terminating %s provisioner job", job.Type), slog.Error(err))
+				log.Error(ctx, "error forcefully terminating provisioner job", slog.F("type", job.Type), slog.Error(err))
 			}
 			continue
 		}
@@ -260,7 +260,8 @@ func reapJob(ctx context.Context, log slog.Logger, db database.Store, pub pubsub
 		}
 
 		log.Warn(
-			ctx, fmt.Sprintf("detected %s provisioner job, forcefully terminating", jobToReap.Type),
+			ctx, "forcefully terminating provisioner job",
+			"type", jobToReap.Type,
 			"threshold", jobToReap.Threshold,
 		)
 
@@ -291,7 +292,7 @@ func reapJob(ctx context.Context, log slog.Logger, db database.Store, pub pubsub
 			Output:    nil,
 		}
 		now := dbtime.Now()
-		for i, msg := range jobLogMessages(jobToReap.Type, jobToReap.Threshold) {
+		for i, msg := range JobLogMessages(jobToReap.Type, jobToReap.Threshold) {
 			// Set the created at in a way that ensures each message has
 			// a unique timestamp so they will be sorted correctly.
 			insertParams.CreatedAt = append(insertParams.CreatedAt, now.Add(time.Millisecond*time.Duration(i)))
@@ -325,7 +326,7 @@ func reapJob(ctx context.Context, log slog.Logger, db database.Store, pub pubsub
 				Valid: true,
 			},
 			Error: sql.NullString{
-				String: fmt.Sprintf("Coder: Build has been detected as %s for %.0f minutes and has been terminated by hang detector.", jobToReap.Type, jobToReap.Threshold.Minutes()),
+				String: fmt.Sprintf("Coder: Build has been detected as %s for %.0f minutes and has been terminated by the reaper.", jobToReap.Type, jobToReap.Threshold.Minutes()),
 				Valid:  true,
 			},
 			ErrorCode: sql.NullString{

diff --git a/coderd/jobreaper/detector_test.go b/coderd/jobreaper/detector_test.go
@@ -27,36 +27,6 @@ import (
 	"github.com/coder/coder/v2/testutil"
 )
 
-// jobType represents the type of job being reaped
-type jobType string
-
-const (
-	hungJobType    jobType = "hung"
-	pendingJobType jobType = "pending"
-)
-
-// jobLogMessages returns the messages to be written to provisioner job logs when a job is reaped
-func jobLogMessages(jobType jobType, threshold float64) []string {
-	return []string{
-		"",
-		"====================",
-		fmt.Sprintf("Coder: Build has been detected as %s for %.0f minutes and will be terminated.", jobType, threshold),
-		"====================",
-		"",
-	}
-}
-
-// reapParamsFromJob determines the type and threshold for a job being reaped
-func reapParamsFromJob(job database.ProvisionerJob) (jobType, float64) {
-	jobType := hungJobType
-	threshold := jobreaper.HungJobDuration.Minutes()
-	if !job.StartedAt.Valid {
-		jobType = pendingJobType
-		threshold = jobreaper.PendingJobDuration.Minutes()
-	}
-	return jobType, threshold
-}
-
 func TestMain(m *testing.M) {
 	goleak.VerifyTestMain(m, testutil.GoleakOptions...)
 }
@@ -972,8 +942,13 @@ func TestDetectorPushesLogs(t *testing.T) {
 				CreatedAfter: after,
 			})
 			require.NoError(t, err)
-			jobType, threshold := reapParamsFromJob(templateImportJob)
-			expectedLogs := jobLogMessages(jobType, threshold)
+			threshold := jobreaper.HungJobDuration
+			jobType := jobreaper.Hung
+			if templateImportJob.JobStatus == database.ProvisionerJobStatusPending {
+				threshold = jobreaper.PendingJobDuration
+				jobType = jobreaper.Pending
+			}
+			expectedLogs := jobreaper.JobLogMessages(jobType, threshold)
 			require.Len(t, logs, len(expectedLogs))
 			for i, log := range logs {
 				assert.Equal(t, database.LogLevelError, log.Level)

diff --git a/provisioner/terraform/serve.go b/provisioner/terraform/serve.go
@@ -39,9 +39,9 @@ type ServeOptions struct {
 	//
 	// This is a no-op on Windows where the process can't be interrupted.
 	//
-	// Default value: 3 minutes (reaper.HungJobExitTimeout). This value should
+	// Default value: 3 minutes (jobreaper.HungJobExitTimeout). This value should
 	// be kept less than the value that Coder uses to mark hung jobs as failed,
-	// which is 5 minutes (see reaper package).
+	// which is 5 minutes (see jobreaper package).
 	ExitTimeout time.Duration
 }