Files
seaweedfs/weed/admin/plugin/plugin_monitor_test.go
T
Chris LuandClaude Opus 5.5 5dfda3645e admin: count executor slots per job type and stop lanes waiting on capacity they cannot free (#12384)
* admin: count executor slots per job type, deduped against the heartbeat

per_worker_execution_concurrency is a per-job-type setting, but the
scheduler compared it against the worker's execution_slots_used, which
counts every job type. One s3_lifecycle job a worker reported running
after a reconnect made admin_script (per-worker 1) undispatchable on a
worker with three free slots. A reservation and the heartbeat entry for
the same job were also charged as two slots, so a per-worker limit of N
let N-1 jobs run.

Reservations now carry the job id and job type. The per-type limit is
checked against that type's work alone, the worker's slot total against
work of every type, and a heartbeat entry covered by a reservation is
counted once. Per-lane reservation pools go away: the per-type count is
what kept lanes from starving each other.

* admin: stop a lane waiting on executor capacity it cannot free

A queued job no executor could take was retried every backoff until
job_type_max_runtime ran out, up to 30 minutes, while the default lane
sat in executing and every other job type in it idled.

The dispatch loop now asks what holds the capacity. Slots held by the
lane's own jobs release when they complete, so it keeps waiting. Slots
held by other lanes or by work this admin never dispatched clear on a
schedule the lane has no view of, so the queued jobs are canceled at
once with a skipped_no_executor activity naming the worker, its slot
count and the job types holding it, and the next detection proposes
them again. A missing worker is waited for only the orphan grace.

* admin: cancel a job on its worker when the admin expires it

Expiring a job, by the stale sweep or by the operator's expire endpoint,
only failed the tracked record. The worker never heard about it and kept
running the job with its slot taken, so a job stuck in "starting" held a
slot for over a day and, with the old slot accounting, blocked a whole
lane.

Expiring a job now also sends the worker a cancel for it, so the slot
comes back on the next heartbeat.

* admin: count a completed job's heartbeat echo as its lane's own slot

The worker sends JobCompleted before the heartbeat that frees the slot, so
right after a dispatch goroutine releases its reservation the job still
shows in the worker's running work. That entry was counted as foreign, and
a lane with per-worker 1 gave up and canceled the rest of its queue after
the first job. A released reservation now stays for completedJobEchoGrace
and claims that heartbeat entry as the lane's own load.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

* admin: let the admin's own jobs claim slots a worker does not itemize

The Rust worker reports only a slot count, every 10s, and the Go worker
counts a slot one heartbeat before it lists the job. Those slots were
charged on top of the reservations behind them, and once a job completed
its stale count read as foreign work, so the lane gave up its queue.
Unitemized slots now go first to this admin's unlisted reservations and
recent completions; the rest are of unknown type and count against every
type's per-worker limit, not only the slot total.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

* admin: give up pinned jobs whose busy home a free worker cannot relieve

A job homed on a replica-host worker stays on that home while its queue is
shorter than LocalQueuePin, so a free remote worker cannot take it. The
outlook treated that free worker as a reason to wait, and a home held by
foreign work parked the lane for its whole window. A free worker now only
holds the wait for the orphan grace, after which the held homes decide.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

* admin: let a redispatched job's reservation replace its released one

A job the worker turns away for capacity is released, kept as an echo, and
queued again under the same id. Once the new attempt ran, both the echo and
the new reservation matched its heartbeat entry and it counted as two
slots. Reserving a job now drops what an earlier reservation of it left.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

* admin: credit a count-only slot to a completed job only until the next heartbeat

A released reservation claimed an unitemized slot for its full 30s grace,
so on a count-only heartbeat other work of another type was charged to the
completed job's type. A heartbeat that arrives after the release already
reflects the freed slot; from then on the slot is of unknown type.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

* admin: name unitemized slots in the no-capacity reason

holders() listed only the job types the worker itemized, so a worker with
named and count-only work read as "2/2 slots used by <type>".

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

* admin: keep the blocked clock running until a reservation succeeds

A popped job whose reservation then failed reset the clock before the
failure pushed it back, so pop-then-fail cycles never aged the block.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

* admin: resend an expiry cancel the worker did not receive

Expiring a job sends its worker one cancel. When the worker is
disconnected, or its outgoing buffer stays full past the send timeout,
that cancel is dropped. The record is already failed, so later sweeps
and expire calls skip it, and a worker that kept the job running (a
detached job across a reconnect, or a jammed stream) holds the slot
until the job ends on its own.

The admin now holds an undelivered expiry cancel and sends it again on
the worker's next heartbeat that still lists the job. It is forgotten
when that heartbeat no longer lists the job, and skipped when the job is
active again, since a new attempt reuses the job id.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

* admin: cancel an expired attempt by its request id

The expiry cancel named the job id, and a retry reuses it. The worker
keys its cancel funcs by both ids, so a cancel arriving after a retry
started on the same worker stopped the retry. The held resend also gave
up on any job that was active again, and the expired attempt's own late
progress marks the job running, so a worker that buffered progress
while disconnected kept the expired job.

The cancel now names the attempt's request id, as the other execution
cancels do, and the held resend no longer depends on the tracked state.
Only a cancel that can name nothing but the job id still skips a job
that is active again.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

* admin: ignore late reports from an attempt the admin already ended

Expiring a job now cancels it on its worker, and the worker answers
with its own JobCompleted for that attempt. That overwrote the expiry's
failure with the cancel error and logged a second run record under the
same run id. Late progress from the expired attempt likewise reopened
the record as running.

A progress update or completion whose request id names an attempt the
record already closed is now dropped after the dispatcher's waiter is
told. A retry runs under a new request id, so its reports still apply.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

---------

Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
2026-11-03 15:10:26 -08:00

904 lines
27 KiB
Go

package plugin
import (
"testing"
"time"
"github.com/seaweedfs/seaweedfs/weed/pb/plugin_pb"
"github.com/seaweedfs/seaweedfs/weed/pb/worker_pb"
"google.golang.org/protobuf/proto"
"google.golang.org/protobuf/types/known/timestamppb"
)
func TestPluginLoadsPersistedMonitorStateOnStart(t *testing.T) {
t.Parallel()
dataDir := t.TempDir()
store, err := NewConfigStore(dataDir)
if err != nil {
t.Fatalf("NewConfigStore: %v", err)
}
seedJobs := []TrackedJob{
{
JobID: "job-seeded",
JobType: "vacuum",
State: "running",
CreatedAt: timeToPtr(time.Now().UTC().Add(-2 * time.Minute)),
UpdatedAt: timeToPtr(time.Now().UTC().Add(-1 * time.Minute)),
},
}
seedActivities := []JobActivity{
{
JobID: "job-seeded",
JobType: "vacuum",
Source: "worker_progress",
Message: "seeded",
OccurredAt: timeToPtr(time.Now().UTC().Add(-30 * time.Second)),
},
}
if err := store.SaveTrackedJobs(seedJobs); err != nil {
t.Fatalf("SaveTrackedJobs: %v", err)
}
if err := store.SaveActivities(seedActivities); err != nil {
t.Fatalf("SaveActivities: %v", err)
}
pluginSvc, err := New(Options{DataDir: dataDir})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
gotJobs := pluginSvc.ListTrackedJobs("", "", 0)
if len(gotJobs) != 1 || gotJobs[0].JobID != "job-seeded" {
t.Fatalf("unexpected loaded jobs: %+v", gotJobs)
}
gotActivities := pluginSvc.ListActivities("", 0)
if len(gotActivities) != 1 || gotActivities[0].Message != "seeded" {
t.Fatalf("unexpected loaded activities: %+v", gotActivities)
}
}
func TestPluginPersistsMonitorStateAfterJobUpdates(t *testing.T) {
t.Parallel()
dataDir := t.TempDir()
pluginSvc, err := New(Options{DataDir: dataDir})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
job := &plugin_pb.JobSpec{
JobId: "job-persist",
JobType: "vacuum",
Summary: "persist test",
}
pluginSvc.trackExecutionStart("req-persist", "worker-a", job, 1)
pluginSvc.trackExecutionCompletion(&plugin_pb.JobCompleted{
RequestId: "req-persist",
JobId: "job-persist",
JobType: "vacuum",
Success: true,
Result: &plugin_pb.JobResult{Summary: "done"},
CompletedAt: timestamppb.New(time.Now().UTC()),
})
pluginSvc.Shutdown()
store, err := NewConfigStore(dataDir)
if err != nil {
t.Fatalf("NewConfigStore: %v", err)
}
trackedJobs, err := store.LoadTrackedJobs()
if err != nil {
t.Fatalf("LoadTrackedJobs: %v", err)
}
if len(trackedJobs) == 0 {
t.Fatalf("expected persisted tracked jobs")
}
found := false
for _, tracked := range trackedJobs {
if tracked.JobID == "job-persist" {
found = true
if tracked.State == "" {
t.Fatalf("persisted job state should not be empty")
}
}
}
if !found {
t.Fatalf("persisted tracked jobs missing job-persist")
}
activities, err := store.LoadActivities()
if err != nil {
t.Fatalf("LoadActivities: %v", err)
}
if len(activities) == 0 {
t.Fatalf("expected persisted activities")
}
}
func TestTrackExecutionQueuedMarksPendingState(t *testing.T) {
t.Parallel()
pluginSvc, err := New(Options{})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
pluginSvc.trackExecutionQueued(&plugin_pb.JobSpec{
JobId: "job-pending-1",
JobType: "vacuum",
DedupeKey: "vacuum:1",
Summary: "pending queue item",
})
jobs := pluginSvc.ListTrackedJobs("vacuum", "", 10)
if len(jobs) != 1 {
t.Fatalf("expected one tracked pending job, got=%d", len(jobs))
}
job := jobs[0]
if job.JobID != "job-pending-1" {
t.Fatalf("unexpected pending job id: %s", job.JobID)
}
if job.State != "job_state_pending" {
t.Fatalf("unexpected pending job state: %s", job.State)
}
if job.Stage != "queued" {
t.Fatalf("unexpected pending job stage: %s", job.Stage)
}
activities := pluginSvc.ListActivities("vacuum", 50)
found := false
for _, activity := range activities {
if activity.JobID == "job-pending-1" && activity.Stage == "queued" && activity.Source == "admin_scheduler" {
found = true
break
}
}
if !found {
t.Fatalf("expected queued activity for pending job")
}
}
func TestHandleJobProgressUpdateCarriesWorkerIDInActivities(t *testing.T) {
t.Parallel()
pluginSvc, err := New(Options{})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
job := &plugin_pb.JobSpec{
JobId: "job-progress-worker",
JobType: "vacuum",
}
pluginSvc.trackExecutionStart("req-progress-worker", "worker-a", job, 1)
pluginSvc.handleJobProgressUpdate("worker-a", &plugin_pb.JobProgressUpdate{
RequestId: "req-progress-worker",
JobId: "job-progress-worker",
JobType: "vacuum",
State: plugin_pb.JobState_JOB_STATE_RUNNING,
ProgressPercent: 42.0,
Stage: "scan",
Message: "in progress",
Activities: []*plugin_pb.ActivityEvent{
{
Source: plugin_pb.ActivitySource_ACTIVITY_SOURCE_EXECUTOR,
Message: "volume scanned",
Stage: "scan",
},
},
})
activities := pluginSvc.ListActivities("vacuum", 0)
if len(activities) == 0 {
t.Fatalf("expected activity entries")
}
foundProgress := false
foundEvent := false
for _, activity := range activities {
if activity.Source == "worker_progress" && activity.Message == "in progress" {
foundProgress = true
if activity.WorkerID != "worker-a" {
t.Fatalf("worker_progress activity worker mismatch: got=%q want=%q", activity.WorkerID, "worker-a")
}
}
if activity.Message == "volume scanned" {
foundEvent = true
if activity.WorkerID != "worker-a" {
t.Fatalf("worker event worker mismatch: got=%q want=%q", activity.WorkerID, "worker-a")
}
}
}
if !foundProgress {
t.Fatalf("expected worker_progress activity")
}
if !foundEvent {
t.Fatalf("expected worker activity event")
}
}
func TestHandleJobProgressUpdateWithoutJobIDTracksDetectionActivities(t *testing.T) {
t.Parallel()
pluginSvc, err := New(Options{})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
pluginSvc.handleJobProgressUpdate("worker-detector", &plugin_pb.JobProgressUpdate{
RequestId: "detect-req-1",
JobType: "vacuum",
State: plugin_pb.JobState_JOB_STATE_RUNNING,
Stage: "decision_summary",
Message: "VACUUM: No tasks created for 3 volumes",
Activities: []*plugin_pb.ActivityEvent{
{
Source: plugin_pb.ActivitySource_ACTIVITY_SOURCE_DETECTOR,
Stage: "decision_summary",
Message: "VACUUM: No tasks created for 3 volumes",
},
},
})
activities := pluginSvc.ListActivities("vacuum", 0)
if len(activities) == 0 {
t.Fatalf("expected activity entries")
}
foundDetectionProgress := false
foundDetectorEvent := false
for _, activity := range activities {
if activity.RequestID != "detect-req-1" {
continue
}
if activity.Source == "worker_detection" {
foundDetectionProgress = true
if activity.WorkerID != "worker-detector" {
t.Fatalf("worker_detection worker mismatch: got=%q want=%q", activity.WorkerID, "worker-detector")
}
}
if activity.Source == "activity_source_detector" {
foundDetectorEvent = true
if activity.WorkerID != "worker-detector" {
t.Fatalf("detector event worker mismatch: got=%q want=%q", activity.WorkerID, "worker-detector")
}
}
}
if !foundDetectionProgress {
t.Fatalf("expected worker_detection activity")
}
if !foundDetectorEvent {
t.Fatalf("expected detector activity event")
}
}
func TestHandleJobCompletedCarriesWorkerIDInActivitiesAndRunHistory(t *testing.T) {
t.Parallel()
pluginSvc, err := New(Options{})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
job := &plugin_pb.JobSpec{
JobId: "job-complete-worker",
JobType: "vacuum",
}
pluginSvc.trackExecutionStart("req-complete-worker", "worker-b", job, 1)
pluginSvc.handleJobCompleted(&plugin_pb.JobCompleted{
RequestId: "req-complete-worker",
JobId: "job-complete-worker",
JobType: "vacuum",
Success: true,
Activities: []*plugin_pb.ActivityEvent{
{
Source: plugin_pb.ActivitySource_ACTIVITY_SOURCE_EXECUTOR,
Message: "finalizer done",
Stage: "finalize",
},
},
CompletedAt: timestamppb.Now(),
})
pluginSvc.Shutdown()
activities := pluginSvc.ListActivities("vacuum", 0)
foundWorkerEvent := false
for _, activity := range activities {
if activity.Message == "finalizer done" {
foundWorkerEvent = true
if activity.WorkerID != "worker-b" {
t.Fatalf("worker completion event worker mismatch: got=%q want=%q", activity.WorkerID, "worker-b")
}
}
}
if !foundWorkerEvent {
t.Fatalf("expected completion worker event activity")
}
history, err := pluginSvc.LoadRunHistory("vacuum")
if err != nil {
t.Fatalf("LoadRunHistory: %v", err)
}
if history == nil || len(history.SuccessfulRuns) == 0 {
t.Fatalf("expected successful run history entry")
}
if history.SuccessfulRuns[0].WorkerID != "worker-b" {
t.Fatalf("run history worker mismatch: got=%q want=%q", history.SuccessfulRuns[0].WorkerID, "worker-b")
}
}
func TestTrackExecutionStartStoresJobPayloadDetails(t *testing.T) {
t.Parallel()
pluginSvc, err := New(Options{DataDir: t.TempDir()})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
pluginSvc.trackExecutionStart("req-payload", "worker-c", &plugin_pb.JobSpec{
JobId: "job-payload",
JobType: "vacuum",
Summary: "payload summary",
Detail: "payload detail",
Parameters: map[string]*plugin_pb.ConfigValue{
"volume_id": {
Kind: &plugin_pb.ConfigValue_Int64Value{Int64Value: 9},
},
},
Labels: map[string]string{
"source": "detector",
},
}, 2)
pluginSvc.Shutdown()
job, found := pluginSvc.GetTrackedJob("job-payload")
if !found || job == nil {
t.Fatalf("expected tracked job")
}
if job.Detail != "" {
t.Fatalf("expected in-memory tracked job detail to be stripped, got=%q", job.Detail)
}
if job.Attempt != 2 {
t.Fatalf("unexpected attempt: %d", job.Attempt)
}
if len(job.Labels) != 0 {
t.Fatalf("expected in-memory labels to be stripped, got=%+v", job.Labels)
}
if len(job.Parameters) != 0 {
t.Fatalf("expected in-memory parameters to be stripped, got=%+v", job.Parameters)
}
detail, found, err := pluginSvc.BuildJobDetail("job-payload", 100, 0)
if err != nil {
t.Fatalf("BuildJobDetail: %v", err)
}
if !found || detail == nil || detail.Job == nil {
t.Fatalf("expected disk-backed job detail")
}
if detail.Job.Detail != "payload detail" {
t.Fatalf("unexpected disk-backed detail: %q", detail.Job.Detail)
}
if got := detail.Job.Labels["source"]; got != "detector" {
t.Fatalf("unexpected disk-backed label source: %q", got)
}
if got, ok := detail.Job.Parameters["volume_id"].(map[string]interface{}); !ok || got["int64_value"] != "9" {
t.Fatalf("unexpected disk-backed parameters payload: %#v", detail.Job.Parameters["volume_id"])
}
}
func TestTrackExecutionStartStoresErasureCodingExecutionPlan(t *testing.T) {
t.Parallel()
pluginSvc, err := New(Options{DataDir: t.TempDir()})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
taskParams := &worker_pb.TaskParams{
TaskId: "task-ec-1",
VolumeId: 29,
Collection: "photos",
Sources: []*worker_pb.TaskSource{
{
Node: "source-a:8080",
DataCenter: "dc1",
Rack: "rack1",
VolumeId: 29,
DiskId: 5,
},
},
Targets: []*worker_pb.TaskTarget{
{
Node: "target-a:8080",
DataCenter: "dc1",
Rack: "rack2",
VolumeId: 29,
DiskId: 2,
ShardIds: []uint32{0, 10},
},
{
Node: "target-b:8080",
DataCenter: "dc2",
Rack: "rack3",
VolumeId: 29,
DiskId: 3,
ShardIds: []uint32{1, 11},
},
},
TaskParams: &worker_pb.TaskParams_ErasureCodingParams{
ErasureCodingParams: &worker_pb.ErasureCodingTaskParams{
DataShards: 10,
ParityShards: 4,
},
},
}
payload, err := proto.Marshal(taskParams)
if err != nil {
t.Fatalf("Marshal task params: %v", err)
}
pluginSvc.trackExecutionStart("req-ec-plan", "worker-ec", &plugin_pb.JobSpec{
JobId: "job-ec-plan",
JobType: "erasure_coding",
Parameters: map[string]*plugin_pb.ConfigValue{
"task_params_pb": {
Kind: &plugin_pb.ConfigValue_BytesValue{BytesValue: payload},
},
},
}, 1)
pluginSvc.Shutdown()
detail, found, err := pluginSvc.BuildJobDetail("job-ec-plan", 100, 0)
if err != nil {
t.Fatalf("BuildJobDetail: %v", err)
}
if !found || detail == nil || detail.Job == nil {
t.Fatalf("expected disk-backed detail")
}
rawPlan, ok := detail.Job.Parameters["execution_plan"]
if !ok {
t.Fatalf("expected execution_plan in parameters, got=%+v", detail.Job.Parameters)
}
plan, ok := rawPlan.(map[string]interface{})
if !ok {
t.Fatalf("unexpected execution_plan type: %T", rawPlan)
}
if plan["job_type"] != "erasure_coding" {
t.Fatalf("unexpected execution plan job type: %+v", plan["job_type"])
}
if plan["volume_id"] != float64(29) {
t.Fatalf("unexpected execution plan volume id: %+v", plan["volume_id"])
}
sourcesRaw, ok := plan["sources"].([]interface{})
if !ok || len(sourcesRaw) != 1 {
t.Fatalf("unexpected sources in execution plan: %+v", plan["sources"])
}
firstSource, ok := sourcesRaw[0].(map[string]interface{})
if !ok {
t.Fatalf("unexpected source payload: %+v", sourcesRaw[0])
}
if firstSource["disk_id"] != float64(5) {
t.Fatalf("unexpected source disk_id: %+v", firstSource["disk_id"])
}
targets, ok := plan["targets"].([]interface{})
if !ok || len(targets) != 2 {
t.Fatalf("unexpected targets in execution plan: %+v", plan["targets"])
}
firstTarget, ok := targets[0].(map[string]interface{})
if !ok {
t.Fatalf("unexpected target payload: %+v", targets[0])
}
if firstTarget["disk_id"] != float64(2) {
t.Fatalf("unexpected target disk_id: %+v", firstTarget["disk_id"])
}
assignments, ok := plan["shard_assignments"].([]interface{})
if !ok || len(assignments) != 4 {
t.Fatalf("unexpected shard assignments in execution plan: %+v", plan["shard_assignments"])
}
firstAssignment, ok := assignments[0].(map[string]interface{})
if !ok {
t.Fatalf("unexpected first assignment payload: %+v", assignments[0])
}
if firstAssignment["shard_id"] != float64(0) || firstAssignment["kind"] != "data" {
t.Fatalf("unexpected first assignment: %+v", firstAssignment)
}
if firstAssignment["target_disk_id"] != float64(2) {
t.Fatalf("unexpected first assignment target_disk_id: %+v", firstAssignment["target_disk_id"])
}
secondAssignment, ok := assignments[1].(map[string]interface{})
if !ok {
t.Fatalf("unexpected second assignment payload: %+v", assignments[1])
}
if secondAssignment["shard_id"] != float64(1) || secondAssignment["target_disk_id"] != float64(3) {
t.Fatalf("unexpected second assignment: %+v", secondAssignment)
}
}
func TestBuildJobDetailIncludesActivitiesAndRunRecord(t *testing.T) {
t.Parallel()
pluginSvc, err := New(Options{DataDir: t.TempDir()})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
pluginSvc.trackExecutionStart("req-detail", "worker-z", &plugin_pb.JobSpec{
JobId: "job-detail",
JobType: "vacuum",
Summary: "detail summary",
}, 1)
pluginSvc.handleJobProgressUpdate("worker-z", &plugin_pb.JobProgressUpdate{
RequestId: "req-detail",
JobId: "job-detail",
JobType: "vacuum",
State: plugin_pb.JobState_JOB_STATE_RUNNING,
Stage: "scan",
Message: "scanning volume",
})
pluginSvc.handleJobCompleted(&plugin_pb.JobCompleted{
RequestId: "req-detail",
JobId: "job-detail",
JobType: "vacuum",
Success: true,
Result: &plugin_pb.JobResult{
Summary: "done",
OutputValues: map[string]*plugin_pb.ConfigValue{
"affected": {
Kind: &plugin_pb.ConfigValue_Int64Value{Int64Value: 1},
},
},
},
CompletedAt: timestamppb.Now(),
})
pluginSvc.Shutdown()
detail, found, err := pluginSvc.BuildJobDetail("job-detail", 100, 5)
if err != nil {
t.Fatalf("BuildJobDetail error: %v", err)
}
if !found || detail == nil {
t.Fatalf("expected job detail")
}
if detail.Job == nil || detail.Job.JobID != "job-detail" {
t.Fatalf("unexpected job detail payload: %+v", detail.Job)
}
if detail.RunRecord == nil || detail.RunRecord.JobID != "job-detail" {
t.Fatalf("expected run record for job-detail, got=%+v", detail.RunRecord)
}
if len(detail.Activities) == 0 {
t.Fatalf("expected activity timeline entries")
}
if detail.Job.ResultOutputValues == nil {
t.Fatalf("expected result output values")
}
}
func TestBuildJobDetailLoadsFromDiskWhenMemoryCleared(t *testing.T) {
t.Parallel()
pluginSvc, err := New(Options{DataDir: t.TempDir()})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
pluginSvc.trackExecutionStart("req-disk", "worker-d", &plugin_pb.JobSpec{
JobId: "job-disk",
JobType: "vacuum",
Summary: "disk summary",
Detail: "disk detail payload",
}, 1)
pluginSvc.Shutdown()
pluginSvc.jobsMu.Lock()
pluginSvc.jobs = map[string]*TrackedJob{}
pluginSvc.jobsMu.Unlock()
pluginSvc.activitiesMu.Lock()
pluginSvc.activities = nil
pluginSvc.activitiesMu.Unlock()
detail, found, err := pluginSvc.BuildJobDetail("job-disk", 100, 0)
if err != nil {
t.Fatalf("BuildJobDetail: %v", err)
}
if !found || detail == nil || detail.Job == nil {
t.Fatalf("expected detail from disk")
}
if detail.Job.Detail != "disk detail payload" {
t.Fatalf("unexpected disk detail payload: %q", detail.Job.Detail)
}
}
func expectCancelFor(t *testing.T, session *streamSession, target string) {
t.Helper()
select {
case msg := <-session.outgoing:
cancel := msg.GetCancelRequest()
if cancel == nil || cancel.TargetId != target || cancel.TargetKind != plugin_pb.WorkKind_WORK_KIND_EXECUTION {
t.Fatalf("expected a cancel for %s, got %+v", target, msg)
}
case <-time.After(time.Second):
t.Fatalf("expected the worker to be told to stop %s", target)
}
}
// Expiring a job reaches the worker too: writing a job off in the admin
// while the worker keeps running it would leave the slot taken.
func TestExpireJobCancelsTheJobOnItsWorker(t *testing.T) {
t.Parallel()
pluginSvc, err := New(Options{})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
const workerID = "worker-1"
const jobID = "job-operator-expired"
session := &streamSession{workerID: workerID, outgoing: make(chan *plugin_pb.AdminToWorkerMessage, 8), done: make(chan struct{})}
pluginSvc.putSession(session)
pluginSvc.trackExecutionStart("req-operator-expired", workerID, &plugin_pb.JobSpec{JobId: jobID, JobType: "s3_lifecycle"}, 1)
updated, expired, err := pluginSvc.ExpireJob(jobID, "")
if err != nil || !expired {
t.Fatalf("ExpireJob: expired=%v err=%v", expired, err)
}
if updated == nil || updated.State != StateFailed {
t.Fatalf("expected the job to be failed, got %+v", updated)
}
expectCancelFor(t, session, "req-operator-expired")
}
// The stale sweep sends the same cancel, so the worker's slot comes back
// on its next heartbeat rather than staying taken by a job the admin
// already wrote off.
func TestExpireStaleJobsCancelsTheJobOnItsWorker(t *testing.T) {
t.Parallel()
pluginSvc, err := New(Options{})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
const workerID = "worker-1"
const jobID = "job-stale"
pluginSvc.registry.UpsertFromHello(&plugin_pb.WorkerHello{WorkerId: workerID})
pluginSvc.registry.UpdateHeartbeat(workerID, &plugin_pb.WorkerHeartbeat{WorkerId: workerID, ExecutionSlotsTotal: 4})
session := &streamSession{workerID: workerID, outgoing: make(chan *plugin_pb.AdminToWorkerMessage, 8), done: make(chan struct{})}
pluginSvc.putSession(session)
pluginSvc.trackExecutionStart("req-stale", workerID, &plugin_pb.JobSpec{JobId: jobID, JobType: "s3_lifecycle"}, 1)
startedAt := time.Now().UTC()
if n := pluginSvc.expireStaleJobs(startedAt.Add(defaultStaleActiveJobTimeout - time.Minute)); n != 0 {
t.Fatalf("expired %d jobs before the stale limit", n)
}
if n := pluginSvc.expireStaleJobs(startedAt.Add(defaultStaleActiveJobTimeout + time.Minute)); n != 1 {
t.Fatalf("expired %d jobs past the stale limit, want 1", n)
}
got, _ := pluginSvc.GetTrackedJob(jobID)
if got == nil || got.State != StateFailed {
t.Fatalf("expected the stale job to be failed, got %+v", got)
}
expectCancelFor(t, session, "req-stale")
}
func expectNoCancel(t *testing.T, session *streamSession) {
t.Helper()
select {
case msg := <-session.outgoing:
t.Fatalf("expected no message, got %+v", msg)
case <-time.After(100 * time.Millisecond):
}
}
func heartbeatListing(workerID string, jobIDs ...string) *plugin_pb.WorkerToAdminMessage {
heartbeat := &plugin_pb.WorkerHeartbeat{WorkerId: workerID, ExecutionSlotsTotal: 4}
for _, jobID := range jobIDs {
heartbeat.RunningWork = append(heartbeat.RunningWork, &plugin_pb.RunningWork{
WorkId: jobID,
Kind: plugin_pb.WorkKind_WORK_KIND_EXECUTION,
JobType: "s3_lifecycle",
State: plugin_pb.JobState_JOB_STATE_RUNNING,
})
}
return &plugin_pb.WorkerToAdminMessage{Body: &plugin_pb.WorkerToAdminMessage_Heartbeat{Heartbeat: heartbeat}}
}
// A cancel the worker could not receive when its job expired goes out with
// the worker's next heartbeat that still lists the job, once.
func TestExpireJobResendsAnUndeliveredCancelOnHeartbeat(t *testing.T) {
t.Parallel()
pluginSvc, err := New(Options{})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
const workerID = "worker-1"
const jobID = "job-expired-while-away"
pluginSvc.trackExecutionStart("req-away", workerID, &plugin_pb.JobSpec{JobId: jobID, JobType: "s3_lifecycle"}, 1)
if _, expired, err := pluginSvc.ExpireJob(jobID, ""); err != nil || !expired {
t.Fatalf("ExpireJob: expired=%v err=%v", expired, err)
}
pluginSvc.registry.UpsertFromHello(&plugin_pb.WorkerHello{WorkerId: workerID})
session := &streamSession{workerID: workerID, outgoing: make(chan *plugin_pb.AdminToWorkerMessage, 8), done: make(chan struct{})}
pluginSvc.putSession(session)
pluginSvc.handleWorkerMessage(session, heartbeatListing(workerID, jobID))
expectCancelFor(t, session, "req-away")
pluginSvc.handleWorkerMessage(session, heartbeatListing(workerID, jobID))
expectNoCancel(t, session)
}
// A held cancel names the expired attempt, so it neither stops a retry
// that reuses the job id nor gets lost when the expired attempt's late
// progress marks the job running again.
func TestUndeliveredCancelNamesTheExpiredAttempt(t *testing.T) {
t.Parallel()
pluginSvc, err := New(Options{})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
const workerID = "worker-1"
const retriedJobID = "job-retried"
const revivedJobID = "job-revived"
const stoppedJobID = "job-stopped"
pluginSvc.trackExecutionStart("req-retried-1", workerID, &plugin_pb.JobSpec{JobId: retriedJobID, JobType: "s3_lifecycle"}, 1)
pluginSvc.trackExecutionStart("req-revived", workerID, &plugin_pb.JobSpec{JobId: revivedJobID, JobType: "s3_lifecycle"}, 1)
pluginSvc.trackExecutionStart("req-stopped", workerID, &plugin_pb.JobSpec{JobId: stoppedJobID, JobType: "s3_lifecycle"}, 1)
for _, jobID := range []string{retriedJobID, revivedJobID, stoppedJobID} {
if _, expired, err := pluginSvc.ExpireJob(jobID, ""); err != nil || !expired {
t.Fatalf("ExpireJob(%s): expired=%v err=%v", jobID, expired, err)
}
}
pluginSvc.trackExecutionStart("req-retried-2", workerID, &plugin_pb.JobSpec{JobId: retriedJobID, JobType: "s3_lifecycle"}, 2)
pluginSvc.handleJobProgressUpdate(workerID, &plugin_pb.JobProgressUpdate{
JobId: revivedJobID,
JobType: "s3_lifecycle",
RequestId: "req-revived",
State: plugin_pb.JobState_JOB_STATE_RUNNING,
})
pluginSvc.registry.UpsertFromHello(&plugin_pb.WorkerHello{WorkerId: workerID})
session := &streamSession{workerID: workerID, outgoing: make(chan *plugin_pb.AdminToWorkerMessage, 8), done: make(chan struct{})}
pluginSvc.putSession(session)
pluginSvc.handleWorkerMessage(session, heartbeatListing(workerID, retriedJobID, revivedJobID))
targets := map[string]bool{}
for range 2 {
select {
case msg := <-session.outgoing:
targets[msg.GetCancelRequest().GetTargetId()] = true
case <-time.After(time.Second):
t.Fatalf("expected two cancels, got %v", targets)
}
}
if !targets["req-retried-1"] || !targets["req-revived"] {
t.Fatalf("expected cancels for the expired attempts, got %v", targets)
}
pluginSvc.handleWorkerMessage(session, heartbeatListing(workerID, stoppedJobID))
expectNoCancel(t, session)
}
// Without a request id the cancel can only name the job, so it is held
// back once the job is active again rather than stopping the new attempt.
func TestUndeliveredCancelByJobIDSkipsAnActiveJob(t *testing.T) {
t.Parallel()
pluginSvc, err := New(Options{})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
const workerID = "worker-1"
const jobID = "job-without-request"
pluginSvc.trackExecutionStart("", workerID, &plugin_pb.JobSpec{JobId: jobID, JobType: "s3_lifecycle"}, 1)
if _, expired, err := pluginSvc.ExpireJob(jobID, ""); err != nil || !expired {
t.Fatalf("ExpireJob: expired=%v err=%v", expired, err)
}
pluginSvc.trackExecutionStart("", workerID, &plugin_pb.JobSpec{JobId: jobID, JobType: "s3_lifecycle"}, 2)
pluginSvc.registry.UpsertFromHello(&plugin_pb.WorkerHello{WorkerId: workerID})
session := &streamSession{workerID: workerID, outgoing: make(chan *plugin_pb.AdminToWorkerMessage, 8), done: make(chan struct{})}
pluginSvc.putSession(session)
pluginSvc.handleWorkerMessage(session, heartbeatListing(workerID, jobID))
expectNoCancel(t, session)
}
// Once the admin expires an attempt, that attempt's late progress and its
// completion from the cancel neither reopen the record nor log a second run,
// while a retry under a new request id is still recorded.
func TestExpiredAttemptIgnoresItsLateReports(t *testing.T) {
t.Parallel()
pluginSvc, err := New(Options{})
if err != nil {
t.Fatalf("New: %v", err)
}
defer pluginSvc.Shutdown()
const workerID = "worker-1"
const jobID = "job-late-reports"
const jobType = "s3_lifecycle"
pluginSvc.trackExecutionStart("req-late-1", workerID, &plugin_pb.JobSpec{JobId: jobID, JobType: jobType}, 1)
if _, expired, err := pluginSvc.ExpireJob(jobID, "stuck"); err != nil || !expired {
t.Fatalf("ExpireJob: expired=%v err=%v", expired, err)
}
pluginSvc.handleJobProgressUpdate(workerID, &plugin_pb.JobProgressUpdate{
JobId: jobID,
JobType: jobType,
RequestId: "req-late-1",
State: plugin_pb.JobState_JOB_STATE_RUNNING,
Stage: "copying",
})
pluginSvc.handleJobCompleted(&plugin_pb.JobCompleted{
JobId: jobID,
JobType: jobType,
RequestId: "req-late-1",
ErrorMessage: "context canceled",
})
got, _ := pluginSvc.GetTrackedJob(jobID)
if got == nil || got.State != StateFailed || got.ErrorMessage != "stuck" {
t.Fatalf("expected the expiry to stand, got %+v", got)
}
history, err := pluginSvc.LoadRunHistory(jobType)
if err != nil {
t.Fatalf("LoadRunHistory: %v", err)
}
if len(history.ErrorRuns) != 1 || len(history.SuccessfulRuns) != 0 {
t.Fatalf("expected the expiry's run record only, got %+v", history)
}
pluginSvc.trackExecutionStart("req-late-2", workerID, &plugin_pb.JobSpec{JobId: jobID, JobType: jobType}, 2)
pluginSvc.handleJobCompleted(&plugin_pb.JobCompleted{
JobId: jobID,
JobType: jobType,
RequestId: "req-late-2",
Success: true,
})
got, _ = pluginSvc.GetTrackedJob(jobID)
if got == nil || got.State != StateSucceeded {
t.Fatalf("expected the retry to complete, got %+v", got)
}
history, err = pluginSvc.LoadRunHistory(jobType)
if err != nil {
t.Fatalf("LoadRunHistory: %v", err)
}
if len(history.ErrorRuns) != 1 || len(history.SuccessfulRuns) != 1 {
t.Fatalf("expected the retry's run to be recorded, got %+v", history)
}
}