kubevirt: ghost record not cleanup properly causes error to find the correct launcher client
BUG REPORT:
/kind bug
What happened: We noticed an issue that VMI stuck in Scheduled and the launcher pod was Error:
NAMESPACE NAME AGE PHASE IP NODENAME
ns01 vm-08 12h Scheduled node01
NAMESPACE NAME READY STATUS RESTARTS AGE
ns01 virt-launcher-vm-08-2pdj6 2/3 Error 0 12h
Looked into the stuck vmi, the pod went to Error because the compute container was terminated due to timeout failure of creating virt-launcher client connection when the entry already exists with differing UID
{“component”:“virt-handler”,“kind”:“”,“level”:“error”,“msg”:“Synchronizing the VirtualMachineInstance failed.”,“name”:“vm-08”,“namespace”:“ns01”,“pos”:“vm.go:1359”,“reason”:“unable to create virt-launcher client connection: can not add ghost record when entry already exists with differing UID”,“timestamp”:“2021-12-08T09:23:02.504977Z”,“uid”:“054e439b-4402-4a65-9dd1-70e4235762b3”}
Events:
Type Reason Age From Message
---- ------ ---- ---- -------
Warning SyncFailed 4m30s (x4316 over 13h) virt-handler unable to create virt-launcher client connection: can not add ghost record when entry already exists with differing UID
{“component”:“virt-launcher”,“level”:“info”,“msg”:“Marked as ready”,“pos”:“virt-launcher.go:72”,“timestamp”:“2021-12-08T09:23:02.187469Z”} panic: timed out waiting for domain to be defined
goroutine 1 [running]: main.waitForDomainUUID(0x45d964b800, 0xc0003376e0, 0xc0005a68a0, 0x1af0838, 0xc000452180, 0x0) cmd/virt-launcher/virt-launcher.go:218 +0x517 main.main() cmd/virt-launcher/virt-launcher.go:449 +0x1265
This is an issue that virt-handler was using a wrong virt-launcher client to build connection.
{“component”:“virt-handler”,“kind”:“VirtualMachineInstance”,“level”:“error”,“msg”:“Updating the VirtualMachineInstance status failed.”,“name”:“vm-08”,“namespace”:“ns01”,“pos”:“vm.go:1366”,“reason”:“Operation cannot be fulfilled on virtualmachineinstances.kubevirt.io "vm-08": StorageError: invalid object, Code: 4, Key: /registry/kubevirt.io/virtualmachineinstances/ns01/vm-08, ResourceVersion: 0, AdditionalErrorMsg: Precondition failed: UID in precondition: 8667609c-15c6-44dd-bdc1-704ee0bdf40f, UID in object meta: 054e439b-4402-4a65-9dd1-70e4235762b3”,“timestamp”:“2021-12-08T09:22:54.560475Z”,“uid”:“8667609c-15c6-44dd-bdc1-704ee0bdf40f”}
The error can not add ghost record when entry already exists with differing UID showed that the ghost record was not deleted properly. This issue was noticed when a pod was evicted from node which went NotReady for a period of time, and virt-handler did not properly handle VMI shutdown process and cleanup of local data.
What you expected to happen: A rebooted VMI scheduled to the node where a prior vmi of the same name was terminated improperly can be Running
How to reproduce it (as minimally and precisely as possible):
Anything else we need to know?:
Environment:
- KubeVirt version (use
virtctl version): 0.35 - Kubernetes version (use
kubectl version): 1.20 - VM or VMI specifications:
- Cloud provider or hardware configuration: bare metal
- OS (e.g. from /etc/os-release):
NAME="CentOS Linux" VERSION="8 (Core)" ID="centos" ID_LIKE="rhel fedora" VERSION_ID="8" PLATFORM_ID="platform:el8" PRETTY_NAME="CentOS Linux 8 (Core)" ANSI_COLOR="0;31" CPE_NAME="cpe:/o:centos:centos:8" HOME_URL="https://www.centos.org/" BUG_REPORT_URL="https://bugs.centos.org/" CENTOS_MANTISBT_PROJECT="CentOS-8" CENTOS_MANTISBT_PROJECT_VERSION="8" REDHAT_SUPPORT_PRODUCT="centos" - Kernel (e.g.
uname -a):Linux gs-node.nvmetal.net 4.18.0-193.13.2.el8.1622008870.664c92a05.x86_64 #1 SMP Wed May 26 13:04:56 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux - Install tools:
- Others:
About this issue
- Original URL
- State: closed
- Created 2 years ago
- Comments: 17 (13 by maintainers)
interesting bug.
The ghost records exist in order to guarantee that a VMI’s local data is cleaned up when virt-handler re-initializes even if the VMI is deleted from etcd.
What you’re hitting is that the ghost record for a VMI is sticking around even after a new VMI with the exact same name has been created. Looking at the code, we don’t handle this situation at all, and the result is the new VMI will never get processed.
Here’s my suggestion as a fix.
When virt-handler is executing on a VMI, add a check to determine if an old ghost record exists for the a VMI with the same name but has a different UID. If that condition exists, run the equavalent of this code in order to process the cleanup of the old ghost record. https://github.com/kubevirt/kubevirt/blob/bf73abb9ac945bc0798b88235db8f487be0d5d82/pkg/virt-handler/vm.go#L1745
We’re already doing this exact same thing to cleanup when we detect an old domain exists somehow, so extend that logic to handle when an old ghost record exists somehow.