Nomad server reports 0 allocations placed, but is wrong
- Dominant language
- Go
- Stars
- 17k
- Forks
- 2.1k
- Avg merge
- 1d 9h
- Merged PRs (30d)
- 105
Description
### Nomad version
0.12.1
### Operating system and Environment details
unix kernel 5.4.70; debian
### Issue
We are using the API to schedule a batch job. This batch job is new - nomad has never seen it before in its current state - i know this because it has randomly generated data inside of it - though there may have been a previous job with the same name.
The API returns the following Evaluation structure indicating "no allocations were placed"
```
2020-10-08T19:44:55.335Z: {ID:53563aed-6b2d-b607-4d17-27788affbb93 Priority:50 Type:batch TriggeredBy:job-register Namespace:default JobID:browser-131m9-10100-10199 JobModifyIndex:892821 NodeID: NodeModifyIndex:0 DeploymentID: Status:complete StatusDescription: Wait:0s WaitUntil:0001-01-01 00:00:00 +0000 UTC NextEval: PreviousEval: BlockedEval: FailedTGAllocs:map[] ClassEligibility:map[] EscapedComputedClass:false QuotaLimitReached: AnnotatePlan:false QueuedAllocations:map[browsers:0] SnapshotIndex:892828 CreateIndex:892821 ModifyIndex:892830 CreateTime:1602186294990126740 ModifyTime:1602186295310028622}
```
The nomad server DEBUG logs agree, saying it ignored 2 allocs and placed 0
```
2020-10-08T19:44:55.309Z [DEBUG] worker: dequeued evaluation: eval_id=53563aed-6b2d-b607-4d17-27788affbb93
2020-10-08T19:44:55.309Z [DEBUG] worker.batch_sched: setting eval status: eval_id=53563aed-6b2d-b607-4d17-27788affbb93 job_id=browser-131m9-10100-10199 namespace=default status=complete
2020-10-08T19:44:55.309Z [DEBUG] worker.batch_sched: reconciled current state with desired state: eval_id=53563aed-6b2d-b607-4d17-27788affbb93 job_id=browser-131m9-10100-10199 namespace=default results="Total changes: (place 0) (destructive 0) (inplace 0) (stop 0)
worker: dequeued evaluation: eval_id=53563aed-6b2d-b607-4d17-27788affbb93
worker.batch_sched: reconciled current state with desired state: eval_id=53563aed-6b2d-b607-4d17-27788affbb93 job_id=browser-131m9-10100-10199 namespace=default results="Total changes: (place 0) (destructive 0) (inplace 0) (stop 0) Desired Changes for "browsers": (place 0) (inplace 0) (destructive 0) (stop 0) (migrate 0) (ignore 2) (canary 0)"
worker.batch_sched: setting eval status: eval_id=53563aed-6b2d-b607-4d17-27788affbb93 job_id=browser-131m9-10100-10199 namespace=default status=complete
```
(these logs are confusing, some have timestamps some dont, and there seem to be 2 very similar ones for a few lines)
**Question 1: Why don't the logs or the API tell me WHY it wasn't placed? The current information is not very useful.**
HOWEVER, I could confirm in the nomad client logs that it WAS placed, through some trickery. There is no proof, but you will have to trust me that I can tell by piecing together, that this run was allocation `e8699e91-91e6-e610-6d8b-0f18ba4996dd`
**Question 2: Is there some way to correlate the eval with an allocation in the server or client logs? I cannot find any.**
```
client.alloc_runner.task_runner.task_hook.logmon: starting plugin: alloc_id=e8699e91-91e6-e610-6d8b-0f18ba4996dd task=browser path=/usr/bin/nomad args=[/usr/bin/nomad, logmon]
2020-10-08T19:44:55.313Z [DEBUG] client.alloc_runner.task_runner.task_hook.logmon: waiting for RPC address: alloc_id=e8699e91-91e6-e610-6d8b-0f18ba4996dd task=browser path=/usr/bin/nomad
```
it actually runs fine for a few minutes before it stops for some reason, but I dont care about that right now
**Main bug: What happened? Why does the server thing no alloc was placed, when in fact I can see that one was?**
### Possibly related, but maybe not
The node exited drain mode less than a second before this happened
```
020-10-08T19:44:54.909Z [DEBUG] http: request complete: method=PUT path=/v1/node/aec2d08a-c72c-1166-eaca-1fbb79a373a2/drain duration=36.181106ms
020-10-08T19:44:55.030Z [DEBUG] http: request complete: method=PUT path=/v1/node/aec2d08a-c72c-1166-eaca-1fbb79a373a2/eligibility duration=1.323457ms
```
Contributor guide
No contributing guide indexed for this repository
Research direction
Start with the reported evaluation structure and the server and client DEBUG logs, comparing their timestamps and evaluation and allocation IDs. Determine why the server reports ignored allocations and zero placements while the client shows allocation e8699e91-91e6-e610-6d8b-0f18ba4996dd, and document or improve the diagnostics so placement and correlation are clear.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go
- Domain
- distributed-systems
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100