Nomad appears to fail to track deploy state of task group possibly leading to blocked drains

### Nomad version
Found on
```
$ nomad version
Nomad v0.9.7 (0e0eb07c53f99f54bcdb2e69aa8a9690a0597e7a)
```

Verified still exists on
```
$ nomad version
Nomad v0.10.4 (f750636ca68e17dcd2445c1ab9c5a34f9ac69345)
```

### Operating system and Environment details
Found on colocated hardware:
* 3x Nomad servers (v0.9.7 and v0.10.4)
* On the order of 100s of Nomad clients

Also repros in a small Vagrant setup
* 1x Nomad server (v0.10.4)
* 2 Nomad clients

### Issue
The behavior we're seeing is that running a `node drain` on a node running a particular job hangs _forever_. There appears to be nothing unique in the jobspec that would lead to this behavior but could totally be missing something here.

While digging into this we've noticed that Nomad appears to never move the desired state of these allocs from `run` to `stop`. What we _think_ is going on here is that Nomad is losing the deployment state of the task group that refuses to drain.

So for example with a job that works just fine we see the following state once deployed:
```
[root@nomad1 vagrant]# nomad job status test-nomad-job
ID = test-nomad-job
Name = test-nomad-job
Submit Date = 2020-03-20T20:18:09Z
Type = service
Priority = 50
Datacenters = vagrant-test
Namespace = default
Status = running
Periodic = false
Parameterized = false

Summary
Task Group Queued Starting Running Failed Complete Lost
test-nomad-job 0 0 1 0 0 0
test-nomad-job-tg2 0 0 1 0 0 0

Latest Deployment
ID = 5d145a64
Status = successful
Description = Deployment completed successfully

Deployed
Task Group Auto Revert Desired Placed Healthy Unhealthy Progress Deadline
test-nomad-job true 1 1 1 0 2020-03-20T20:34:32Z
test-nomad-job-tg2 true 1 1 1 0 2020-03-20T20:34:32Z

Allocations
ID Node ID Task Group Version Desired Status Created Modified
599e2343 4b8317e0 test-nomad-job-tg2 0 run running 2h26m ago 2h26m ago
5e6c1851 4b8317e0 test-nomad-job 0 run running 2h26m ago 2h26m ago

[root@nomad1 vagrant]# nomad deployment status 5d145a64
ID = 5d145a64
Job ID = test-nomad-job
Job Version = 0
Status = successful
Description = Deployment completed successfully

Deployed
Task Group Auto Revert Desired Placed Healthy Unhealthy Progress Deadline
test-nomad-job true 1 1 1 0 2020-03-20T20:34:32Z
test-nomad-job-tg2 true 1 1 1 0 2020-03-20T20:34:32Z
```

Notice that we get an entry for each of the task groups in this job in the 'Deployed' section.
When we issue a drain, it does so just fine. However when we look at the job that _doesn't_ drain:
```
[root@nomad1 vagrant]# nomad job status test-job
ID = test-job
Name = test-job
Submit Date = 2020-03-20T23:15:57Z
Type = service
Priority = 50
Datacenters = vagrant-test
Namespace = default
Status = running
Periodic = false
Parameterized = false

Summary
Task Group Queued Starting Running Failed Complete Lost
master 0 0 1 0 0 0
worker 0 0 3 0 0 0

Latest Deployment
ID = cd863ae2
Status = successful
Description = Deployment completed successfully

Deployed
Task Group Desired Placed Healthy Unhealthy Progress Deadline
master 1 1 1 0 2020-03-20T23:26:14Z

Allocations
ID Node ID Task Group Version Desired Status Created Modified
09f6eb0b 494d1cf3 master 0 run running 55s ago 37s ago
c15da0d0 494d1cf3 worker 0 run running 55s ago 53s ago
c5c6e3d8 494d1cf3 worker 0 run running 55s ago 53s ago
f9ed45c1 494d1cf3 worker 0 run running 55s ago 53s ago
[root@nomad1 vagrant]# nomad deployment status cd863ae2
ID = cd863ae2
Job ID = test-job
Job Version = 0
Status = successful
Description = Deployment completed successfully

Deployed
Task Group Desired Placed Healthy Unhealthy Progress Deadline
master 1 1 1 0 2020-03-20T23:26:14Z
[root@nomad1 vagrant]#
```
Notice that Nomad considers the deployment successfully completed, but the `worker` task groups aren't listed in this deployment. My wild-ass guess is that this is related to the drains failing.

Running the drain we see it successfully drains the allocations from the task group tracked in the deployment, but not allocations from he second task group that is lost. At this point, forcing the drain _does_ stop and migrate the missing task group.

### Reproduction steps
1. Submit the job
1. Wait for all allocations to start
1. Attempt to drain node with allocations from the task group not represented in the deployment
1. Nomad never puts any of the allocs into desired state of `stop` or attempts to migrate them

### Job file (if appropriate)
So this is about as minimal as I could get for the job spec, the original one is much more complex but this issue reproduces 100% of the time for me with the un-anonymized version. This job is running internal Docker images so repro with this exact job may be tough.
```
{
"Job": {
"Affinities": null,
"AllAtOnce": false,
"Datacenters": [
"vagrant-test"
],
"Dispatched": false,
"ID": "test-job",
"Migrate": null,
"Name": "test-job",
"Priority": 50,
"Reschedule": null,
"Spreads": [
{
"Attribute": "${node.unique.id}",
"SpreadTarget": null,
"Weight": 50
}
],
"TaskGroups": [
{
"Affinities": null,
"Constraints": [
{
"LTarget": "${attr.vault.version}",
"Operand": "version",
"RTarget": ">= 0.6.1"
},
{
"LTarget": "${attr.os.signals}",
"Operand": "set_contains",
"RTarget": "SIGINT"
}
],
"Count": 1,
"EphemeralDisk": {
"Migrate": false,
"SizeMB": 300,
"Sticky": false
},
"Meta": null,
"Migrate": {
"HealthCheck": "checks",
"HealthyDeadline": 300000000000,
"MaxParallel": 1,
"MinHealthyTime": 10000000000
},
"Name": "master",
"ReschedulePolicy": {
"Attempts": 0,
"Delay": 30000000000,
"DelayFunction": "exponential",
"Interval": 0,
"MaxDelay": 3600000000000,
"Unlimited": true
},
"RestartPolicy": {
"Attempts": 3,
"Delay": 15000000000,
"Interval": 900000000000,
"Mode": "delay"
},
"Spreads": null,
"Tasks": [
{
"Affinities": null,
"Artifacts": null,
"Config": {
"extra_hosts": [
"telegraf:127.0.0.1"
],
"force_pull": false,
"image": "some-docker-image:latest",
"hostname": "${attr.unique.hostname}",
"network_mode": "host",
"command": "",
"args": [
"REDACTED",
"REDACTED"
]
},
"Constraints": null,
"DispatchPayload": null,
"Driver": "docker",
"Env": {
"NOMAD_UNIQUE_HOSTNAME": "${attr.unique.hostname}"
},
"KillSignal": "",
"KillTimeout": 5000000000,
"Leader": false,
"LogConfig": {
"MaxFileSizeMB": 10,
"MaxFiles": 10
},
"Name": "test-job-master",
"Resources": {
"CPU": 300,
"Devices": null,
"DiskMB": 0,
"IOPS": 0,
"MemoryMB": 512,
"Networks": [
{
"CIDR": "",
"Device": "",
"DynamicPorts": [
{
"Label": "ui",
"Value": 0
},
{
"Label": "master",
"Value": 0
},
{
"Label": "api",
"Value": 0
},
{
"Label": "rest",
"Value": 0
},
{
"Label": "history",
"Value": 0
},
{
"Label": "driver",
"Value": 0
},
{
"Label": "blockManager",
"Value": 0
},
{
"Label": "app_prom",
"Value": 0
}
],
"IP": "",
"MBits": 10,
"ReservedPorts": null
}
]
},
"Services": [
{
"AddressMode": "auto",
"CanaryTags": null,
"CheckRestart": null,
"Checks": [
{
"AddressMode": "",
"Args": null,
"CheckRestart": {
"Grace": 90000000000,
"IgnoreWarnings": true,
"Limit": 3
},
"Command": "",
"GRPCService": "",
"GRPCUseTLS": false,
"Header": null,
"Id": "",
"InitialStatus": "",
"Interval": 10000000000,
"Method": "",
"Name": "test-job-master",
"Path": "/",
"PortLabel": "ui",
"Protocol": "",
"TLSSkipVerify": false,
"Timeout": 2000000000,
"Type": "http"
}
],
"Id": "",
"Name": "test-job-master",
"PortLabel": "master",
"Tags": [
"test-job-master"
]
},
{
"AddressMode": "auto",
"CanaryTags": null,
"CheckRestart": null,
"Checks": [
{
"AddressMode": "",
"Args": null,
"CheckRestart": null,
"Command": "",
"GRPCService": "",
"GRPCUseTLS": false,
"Header": null,
"Id": "",
"InitialStatus": "",
"Interval": 10000000000,
"Method": "",
"Name": "test-job-master-ui",
"Path": "",
"PortLabel": "ui",
"Protocol": "",
"TLSSkipVerify": false,
"Timeout": 2000000000,
"Type": "tcp"
}
],
"Id": "",
"Name": "test-job-master-ui",
"PortLabel": "ui",
"Tags": [
"test-job-master-ui"
]
},
{
"AddressMode": "auto",
"CanaryTags": null,
"CheckRestart": null,
"Checks": [
{
"AddressMode": "",
"Args": null,
"CheckRestart": null,
"Command": "",
"GRPCService": "",
"GRPCUseTLS": false,
"Header": null,
"Id": "",
"InitialStatus": "",
"Interval": 10000000000,
"Method": "",
"Name": "test-job-master-api",
"Path": "",
"PortLabel": "rest",
"Protocol": "",
"TLSSkipVerify": false,
"Timeout": 2000000000,
"Type": "tcp"
}
],
"Id": "",
"Name": "test-job-master-api",
"PortLabel": "rest",
"Tags": [
"test-job-rest"
]
}
],
"ShutdownDelay": 0,
"Templates": [
{
"ChangeMode": "restart",
"ChangeSignal": "SIGHUP",
"DestPath": "secrets/conf/secrets.env",
"EmbeddedTmpl": "REDACTED",
"Envvars": true,
"LeftDelim": "{{",
"Perms": "0600",
"RightDelim": "}}",
"SourcePath": "",
"Splay": 5000000000,
"VaultGrace": 15000000000
},
{
"ChangeMode": "restart",
"ChangeSignal": "SIGHUP",
"DestPath": "local/conf/conf.env",
"EmbeddedTmpl": "REDACTED",
"Envvars": true,
"LeftDelim": "{{",
"Perms": "0644",
"RightDelim": "}}",
"SourcePath": "",
"Splay": 5000000000,
"VaultGrace": 15000000000
},
{
"ChangeMode": "restart",
"ChangeSignal": "SIGHUP",
"DestPath": "local/conf/conf.conf",
"EmbeddedTmpl": "REDACTED",
"Envvars": false,
"LeftDelim": "{{",
"Perms": "0644",
"RightDelim": "}}",
"SourcePath": "",
"Splay": 5000000000,
"VaultGrace": 15000000000
}
],
"User": "",
"Vault": {
"ChangeMode": "noop",
"ChangeSignal": "SIGHUP",
"Env": false,
"Policies": [
"REDACTED"
]
}
}
],
"Update": {
"AutoPromote": false,
"AutoRevert": false,
"Canary": 0,
"HealthCheck": "task_states",
"HealthyDeadline": 300000000000,
"MaxParallel": 1,
"MinHealthyTime": 10000000000,
"ProgressDeadline": 600000000000,
"Stagger": 30000000000
}
},
{
"Affinities": null,
"Constraints": [
{
"LTarget": "${attr.vault.version}",
"Operand": "version",
"RTarget": ">= 0.6.1"
},
{
"LTarget": "${attr.os.signals}",
"Operand": "set_contains",
"RTarget": "SIGINT"
}
],
"Count": 3,
"EphemeralDisk": {
"Migrate": false,
"SizeMB": 300,
"Sticky": false
},
"Meta": null,
"Name": "worker",
"ReschedulePolicy": {
"Attempts": 0,
"Delay": 30000000000,
"DelayFunction": "exponential",
"Interval": 0,
"MaxDelay": 3600000000000,
"Unlimited": true
},
"RestartPolicy": {
"Attempts": 3,
"Delay": 15000000000,
"Interval": 900000000000,
"Mode": "delay"
},
"Spreads": null,
"Tasks": [
{
"Affinities": null,
"Artifacts": null,
"Config": {
"command": "REDACTED",
"args": [
"REDACTED",
"REDACTED,"
],
"extra_hosts": [
"telegraf:127.0.0.1"
],
"force_pull": false,
"image": "some-other-docker-image:latest",
"network_mode": "host"
},
"Constraints": null,
"DispatchPayload": null,
"Driver": "docker",
"Env": {
"NOMAD_UNIQUE_HOSTNAME": "${attr.unique.hostname}"
},
"KillSignal": "",
"KillTimeout": 5000000000,
"Leader": false,
"LogConfig": {
"MaxFileSizeMB": 10,
"MaxFiles": 10
},
"Name": "worker",
"Resources": {
"CPU": 300,
"Devices": null,
"DiskMB": 0,
"IOPS": 0,
"MemoryMB": 512,
"Networks": [
{
"CIDR": "",
"Device": "",
"DynamicPorts": [
{
"Label": "ui",
"Value": 0
},
{
"Label": "worker",
"Value": 0
},
{
"Label": "api",
"Value": 0
},
{
"Label": "rest",
"Value": 0
},
{
"Label": "history",
"Value": 0
},
{
"Label": "driver",
"Value": 0
},
{
"Label": "blockManager",
"Value": 0
},
{
"Label": "app_prom",
"Value": 0
}
],
"IP": "",
"MBits": 10,
"ReservedPorts": null
}
]
},
"Services": [
{
"AddressMode": "auto",
"CanaryTags": null,
"CheckRestart": null,
"Checks": [
{
"AddressMode": "",
"Args": null,
"CheckRestart": null,
"Command": "",
"GRPCService": "",
"GRPCUseTLS": false,
"Header": null,
"Id": "",
"InitialStatus": "",
"Interval": 1000000000,
"Method": "",
"Name": "web-ui",
"Path": "/",
"PortLabel": "ui",
"Protocol": "",
"TLSSkipVerify": false,
"Timeout": 1000000000,
"Type": "http"
}
],
"Id": "",
"Name": "test-job-worker",
"PortLabel": "ui",
"Tags": null
}
],
"ShutdownDelay": 0,
"Templates": [
{
"ChangeMode": "restart",
"ChangeSignal": "SIGHUP",
"DestPath": "local/other.env",
"EmbeddedTmpl": "",
"Envvars": true,
"LeftDelim": "{{",
"Perms": "0644",
"RightDelim": "}}",
"SourcePath": "",
"Splay": 5000000000,
"VaultGrace": 15000000000
},
{
"ChangeMode": "restart",
"ChangeSignal": "SIGHUP",
"DestPath": "local/conf/defaults.conf",
"EmbeddedTmpl": "",
"Envvars": false,
"LeftDelim": "{{",
"Perms": "0644",
"RightDelim": "}}",
"SourcePath": "",
"Splay": 5000000000,
"VaultGrace": 15000000000
},
{
"ChangeMode": "restart",
"ChangeSignal": "SIGHUP",
"DestPath": "local/REDACTED.json",
"EmbeddedTmpl": "",
"Envvars": false,
"LeftDelim": "{{",
"Perms": "0644",
"RightDelim": "}}",
"SourcePath": "",
"Splay": 5000000000,
"VaultGrace": 15000000000
}
],
"User": ""
}
],
"Update": null
}
],
"Type": "service",
"Update": {
"AutoPromote": false,
"AutoRevert": false,
"Canary": 0,
"HealthCheck": "",
"HealthyDeadline": 0,
"MaxParallel": 0,
"MinHealthyTime": 0,
"ProgressDeadline": 0,
"Stagger": 0
},
"VaultToken": ""
}
}
```

### Nomad Server logs
```
Mar 20 23:22:52 nomad1 nomad[6066]: 2020-03-20T23:22:52.035Z [DEBUG] http: request complete: method=PUT path=/v1/node/494d1cf3-921a-0e2a-b7d5-948ff93527c9/drain duration=7.97632ms
Mar 20 23:22:52 nomad1 nomad[6066]: 2020-03-20T23:22:52.035Z [TRACE] nomad.drain: node has draining jobs on it: node_id=494d1cf3-921a-0e2a-b7d5-948ff93527c9 num_jobs=1
Mar 20 23:22:52 nomad1 nomad[6066]: 2020-03-20T23:22:52.035Z [TRACE] nomad.drain.job_watcher: registering job: job=""
Mar 20 23:22:52 nomad1 nomad[6066]: 2020-03-20T23:22:52.035Z [TRACE] nomad.drain.job_watcher: retrieved allocs for draining jobs: num_allocs=0 index=0 error="context canceled"
Mar 20 23:22:52 nomad1 nomad[6066]: 2020-03-20T23:22:52.035Z [TRACE] nomad.drain.job_watcher: getting job allocs at index: index=1
Mar 20 23:22:52 nomad1 nomad[6066]: 2020-03-20T23:22:52.035Z [TRACE] nomad.drain.job_watcher: retrieved allocs for draining jobs: num_allocs=1 index=1026 error=
Mar 20 23:22:52 nomad1 nomad[6066]: 2020-03-20T23:22:52.035Z [TRACE] nomad.drain.job_watcher: handling job: job=""
Mar 20 23:22:52 nomad1 nomad[6066]: 2020-03-20T23:22:52.035Z [TRACE] nomad.drain.job_watcher: received result for job: job="" result="Drain 1 ; Migrate 0 ; Done false"
Mar 20 23:22:52 nomad1 nomad[6066]: 2020-03-20T23:22:52.035Z [TRACE] nomad.drain.job_watcher: sending drain request for allocs: num_allocs=1
Mar 20 23:22:52 nomad1 nomad[6066]: 2020-03-20T23:22:52.041Z [DEBUG] http: request complete: method=GET path=/v1/node/494d1cf3-921a-0e2a-b7d5-948ff93527c9/allocations?stale= duration=1.075622ms
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.045Z [TRACE] nomad.drain.job_watcher: getting job allocs at index: index=1038
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.047Z [DEBUG] http: request complete: method=GET path=/v1/node/494d1cf3-921a-0e2a-b7d5-948ff93527c9/allocations?index=1026&stale= duration=1.000008036s
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.053Z [DEBUG] worker: dequeued evaluation: eval_id=92142103-0faa-d220-d0d7-af8eb67d302d
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.053Z [DEBUG] worker.service_sched: reconciled current state with desired state: eval_id=92142103-0faa-d220-d0d7-af8eb67d302d job_id=test-job namespace=default results="Total changes: (place 1) (destructive 0) (inplace 0) (stop 1)
Mar 20 23:22:53 nomad1 nomad[6066]: Desired Changes for "master": (place 0) (inplace 0) (destructive 0) (stop 0) (migrate 1) (ignore 0) (canary 0)
Mar 20 23:22:53 nomad1 nomad[6066]: Desired Changes for "worker": (place 0) (inplace 0) (destructive 0) (stop 0) (migrate 0) (ignore 3) (canary 0)"
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.068Z [DEBUG] worker: submitted plan for evaluation: eval_id=92142103-0faa-d220-d0d7-af8eb67d302d
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.068Z [DEBUG] worker.service_sched: setting eval status: eval_id=92142103-0faa-d220-d0d7-af8eb67d302d job_id=test-job namespace=default status=complete
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.071Z [DEBUG] http: request complete: method=GET path=/v1/node/494d1cf3-921a-0e2a-b7d5-948ff93527c9/allocations?index=1038&stale= duration=9.1505ms
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.071Z [TRACE] nomad.drain.job_watcher: retrieved allocs for draining jobs: num_allocs=1 index=1039 error=
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.071Z [TRACE] nomad.drain.job_watcher: handling job: job=""
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.071Z [TRACE] nomad.drain.job_watcher: received result for job: job="" result="Drain 0 ; Migrate 1 ; Done false"
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.071Z [TRACE] nomad.drain.job_watcher: sending migrated for allocs: num_allocs=1
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.071Z [TRACE] nomad.drain.job_watcher: getting job allocs at index: index=1039
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.089Z [DEBUG] worker: updated evaluation: eval=""
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.089Z [DEBUG] worker: ack evaluation: eval_id=92142103-0faa-d220-d0d7-af8eb67d302d
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.201Z [DEBUG] http: request complete: method=GET path=/v1/node/494d1cf3-921a-0e2a-b7d5-948ff93527c9/allocations?index=1039&stale= duration=116.113468ms
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.205Z [TRACE] nomad.drain.job_watcher: retrieved allocs for draining jobs: num_allocs=1 index=1041 error=
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.205Z [TRACE] nomad.drain.job_watcher: handling job: job=""
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.205Z [TRACE] nomad.drain.job_watcher: received result for job: job="" result="Drain 0 ; Migrate 1 ; Done false"
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.205Z [TRACE] nomad.drain.job_watcher: sending migrated for allocs: num_allocs=1
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.205Z [TRACE] nomad.drain.job_watcher: getting job allocs at index: index=1041
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.802Z [DEBUG] nomad.client: revoking vault accessors due to terminal allocations: num_accessors=1
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.806Z [DEBUG] http: request complete: method=GET path=/v1/node/494d1cf3-921a-0e2a-b7d5-948ff93527c9/allocations?index=1041&stale= duration=600.329036ms
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.807Z [TRACE] nomad.drain.job_watcher: retrieved allocs for draining jobs: num_allocs=1 index=1042 error=
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.807Z [TRACE] nomad.drain.job_watcher: handling job: job=""
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.807Z [TRACE] nomad.drain.job_watcher: received result for job: job="" result="Drain 0 ; Migrate 1 ; Done false"
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.807Z [TRACE] nomad.drain.job_watcher: sending migrated for allocs: num_allocs=1
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.807Z [TRACE] nomad.drain.job_watcher: getting job allocs at index: index=1042
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.938Z [TRACE] nomad.drain.job_watcher: retrieved allocs for draining jobs: num_allocs=1 index=1043 error=
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.938Z [TRACE] nomad.drain.job_watcher: handling job: job=""
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.939Z [TRACE] nomad.drain.job_watcher: received result for job: job="" result="Drain 0 ; Migrate 0 ; Done false"
Mar 20 23:22:53 nomad1 nomad[6066]: 2020-03-20T23:22:53.939Z [TRACE] nomad.drain.job_watcher: getting job allocs at index: index=1043
Mar 20 23:22:54 nomad1 nomad[6066]: 2020-03-20T23:22:54.938Z [TRACE] nomad.drain.job_watcher: retrieved allocs for draining jobs: num_allocs=1 index=1046 error=
Mar 20 23:22:54 nomad1 nomad[6066]: 2020-03-20T23:22:54.938Z [TRACE] nomad.drain.job_watcher: handling job: job=""
Mar 20 23:22:54 nomad1 nomad[6066]: 2020-03-20T23:22:54.938Z [TRACE] nomad.drain.job_watcher: received result for job: job="" result="Drain 0 ; Migrate 0 ; Done false"
Mar 20 23:22:54 nomad1 nomad[6066]: 2020-03-20T23:22:54.938Z [TRACE] nomad.drain.job_watcher: getting job allocs at index: index=1046
Mar 20 23:22:59 nomad1 nomad[6066]: 2020-03-20T23:22:59.349Z [DEBUG] nomad: memberlist: Stream connection from=192.168.51.12:39270
Mar 20 23:23:01 nomad1 nomad[6066]: 2020-03-20T23:23:01.527Z [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=server duration=171.745µs
Mar 20 23:23:09 nomad1 nomad[6066]: 2020-03-20T23:23:09.352Z [DEBUG] nomad: memberlist: Stream connection from=192.168.51.12:39276
Mar 20 23:23:11 nomad1 nomad[6066]: 2020-03-20T23:23:11.531Z [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=server duration=130.945µs
Mar 20 23:23:19 nomad1 nomad[6066]: 2020-03-20T23:23:19.354Z [DEBUG] nomad: memberlist: Stream connection from=192.168.51.12:39282
Mar 20 23:23:21 nomad1 nomad[6066]: 2020-03-20T23:23:21.536Z [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=server duration=156.078µs
Mar 20 23:23:29 nomad1 nomad[6066]: 2020-03-20T23:23:29.354Z [DEBUG] nomad: memberlist: Stream connection from=192.168.51.12:39290
Mar 20 23:23:31 nomad1 nomad[6066]: 2020-03-20T23:23:31.539Z [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=server duration=148.379µs
Mar 20 23:23:39 nomad1 nomad[6066]: 2020-03-20T23:23:39.356Z [DEBUG] nomad: memberlist: Stream connection from=192.168.51.12:39296
Mar 20 23:23:41 nomad1 nomad[6066]: 2020-03-20T23:23:41.542Z [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=server duration=129.229µs
Mar 20 23:23:49 nomad1 nomad[6066]: 2020-03-20T23:23:49.356Z [DEBUG] nomad: memberlist: Stream connection from=192.168.51.12:39302
Mar 20 23:23:51 nomad1 nomad[6066]: 2020-03-20T23:23:51.544Z [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=server duration=142.092µs
Mar 20 23:23:59 nomad1 nomad[6066]: 2020-03-20T23:23:59.358Z [DEBUG] nomad: memberlist: Stream connection from=192.168.51.12:39310
Mar 20 23:24:01 nomad1 nomad[6066]: 2020-03-20T23:24:01.547Z [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=server duration=155.11µs
Mar 20 23:24:09 nomad1 nomad[6066]: 2020-03-20T23:24:09.360Z [DEBUG] nomad: memberlist: Stream connection from=192.168.51.12:39316
Mar 20 23:24:11 nomad1 nomad[6066]: 2020-03-20T23:24:11.550Z [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=server duration=164.094µs
Mar 20 23:24:19 nomad1 nomad[6066]: 2020-03-20T23:24:19.361Z [DEBUG] nomad: memberlist: Stream connection from=192.168.51.12:39322
Mar 20 23:24:21 nomad1 nomad[6066]: 2020-03-20T23:24:21.554Z [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=server duration=131.678µs
Mar 20 23:24:24 nomad1 nomad[6066]: 2020-03-20T23:24:24.004Z [TRACE] nomad.drain.job_watcher: retrieved allocs for draining jobs: num_allocs=1 index=1049 error=
Mar 20 23:24:24 nomad1 nomad[6066]: 2020-03-20T23:24:24.004Z [TRACE] nomad.drain.job_watcher: handling job: job=""
Mar 20 23:24:24 nomad1 nomad[6066]: 2020-03-20T23:24:24.004Z [TRACE] nomad.drain.job_watcher: received result for job: job="" result="Drain 0 ; Migrate 0 ; Done false"
Mar 20 23:24:24 nomad1 nomad[6066]: 2020-03-20T23:24:24.004Z [TRACE] nomad.drain.job_watcher: getting job allocs at index: index=1049
Mar 20 23:24:24 nomad1 nomad[6066]: 2020-03-20T23:24:24.006Z [DEBUG] http: request complete: method=GET path=/v1/node/494d1cf3-921a-0e2a-b7d5-948ff93527c9/allocations?index=1042&stale= duration=1m30.191666629s
Mar 20 23:24:29 nomad1 nomad[6066]: 2020-03-20T23:24:29.364Z [DEBUG] nomad: memberlist: Stream connection from=192.168.51.12:39332
Mar 20 23:24:31 nomad1 nomad[6066]: 2020-03-20T23:24:31.556Z [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=server duration=114.031µs
Mar 20 23:24:39 nomad1 nomad[6066]: 2020-03-20T23:24:39.366Z [DEBUG] nomad: memberlist: Stream connection from=192.168.51.12:39338
Mar 20 23:24:41 nomad1 nomad[6066]: 2020-03-20T23:24:41.203Z [DEBUG] http: request complete: method=GET path=/v1/node/494d1cf3-921a-0e2a-b7d5-948ff93527c9/allocations?index=1049&stale= duration=17.188561644s
Mar 20 23:24:41 nomad1 nomad[6066]: 2020-03-20T23:24:41.203Z [TRACE] nomad.drain.job_watcher: retrieved allocs for draining jobs: num_allocs=1 index=1050 error=
Mar 20 23:24:41 nomad1 nomad[6066]: 2020-03-20T23:24:41.203Z [TRACE] nomad.drain.job_watcher: handling job: job=""
Mar 20 23:24:41 nomad1 nomad[6066]: 2020-03-20T23:24:41.203Z [TRACE] nomad.drain.job_watcher: received result for job: job="" result="Drain 0 ; Migrate 0 ; Done false"
Mar 20 23:24:41 nomad1 nomad[6066]: 2020-03-20T23:24:41.203Z [TRACE] nomad.drain.job_watcher: getting job allocs at index: index=1050
Mar 20 23:24:41 nomad1 nomad[6066]: 2020-03-20T23:24:41.559Z [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=server duration=140.676µs
Mar 20 23:24:42 nomad1 nomad[6066]: 2020-03-20T23:24:42.802Z [DEBUG] http: request complete: method=GET path=/v1/node/494d1cf3-921a-0e2a-b7d5-948ff93527c9/allocations?index=1050&stale= duration=1.593281572s
Mar 20 23:24:42 nomad1 nomad[6066]: 2020-03-20T23:24:42.808Z [TRACE] nomad.drain.job_watcher: retrieved allocs for draining jobs: num_allocs=1 index=1051 error=
Mar 20 23:24:42 nomad1 nomad[6066]: 2020-03-20T23:24:42.808Z [TRACE] nomad.drain.job_watcher: handling job: job=""
Mar 20 23:24:42 nomad1 nomad[6066]: 2020-03-20T23:24:42.808Z [TRACE] nomad.drain.job_watcher: received result for job: job="" result="Drain 0 ; Migrate 0 ; Done false"
Mar 20 23:24:42 nomad1 nomad[6066]: 2020-03-20T23:24:42.808Z [TRACE] nomad.drain.job_watcher: getting job allocs at index: index=1051
Mar 20 23:24:49 nomad1 nomad[6066]: 2020-03-20T23:24:49.367Z [DEBUG] nomad: memberlist: Stream connection from=192.168.51.12:39348
Mar 20 23:24:51 nomad1 nomad[6066]: 2020-03-20T23:24:51.561Z [DEBUG] http: request complete: method=GET path=/v1/agent/health?type=server duration=131.953µs
Mar 20 23:24:54 nomad1 nomad[6066]: 2020-03-20T23:24:54.938Z [TRACE] nomad.drain.job_watcher: retrieved allocs for draining jobs: num_allocs=1 index=1052 error=
Mar 20 23:24:54 nomad1 nomad[6066]: 2020-03-20T23:24:54.938Z [TRACE] nomad.drain.job_watcher: handling job: job=""
Mar 20 23:24:54 nomad1 nomad[6066]: 2020-03-20T23:24:54.938Z [TRACE] nomad.drain.job_watcher: received result for job: job="" result="Drain 0 ; Migrate 0 ; Done false"
```

Please let me know if there's any more diagnostic info I can provide that will help debug this issue.

Reproduce the issue with the minimal job specification by submitting the job, waiting for all allocations, and draining the node. Compare deployment state and allocation desired state for task groups listed and missing from the deployment; done means every allocation is stopped or migrated without requiring a forced drain.

Written by the indexing model from the issue text.