hashicorp / hashicorp/nomad

Evaluation can transition from Canceled to Complete

Open
#17,375 2 comments 0 reactions 0 assignees View on GitHub
stage/accepted theme/scheduling type/bug
Dominant language
Go
Stars
17k
Forks
2.1k
Avg merge
1d 9h
Merged PRs (30d)
105

Description

### Nomad version
Output from `nomad version`
Nomad v1.5.5
BuildDate 2023-05-15T14:42:17Z
Revision 3e1c7055e0a2197cbda887522e57a562784d1a89

### Operating system and Environment details
Unix

### Issue
When an evaluation is blocked, and canceled by another completed evaluation, it can later get dequeued and processed, and transition to complete.

### Reproduction steps
The following are steps that are believed to have caused the issue, although reproduction is not guaranteed as the issue is inherently racy.

1. A job is registered, producing an evaluation E1. This evaluation fails to produce an allocation. A blocked evaluation E2 is created and this evaluation is marked as complete.
2. A node update causes another evaluation E3 to occur. E3 completes successfully, yielding an allocation. The completion of E3 causes all blocked evaluations on the job to be marked as canceled (https://github.com/hashicorp/nomad/blob/main/nomad/state/state_store.go#L3202), so E2 is marked “Canceled”.
3. Evaluation E2 gets dequeued and processed. Since there is already an evaluation, E2 results in a plan that is a no-op, and is marked “Complete” (see https://github.com/hashicorp/nomad/blob/main/scheduler/generic_sched.go#L311, https://github.com/hashicorp/nomad/blob/main/scheduler/generic_sched.go#L217).

#### Worked repro example
Setup.
```
# Setup – one client and one server.
## Server config
$ cat server_config.hcl
data_dir = "/tmp/nomad/server"
log_level = "DEBUG"

advertise {
http = "127.0.0.1"
rpc = "127.0.0.1"
serf = "127.0.0.1"
}

server {
enabled = true
bootstrap_expect = 1
}

./nomad agent -config server_config.hcl

## Client number one
$ cat client_config.hcl
data_dir = "/tmp/nomad/client-1"
log_level = "debug"

advertise {
http = "127.0.0.1"
rpc = "127.0.0.1"
serf = "127.0.0.1"
}

ports {
http = "9876"
rpc = "9875"
serf = "9874"
}

client {
enabled = true
servers = ["127.0.0.1"]
gc_max_allocs = 1
}

plugin "raw_exec" {
config {
enabled = true
}
}

./nomad agent -config client_config.hcl
```
We found that repro with one server and one worker is possible, but less likely than in a setup with two servers and one worker. This makes sense since the latency of servers plays a larger role with >1 server. That said, we show the one server repro here for brevity.

With a cluster of two clients and one scheduler, we can now start up a job.
```
$ cat job.hcl
job "example" {
datacenters = ["dc1"]
type = "batch"

group "test-group" {
task "test-task" {
driver = "raw_exec"

config {
command = "/usr/bin/sleep"
args = [ "inf" ]
}
}
}
}

./nomad run job.hcl
```

On one thread we start toggling eligibility of a node back and forth. This is to ensure that we get evaluations which are blocked:

`while true; do ./nomad node eligibility -disable 7070e554; sleep .1; ./nomad node eligibility -enable 7070e554; sleep .1; done`

In another thread we start aggressively updating the job which we started prior:

`while true; do sed -e "sx\"inf\"x$(date +\"%s\")x" job.hcl > /tmp/job.hcl ; ./nomad run /tmp/job.hcl; done`

We let this run a little bit and in another terminal we start observing the event stream of Nomad:

`curl -s -v -N http://127.0.0.1:4646/v1/event/stream?index=100&topic=Evaluation`

If we now look at the event stream we can find evaluations which went through the cycle of Creation -> Blocked -> Canceled -> Completed. Sample history of an evaluation included below (see at the end)

#### Expected Result
According to https://github.com/hashicorp/nomad/blob/v1.5.0/contributing/architecture-eval-states.md, “Canceled” is expected to be a terminal state, so the evaluation is expected to remain canceled.

#### Actual Result
The evaluation transitions to complete.

### Nomad Server logs (if appropriate)

I’ve attached some relevant events which were retrieved via the [Events API](https://developer.hashicorp.com/nomad/api-docs/events).
```
{"Events":[{"FilterKeys":["job-name",""],"Index":6602338,"Key":"76a9f6b7-1014-e92e-03da-246d9c0c0851","Namespace":"nomad-namespace","Payload":{"Evaluation":{"CreateIndex":6602338,"CreateTime":1683578207440384671,"FailedTGAllocs":{"workload":{"AllocationTime":4859,"ClassExhausted":null,"ClassFiltered":null,"CoalescedFailures":0,"ConstraintFiltered":null,"DimensionExhausted":null,"NodesAvailable":{"cluster-name":0},"NodesEvaluated":0,"NodesExhausted":0,"NodesFiltered":0,"QuotaExhausted":null,"ResourcesExhausted":null,"ScoreMetaData":null,"Scores":null}},"ID":"76a9f6b7-1014-e92e-03da-246d9c0c0851","JobID":"job-name","JobModifyIndex":6602332,"ModifyIndex":6602338,"ModifyTime":1683578207440384671,"Namespace":"nomad-namespace","PreviousEval":"8b283d97-df72-8fff-1dd1-8e1c6e6bb7e6","Priority":50,"SnapshotIndex":6602333,"Status":"blocked","StatusDescription":"created to place remaining allocations","TriggeredBy":"queued-allocs","Type":"batch"}},"Topic":"Evaluation","Type":"EvaluationUpdated"}],"Index":6602338}

# Eval 8b283d97 (the original job-register eval) marked complete (with BlockedEval 76a9f6b7)
{"Events":[{"FilterKeys":["job-name",""],"Index":6602339,"Key":"8b283d97-df72-8fff-1dd1-8e1c6e6bb7e6","Namespace":"nomad-namespace","Payload":{"Evaluation":{"BlockedEval":"76a9f6b7-1014-e92e-03da-246d9c0c0851","CreateIndex":6602332,"CreateTime":1683578207068006215,"FailedTGAllocs":{"workload":{"AllocationTime":4859,"ClassExhausted":null,"ClassFiltered":null,"CoalescedFailures":0,"ConstraintFiltered":null,"DimensionExhausted":null,"NodesAvailable":{"cluster-name":0},"NodesEvaluated":0,"NodesExhausted":0,"NodesFiltered":0,"QuotaExhausted":null,"ResourcesExhausted":null,"ScoreMetaData":null,"Scores":null}},"ID":"8b283d97-df72-8fff-1dd1-8e1c6e6bb7e6","JobID":"job-name","JobModifyIndex":6602332,"ModifyIndex":6602339,"ModifyTime":1683578207462048129,"Namespace":"nomad-namespace","Priority":50,"QueuedAllocations":{"workload":1},"SnapshotIndex":6602333,"Status":"complete","TriggeredBy":"job-register","Type":"batch"}},"Topic":"Evaluation","Type":"EvaluationUpdated"}],"Index":6602339}

# Eval 76a9f6b7 canceled, eval 4076e31f created.
{"Events":[
{"FilterKeys":["job-name",""],"Index":6602349,"Key":"76a9f6b7-1014-e92e-03da-246d9c0c0851","Namespace":"nomad-namespace","Payload":{"Evaluation":{"CreateIndex":6602338,"CreateTime":1683578207440384671,"FailedTGAllocs":{"workload":{"AllocationTime":4859,"ClassExhausted":null,"ClassFiltered":null,"CoalescedFailures":0,"ConstraintFiltered":null,"DimensionExhausted":null,"NodesAvailable":{"cluster-name":0},"NodesEvaluated":0,"NodesExhausted":0,"NodesFiltered":0,"QuotaExhausted":null,"ResourcesExhausted":null,"ScoreMetaData":null,"Scores":null}},"ID":"76a9f6b7-1014-e92e-03da-246d9c0c0851","JobID":"job-name","JobModifyIndex":6602332,"ModifyIndex":6602349,"ModifyTime":1683578207440384671,"Namespace":"nomad-namespace","PreviousEval":"8b283d97-df72-8fff-1dd1-8e1c6e6bb7e6","Priority":50,"SnapshotIndex":6602333,"Status":"canceled","StatusDescription":"evaluation \"76a9f6b7-1014-e92e-03da-246d9c0c0851\" successful","TriggeredBy":"queued-allocs","Type":"batch"}},"Topic":"Evaluation","Type":"EvaluationUpdated"},
{"FilterKeys":["job-name",""],"Index":6602349,"Key":"4076e31f-da38-2231-4d5c-afc4e72ccb19","Namespace":"nomad-namespace","Payload":{"Evaluation":{"CreateIndex":6602341,"CreateTime":1683578209911006082,"ID":"4076e31f-da38-2231-4d5c-afc4e72ccb19","JobID":"job-name","ModifyIndex":6602349,"ModifyTime":1683578210665337788,"Namespace":"nomad-namespace","NodeID":"50557555-4124-12a4-5a1e-32f8390d731a","NodeModifyIndex":6602340,"Priority":50,"QueuedAllocations":{"workload":0},"SnapshotIndex":6602345,"Status":"complete","TriggeredBy":"node-update","Type":"batch"}},"Topic":"Evaluation","Type":"EvaluationUpdated"}],"Index":6602349}

# 76a9f6b7 updated to complete.
{"Events":[{"FilterKeys":["job-name",""],"Index":6602351,"Key":"76a9f6b7-1014-e92e-03da-246d9c0c0851","Namespace":"nomad-namespace","Payload":{"Evaluation":{"CreateIndex":6602338,"CreateTime":1683578207440384671,"ID":"76a9f6b7-1014-e92e-03da-246d9c0c0851","JobID":"job-name","JobModifyIndex":6602332,"ModifyIndex":6602351,"ModifyTime":1683578210721774067,"Namespace":"nomad-namespace","PreviousEval":"8b283d97-df72-8fff-1dd1-8e1c6e6bb7e6","Priority":50,"QueuedAllocations":{"workload":0},"SnapshotIndex":6602349,"Status":"complete","TriggeredBy":"queued-allocs","Type":"batch"}},"Topic":"Evaluation","Type":"EvaluationUpdated"}],"Index":6602351}
```

Contributor guide

No contributing guide indexed for this repository

Research direction

Start with the cancellation logic in nomad/state/state_store.go and the evaluation processing paths referenced in scheduler/generic_sched.go. Read architecture-eval-states.md and trace the reproduction's blocked-to-canceled sequence. Done means a canceled evaluation remains in that terminal state and the regression is covered by the relevant scheduler or state-store test.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
backend, distributed-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Clearly specified
Newbie friendliness
45/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.