hashicorp / hashicorp/nomad

Nomad Client stuck initializing

Open
#18,541 18 comments 0 reactions 0 assignees View on GitHub
hcc/jira stage/needs-investigation theme/client theme/heartbeating type/bug
Dominant language
Go
Stars
17k
Forks
2.1k
Avg merge
1d 9h
Merged PRs (30d)
105

Description

### Nomad version

```
Nomad v1.6.1
BuildDate 2023-07-21T13:49:42Z
Revision 515895c7690cdc72278018dc5dc58aca41204ccc
```

### Operating system and Environment details

```
Debian GNU/Linux 11 (bullseye)
```

### Issue

After a client restart, node gets stuck in `initializing` state. Once it gets stuck, only a restart makes it recover.

```
nomad node status -verbose

ID Node Pool DC Name Class Address Version Drain Eligibility Status
3de7fa5a-336f-d976-1c14-7a6caafd564e default acme s505.acme.com storage 10.5.1.210 1.6.1 false eligible ready
fa18d47e-c16e-947a-958b-6486a862516a default acme s402.acme.com storage 10.5.1.203 1.6.1 false eligible ready
7d0e570c-0615-34a4-227b-568e8af91ca5 default acme s403.acme.com storage 10.5.1.205 1.6.1 false eligible ready
625b55d4-b763-ee41-8b5c-bd93ee15cfec default acme s502.acme.com storage 10.5.1.204 1.6.1 false eligible ready
23523791-f4d1-499c-834c-3af34d0d6ffb default acme s501.acme.com storage 10.5.1.202 1.6.1 false eligible ready
34612ebb-4418-3d2d-bf70-0e188451429e default acme s404.acme.com storage 10.5.1.207 1.6.1 false eligible ready
a6fee44f-5398-dae6-049d-e65548f5d076 default acme s506.acme.com storage 10.5.1.212 1.6.1 false eligible ready
7adfb092-6b29-6dab-12bf-afe5a6b6c900 default acme s405.acme.com storage 10.5.1.209 1.6.1 false eligible ready
eadfd1af-91d8-860c-3a81-022bb94c9db5 default acme s503.acme.com storage 10.5.1.206 1.6.1 false eligible initializing
```

```
nomad node status -verbose eadfd1af-91d8-860c-3a81-022bb94c9db5

ID = eadfd1af-91d8-860c-3a81-022bb94c9db5
Name = s503.acme.com
Node Pool = default
Class = storage
DC = acme
Drain = false
Eligibility = eligible
Status = initializing
CSI Controllers =
CSI Drivers =
Uptime = 4840h58m33s

Host Volumes
Name ReadOnly Source
blob-storage false /data/blob-storage

Drivers
Driver Detected Healthy Message Time
docker true true Healthy 2023-09-20T13:35:08Z
exec true true Healthy 2023-09-20T13:35:08Z
java false false 2023-09-20T13:35:08Z
qemu false false 2023-09-20T13:35:08Z
raw_exec false false disabled 2023-09-20T13:35:08Z

Node Events
Time Subsystem Message Details
2023-09-20T13:35:08Z Cluster Node heartbeat missed
2023-05-30T12:03:16Z Cluster Node re-registered
2023-05-30T11:48:28Z Cluster Node heartbeat missed
2023-03-03T07:35:38Z Cluster Node re-registered
2023-03-03T00:56:25Z Cluster Node heartbeat missed
2022-11-22T14:25:24Z Cluster Node registered
```

So far, every time we experience this problem, the node contains a `Node heartbeat missed` event.

### Reproduction steps

We don't know how to reproduce it yet.

#### Expected Result

Client restarts and eventually transition to `ready` state.

#### Actual Result

Client restarts and might get stuck in `initializing` state

### Nomad Server logs (if appropriate)

```
Sep 20 01:17:40 c206.acme.com nomad-server[3895982]: 2023-09-20T01:17:40.782Z [INFO] nomad.raft: starting snapshot up to: index=1589250
Sep 20 01:17:40 c206.acme.com nomad-server[3895982]: 2023-09-20T01:17:40.782Z [INFO] snapshot: creating new snapshot: path=/data/service/nomad-server/data/server/raft/snapshots/589114-1589250-1695172660782.tmp
Sep 20 01:17:40 c206.acme.com nomad-server[3895982]: 2023-09-20T01:17:40.905Z [INFO] snapshot: reaping snapshot: path=/data/service/nomad-server/data/server/raft/snapshots/589114-1572852-1694931874411
Sep 20 01:17:40 c206.acme.com nomad-server[3895982]: 2023-09-20T01:17:40.906Z [INFO] nomad.raft: compacting logs: from=1570815 to=1579010
Sep 20 01:17:40 c206.acme.com nomad-server[3895982]: 2023-09-20T01:17:40.958Z [INFO] nomad.raft: snapshot complete up to: index=1589250
Sep 20 13:33:33 c206.acme.com nomad-server[3895982]: 2023-09-20T13:33:33.748Z [WARN] nomad.heartbeat: node TTL expired: node_id=3c6f37a6-d45d-925d-90de-0ddc7321d679
Sep 20 13:34:26 c206.acme.com nomad-server[3895982]: 2023-09-20T13:34:26.565Z [WARN] nomad.heartbeat: node TTL expired: node_id=f6b4703e-bdca-a959-90b8-60637a165592
Sep 20 13:35:08 c206.acme.com nomad-server[3895982]: 2023-09-20T13:35:08.316Z [WARN] nomad.heartbeat: node TTL expired: node_id=eadfd1af-91d8-860c-3a81-022bb94c9db5
```

### Nomad Client logs (if appropriate)

```
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.435Z [INFO] client.plugin: starting plugin manager: plugin-type=driver
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.435Z [INFO] client.plugin: starting plugin manager: plugin-type=device
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.469Z [INFO] client.alloc_runner.task_runner: Task event: alloc_id=102852d4-8b75-e5b4-fdb3-03319ee6c8bc task=apigw-envoy-be type=Received msg="Task received by client" failed=false
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.470Z [INFO] client.alloc_runner.task_runner: Task event: alloc_id=102852d4-8b75-e5b4-fdb3-03319ee6c8bc task=proxy-init type=Received msg="Task received by client" failed=false
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.483Z [INFO] client.alloc_runner.task_runner: Task event: alloc_id=491e3dfa-68d2-61d3-2971-3f459c98fe91 task=tag-sync type=Received msg="Task received by client" failed=false
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.490Z [INFO] client.alloc_runner.task_runner: Task event: alloc_id=61647409-6e33-b6d8-5275-cc1aac95da1b task=kde-planner type=Received msg="Task received by client" failed=false
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.498Z [INFO] client.alloc_runner.task_runner: Task event: alloc_id=a1e0d299-5b7d-e551-d885-7589b6472986 task=kde-cache type=Received msg="Task received by client" failed=false
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.503Z [INFO] client.alloc_runner.task_runner: Task event: alloc_id=ed544457-3a35-6b86-5219-1b1b205365b6 task=controlplane-agent type=Received msg="Task received by client" failed=false
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.517Z [INFO] client.alloc_runner.task_runner: Task event: alloc_id=fcacf1a5-10f3-29cb-618e-e51b937fa6da task=kde-worker-b type=Received msg="Task received by client" failed=false
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.523Z [INFO] client: started client: node_id=eadfd1af-91d8-860c-3a81-022bb94c9db5
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.523Z [INFO] client: node registration complete
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.570Z [WARN] client.alloc_runner.task_runner.task_hook.api: error creating task api socket: alloc_id=ed544457-3a35-6b86-5219-1b1b205365b6 task=controlplane-agent path=/data/service/nomad-client/data/alloc/ed544457-3a35-6b86-5219-1b1b205365b6/controlplane-agent/secrets/api.sock error="listen>
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.612Z [INFO] agent: (runner) creating new runner (dry: false, once: false)
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.614Z [INFO] agent: (runner) creating watcher
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.614Z [INFO] agent: (runner) starting
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.652Z [INFO] agent: (runner) creating new runner (dry: false, once: false)
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.653Z [INFO] agent: (runner) creating watcher
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.653Z [INFO] agent: (runner) starting
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.680Z [INFO] agent: (runner) creating new runner (dry: false, once: false)
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.682Z [INFO] agent: (runner) creating watcher
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.682Z [INFO] agent: (runner) starting
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.710Z [INFO] agent: (runner) creating new runner (dry: false, once: false)
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.711Z [INFO] agent: (runner) creating watcher
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.712Z [INFO] agent: (runner) starting
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.741Z [INFO] agent: (runner) creating new runner (dry: false, once: false)
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.742Z [INFO] agent: (runner) creating watcher
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.743Z [INFO] agent: (runner) starting
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.783Z [INFO] agent: (runner) creating new runner (dry: false, once: false)
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.784Z [INFO] agent: (runner) creating watcher
Sep 20 13:35:08 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:08.784Z [INFO] agent: (runner) starting
Sep 20 13:35:18 s503.acme.com nomad-client[2331106]: 2023-09-20T13:35:18.070Z [INFO] client: node registration complete
```

Contributor guide

No contributing guide indexed for this repository

Research direction

Start by tracing the Nomad client registration and heartbeat handling around the reported `Node heartbeat missed` event, using the client and server log excerpts as the initial case. Investigate why the node remains `initializing` after registration and define a reproducible scenario; done means a restarted client reliably transitions to `ready` without requiring another restart.

Written by the indexing model from the issue text.

Assessment

Tech stack
go
Domain
distributed-systems, infrastructure
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
30/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.