bhouse-nexthop commented on PR #14666:
URL: https://github.com/apache/cloudstack/pull/14666#issuecomment-6780156218
### Test report: VM map drift check (commit 0963c36847)
**Summary:** the check runs every 5 minutes on its own thread and covers
every CloudManaged cluster in Running or Alert state. Three existing clusters
gave no findings over three cycles. On a fresh test cluster, each kind of drift
I caused was reported once, with one WARN event and one alert naming the VM,
and wasn't reported again on later cycles. Once I undid it, the next cycle
recorded the INFO "matches ... again" event and removed the detail. The kinds
covered were a missing map row, a map row for an expunged VM, a map row for a
VM that doesn't exist, a running node VM that isn't a Kubernetes node, and a
stray VM named as a node. When SSH to the control node failed, only the VM
comparison ran: the node finding was kept, neither cleared nor reported again,
and it cleared once SSH was back. With the setting off nothing ran. A cluster
in the middle of a real scale-up was skipped. The check changed nothing, and
the management-server log had no exceptions or NPEs from it.
**Environment**
- A CloudStack 24.0 (main) build with this PR, alongside some of my other
open PRs. The management server and all three agents were upgraded in place to
this build.
- The PR targets 4.22; it wasn't run on a 4.22 build. The checker only uses
DAOs, `SshHelper` and the action-worker helpers, which are the same on both
branches.
- Three KVM hosts, Ceph RBD primary storage, one management server.
- Three existing CKS clusters: a 3-control-node cluster with 2 workers, a
1-control-node cluster with 1 worker, and a 1-control-node cluster with 2
workers.
- A fresh test cluster, Kubernetes v1.32.13, 1 control node and 2 workers,
on an isolated network, created 40 minutes before the first test so its VMs
were past the 15-minute grace period.
- `cloud.kubernetes.cluster.vm.map.check.enabled` was `true` (the default)
except in scenario 6.
**Results**
| Scenario | Result |
|---|---|
| 1: baseline, the three existing clusters and the fresh test cluster |
pass. 3 cycles, every cluster checked each time; no events, no alerts, no
details |
| 2: worker's map row deleted | pass. One WARN event and one alert, "named
as a node ... but is not one of its VMs". No re-alert on the next cycle. Row
restored: INFO event, detail removed, no more alerts |
| 3: map rows for an expunged VM and for a VM id that doesn't exist | pass.
One event and one alert each ("has been or is being expunged", "does not
exist"). No re-alert. Rows removed: INFO event |
| 4: kubelet stopped and the node deleted from Kubernetes | pass. One event
and one alert, "is running but is not a Kubernetes node". Cleared after kubelet
was restarted (see 5) |
| 5: SSH to the control node broken | pass. Only the VM comparison ran: a
new unmapped-VM finding was reported, and the node finding was kept although
the node had rejoined. No INFO event, no node findings. SSH restored: both INFO
events on the next cycle |
| 6: setting off | pass. Two cycles with a map row deleted: no SSH to any
cluster, no events, no alerts. Setting back on: checked within 12 s and
reported |
| 7: cluster in the middle of a scale-up | pass. The test cluster was
skipped in the cycle during the scale, the new node VM wasn't flagged, and a
stray VM within its 15-minute grace wasn't flagged. It was reported on the
first cycle after the scale |
| 8: the check changes nothing | pass. Map rows, VMs and the cluster only
changed through my edits and the existing state scanner |
**How the drift was caused**
- **Missing map row (2, 5, 6).** I saved and deleted a worker's
`kubernetes_cluster_vm_map` row, and later inserted it back with the same id
and values.
- **Stale map rows (3).** I inserted two rows into the test cluster's map.
One pointed to the VM of a node removed from another cluster earlier, which is
expunged (`removed` set, state Expunging). The other pointed to VM id 999999,
which doesn't exist.
- **Not a node (4).** On one worker I ran `systemctl stop kubelet`, then
`kubectl delete node`. The VM kept running. To undo it I ran `systemctl start
kubelet`, and the node registered again within 10 s.
- **SSH failure (5).** I deleted the control node's SSH port-forwarding rule
(public port 2222), which the checker uses, so SSH timed out. Afterwards I
recreated it with the same ports.
- **Stray VM (7).** I deployed a small VM in the same account, on a
different network, named `<cluster>-node-1a1c6f00000`, which matches the node
naming. It was then destroyed with expunge.
- **Mid-operation (7).** I first set the cluster's state to Scaling in the
DB, but another PR in this build recovers a cluster stuck in an operation state
with no operation running, and set it back to Running within 30 s. So I used a
real scale-up from 2 to 3 workers instead (Scaling 21:31:28 to 21:33:35), timed
to span a check cycle.
**1: baseline**
- Right after the upgrade there were no `KUBERNETES.CLUSTER.VM.MAP.CHECK`
events at all, no USERVM alerts, and no `vmMapCheck*` cluster details.
- When everything matches, the checker writes nothing to the
management-server log. I confirmed that it ran from the sudo log on each
cluster's first control node, where every cycle shows `kubectl get nodes -o
name`:
```
3-control cluster: 20:05:30 20:10:28 20:15:28
1+1 cluster: 20:05:28 20:10:28 20:15:28
1+2 cluster: 20:05:33 20:10:29 20:15:29
test cluster: 20:05:35 20:10:29 20:15:29
```
The management server finished starting at 20:00:27, and the status
scanner's first run is 300 s later. The cycles kept this 5-minute rhythm for
the whole test, about 1 h 40 min.
- None of the three existing clusters produced an event or alert at any
point in the test.
**2: missing map row**
- Row deleted at 20:16:18. At the 20:20:29 cycle:
```
event WARN display=0 VM <cluster>-node-1a1c6ebf01d (2b7607ac-...,
Running) is named as a node of Kubernetes cluster <cluster> but is not one of
its VMs in CloudStack
alert type 8 (USERVM), same subject. Body: "... This is only reported,
nothing was changed. Check the VMs of the Kubernetes cluster in CloudStack
against its VMs and its Kubernetes nodes."
detail vmMapCheckReportedVmDrift = UNMAPPED_VM:493 (display=0)
```
- Only the unmapped VM was reported. Its Kubernetes node wasn't reported as
a node with no VM, because the node matches the unmapped VM by name, as the PR
describes.
- At the 20:25:29 cycle the check ran (kubectl on the control node) but
recorded no new event or alert.
- The existing state scanner moved the cluster to Alert, since it had fewer
map rows than nodes. The check still covered it in Alert.
- Row restored at 20:26:31. At the 20:30:32 cycle: `INFO The VM map of
Kubernetes cluster <cluster> matches the VMs of the cluster in CloudStack
again`. The detail was removed, no alert was raised, and the state scanner set
the cluster back to Running.
**3: stale map rows**
- Rows inserted at 20:31:27. At the 20:35:31 cycle there were two events and
two alerts:
```
VM <other cluster>-node-1a1c2dc4f71 (5dad63d3-...) is one of the VMs of
Kubernetes cluster <cluster> in CloudStack, but has been or is being expunged
VM with ID 999999 is one of the VMs of Kubernetes cluster <cluster> in
CloudStack, but does not exist
detail vmMapCheckReportedVmDrift = MAPPED_VM:489,MAPPED_VM:999999
```
- At 20:40:31: nothing new. Rows removed at 20:41:39. At 20:45:35: the INFO
"matches the VMs ... again" event, and the detail was removed.
**4: running VM that isn't a node**
- At 20:41:44, kubelet was stopped on a worker and its node deleted. The VM
had been Running since 19:25, so it was past the grace period. At the 20:45:35
cycle:
```
WARN VM <cluster>-node-1a1c6eb8176 (9473d5a9-...) of Kubernetes cluster
<cluster> is running but is not a Kubernetes node of the cluster
detail vmMapCheckReportedNodeDrift = VM_NOT_A_NODE:492
```
Only that one finding was raised: no node without a VM, and no finding for
the other VMs. The VM-side INFO event from scenario 3 came in the same cycle;
the two details are tracked separately.
**5: SSH failure**
- At 20:46:46 the port-forwarding rule was deleted, and SSH to it timed out.
At 20:47:05 kubelet was restarted, and the node was back and Ready, so the node
finding was really gone. At 20:47:23 the worker's map row was deleted again.
- At the 20:50:55 cycle, after a 10 s SSH timeout:
```
DEBUG Failed to list the nodes of Kubernetes cluster ...
java.net.SocketTimeoutException: The kexTimeout ...
DEBUG Could not list the Kubernetes nodes of cluster ..., comparing its VM
map with the VMs in CloudStack only
WARN VM <cluster>-node-1a1c6ebf01d ... is named as a node of Kubernetes
cluster <cluster> but is not one of its VMs in CloudStack
details: vmMapCheckReportedNodeDrift = VM_NOT_A_NODE:492 (kept)
vmMapCheckReportedVmDrift = UNMAPPED_VM:493 (new)
```
The VM comparison still ran. The unmapped VM had cleared in scenario 2 and
come back, so it was reported again, as it should be. The node detail was
neither cleared nor reported again, and no node finding came from the failed
listing.
- At 20:52:02 the rule was recreated, and at 20:52:09 the row was restored.
At the 20:55:47 cycle there were both INFO events, "matches the VMs of the
cluster in CloudStack again" and "matches the Kubernetes nodes of the cluster
again". Both details were removed and no alert was raised.
**6: setting off**
- At 20:56:49 the setting was set to `false`, and at 20:56:53 the worker's
map row was deleted.
- Over the next 10 minutes (the 21:00 and 21:05 cycles) no control node of
any cluster saw a `kubectl get nodes -o name`. The checker thread wrote no log
lines, and there were no events or alerts. The state scanner kept running every
30 s and moved the test cluster to Alert as before.
- At 21:07:08 the setting was set back to `true`. The next scanner run
started a check right away (kubectl at 21:07:16-18), and the unmapped VM was
reported at 21:07:18. The row was then restored, and the INFO event came at
21:12:19.
**7: cluster mid-operation**
- At 21:15:35 I deployed the stray VM named as a node. The 21:17, 21:22 and
21:27 cycles didn't report it, since it was under 15 minutes old.
- I scaled from 2 to 3 workers at 21:31:24, and it returned OK in 131 s. The
state went `Running` -> `Scaling` (21:31:28) -> `Running` (21:33:35).
- In the 21:32 cycle the other three clusters were checked (21:32:17-18),
but the test cluster wasn't: its control node saw no kubectl, and there were no
events. The new node VM, created during the scale, was never flagged.
- In the 21:37:18 cycle, with the cluster Running, the stray VM was reported
(`UNMAPPED_VM:494`). This shows that the drift was there during the skipped
cycle. After the VM was destroyed with expunge, the INFO event came at 21:42:19.
**8: no changes**
- The map rows only changed through my inserts and deletes; the scale-up
added the new worker's row. VM states only changed through kubelet, the scale
and the stray VM.
- The cluster's state changes (Running <-> Alert) came from the existing
state scanner, which moves a cluster to Alert when it has fewer map rows than
nodes or a mapped VM isn't Running. They were logged on the
`Kubernetes-Cluster-State-Scanner` thread. The checker's own thread only logged
the findings, the INFO lines and the alert manager's lines.
- The only writes on that thread were to `kubernetes_cluster_details`
(`vmMapCheckReported*`, display=0), the events and the alerts.
**Logs**
- Across the whole run the checker thread logged 21 WARN lines (the
findings, plus the alert manager's "alertType=[8]" and "No recipients" lines
for each), 6 INFO lines (the resolutions) and 2 DEBUG lines (the SSH failure).
There were no ERROR lines.
- The only exception on that thread was the expected
`SocketTimeoutException` in scenario 5, logged at DEBUG. The log had no
`NullPointerException` anywhere after the upgrade.
- Plugin DAOs: the checker reached `kubernetes_cluster`,
`kubernetes_cluster_vm_map` and `kubernetes_cluster_details` on every cycle, so
the injection problem found in review doesn't appear.
**Not covered**
- More than one management server, which is what the global lock is for.
- More than 5 new findings in one cycle, which triggers the alert cap.
- Hashed keys, which are used when there are very many findings.
- Node names registered as FQDNs, and etcd nodes.
- A Kubernetes node with no VM at all, such as a node object created by
hand. Every node I removed still had its VM in the map or named as a node.
- ExternalManaged clusters, and projects.
- A management server restart while a finding is open. The dedupe state is
kept in the cluster details, and I didn't restart with a detail present.
**Result:** pass. The check reports each kind of drift once with an event
and an alert, records the INFO event when the drift is undone, and keeps the
node findings when kubectl can't be reached. It is off when the setting is
false and skips clusters that are being operated on. It changed nothing, and
the three existing clusters gave no false findings.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
