[itayherzberg]

Problem

When the ISO import helper pod fails (the image URL returns 404, the download is cut, the pod cannot write the volume), the bridge removes the importing label and does nothing else. Three things follow:

• If a power-on was deferred until the import completes, the VM watcher runs it as soon as the label is gone: the VM starts from a CD-ROM whose PVC holds no image and sits at the firmware prompt (BdsDxe: failed to load Boot0001 "UEFI QEMU DVD-ROM QM00001" ... Not Found).
• GET .../VirtualMedia/Cd answers Inserted: true, because the check is "the PVC is bound and has capacity". The same is true while the import is still running.
• A repeated InsertMedia with the same image is answered 204 ("already inserted") because the PVC is attached and the stored URL matches, so Ironic's retry does not import again.

The host is then "powered on, media inserted" from Redfish's point of view while it has nothing to boot. Ironic waits for the agent until its timeout and the operator sees a host stuck in inspecting.

Cause

handleImportPodCompleted treats Failed like Succeeded apart from the log line: it deletes the pod and calls removeImportingLabel. Nothing records that the attached PVC is empty, so IsVirtualMediaInserted and CheckInsertedMedia see a normal inserted device, and handlePowerAfterImport sees a VM whose import is over.

Fix

All in pkg/kubevirt/client.go.

• A failed import is ended in one patch (markImportFailed): the importing label is removed, power-after-import.redfish is removed, and the device is marked with the annotation import-failed.redfish/<device> = the pod name. One patch and not three because the VM watcher acts on the first event in which the importing label is gone; with separate writes the deferred power-on could still fire in between, which is the bug being fixed. The dropped power command is logged as a warning: Import of cdrom0 into VM ns/vm failed (pod ...); dropped the deferred power command On. Ironic is left waiting for a power state that does not come and retries the host, which is the expected outcome for a failed import; it was not exercised against a BareMetalHost here.
• Inserted means there is an image to boot. IsVirtualMediaInserted returns false while the importing label is set and while the failed marker is set, bound PVC or not.
• The next InsertMedia imports again. CheckInsertedMedia returns "nothing inserted" when the marker is set, whatever the URL, so the insert path runs, replaces the PVC as it already does for a re-insert, and clears the marker (next to the URL annotation it writes). The eject clears it too.
• A re-insert that is already accepted is compared as usual. With fix(server): Power On right after InsertMedia started the VM before its ISO import (empty CD-ROM, import pod stuck on the RWO volume) #36 the handler marks the VM as importing before the job replaces the PVC and clears the marker. In that window the marker is ignored, so a repeat of the same image answers "in progress" and another image answers 409, as for any pending import (second commit).
• A stale pod (one from an earlier insert cycle, after an eject and a new insert) is still ignored, as before.

Behaviour changes: after a failed import the VM is not started, power-after-import.redfish is removed, Inserted is false, InsertMedia with the same image answers 202 and imports again instead of 204; Inserted is also false while an import is running. The new annotation import-failed.redfish/<device> appears on the VM until the next insert or eject.

Not covered: a CDI (VolumeImportSource) import that fails is not detected today, since the PVC watcher only reacts to Bound; that is unchanged.

Verification on the cluster

OpenShift 4.22 / OpenShift Virtualization 4.22, the bridge built from fork main with #36 and this branch, an in-cluster nginx serving one ISO at 1.5 MB/s. Against a halted VM: InsertMedia with a URL on that server that returns 404 (curl --fail in the helper pod exits non-zero), then On once the importing label is on the VM:

20:02:12 insert missing.iso: HTTP=202
20:02:15 On: deferred HTTP=202
20:02:29 after failed import: status=Stopped  vmi=<none>  power-after-import.redfish=<none>  import-failed.redfish/cdrom0=copy-iso-rl-vm-2-bootiso-...
20:02:35 GET VirtualMedia/Cd  Inserted=false
20:02:35 re-insert same bad URL: HTTP=202          ← imports again (was 204)
20:02:46 insert good ISO: HTTP=202
20:02:48 import-failed.redfish/cdrom0=<none>       ← cleared by the new insert
20:03:40 good import done: Inserted=true  status=Stopped   (no power command pending, so the VM stays off)

Bridge log:

18:02:17.513Z Power action On deferred for VM redfish-prtest-vms/rl-vm-2 (import in progress)
18:02:23.716Z Import pod copy-iso-rl-vm-2-bootiso-1792951334-... failed for VM redfish-prtest-vms/rl-vm-2. Logs: curl: (22) The requested URL returned error: 404
18:02:23.782Z Import of cdrom0 into VM redfish-prtest-vms/rl-vm-2 failed (pod copy-iso-rl-vm-2-bootiso-1792951334-...); dropped the deferred power command On
18:02:43.227Z Import of cdrom0 into VM redfish-prtest-vms/rl-vm-2 failed (pod copy-iso-rl-vm-2-bootiso-1792951356-...); the device reads as not inserted until it is inserted again
18:03:39.654Z Import pod copy-iso-rl-vm-2-bootiso-1792951367-... succeeded for VM redfish-prtest-vms/rl-vm-2 volume cdrom0
18:03:39.712Z Removed importing label importing.redfish/cdrom0 from VM redfish-prtest-vms/rl-vm-2

No Successfully started VM for that VM at any point. The same run had two other VMs importing successfully with a deferred On; they started after their Removed importing label as before.

Tests

pkg/kubevirt/import_failed_test.go: a failed pod removes the importing label and the deferred power command, sets the marker, leaves the VM halted and the URL annotation alone, deletes the pod, and does it in exactly one patch (a counting wrapper around the dynamic client); a succeeded pod removes the label, keeps the deferred command for the watcher and sets no marker; a stale failed pod changes nothing; IsVirtualMediaInserted is true for a bound PVC and false with the importing label or the marker; CheckInsertedMedia returns "nothing inserted" with the marker for the same and for another image; a new insert and an eject clear the marker; with the marker and a pending re-insert, the same image is MediaStateImporting and another image is MediaStateConflict (added after the rebase; it failed with state = 0 before the second commit). With the constant alone and none of the logic, five of the seven fail (deferred power command still set: "On", Inserted = true, want false, state = 2, want MediaStateNone, annotation import-failed.redfish/cdrom0 ... survived the new insert / ... the eject); the tests do not compile on main without the constant.

go build ./..., go vet ./..., go test ./..., gofmt, go mod tidy (no change) pass; go test -race ./pkg/kubevirt/ passes.

Related

• Rebased onto main after fix(kubevirt): concurrent virtual-media insert and boot override could drop the CD-ROM disk from the VM spec #33, fix(server): Power On right after InsertMedia started the VM before its ISO import (empty CD-ROM, import pod stuck on the RWO volume) #36 and fix(server): a power-off is never deferred by a pending ISO import, and withdraws a deferred power-on #37 were merged. The only conflict was the one-line delete(annotations, ...) in EjectVirtualMedia, which now sits inside fix(kubevirt): concurrent virtual-media insert and boot override could drop the CD-ROM disk from the VM spec #33's updateVM closure. The cluster run above was done before the rebase, on a tree that already had fix(kubevirt): concurrent virtual-media insert and boot override could drop the CD-ROM disk from the VM spec #33, fix(server): Power On right after InsertMedia started the VM before its ISO import (empty CD-ROM, import pod stuck on the RWO volume) #36 and the first commit merged together. On the rebased branch, and for the second commit, only the unit tests, go vet and gofmt were run.
• fix(server): Power On right after InsertMedia started the VM before its ISO import (empty CD-ROM, import pod stuck on the RWO volume) #36 (merged) added the pending-import placeholder that CheckInsertedMedia also reads; the second commit orders the two checks.
• fix(server): a power-off is never deferred by a pending ISO import, and withdraws a deferred power-on #37 (merged) makes ForceOff/GracefulShutdown withdraw a deferred power-on on request; this PR withdraws it when the import itself fails.

[kubevirt-prow]

[APPROVALNOTIFIER] This PR is NOT APPROVED

This pull-request has been approved by:
Once this PR has been reviewed and has the lgtm label, please assign yanirq for approval. For more information see the Code Review Process.

The full list of commands accepted by this bot can be found here.

Details

Needs approval from an approver in each of these files:

• OWNERS

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

[kubevirt-prow]

Hi @itayherzberg. Thanks for your PR.

PRs from untrusted users cannot be marked as trusted with /ok-to-test in this repo meaning untrusted PR authors can never trigger tests themselves. Collaborators can still trigger tests on the PR using /test all.

I understand the commands that are listed here.

Details

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes-sigs/prow repository.

[MarSik]

So the workflow cancels the run command and the user must retrigger both import and VM start?

[itayherzberg]

Yes. When the import pod fails, the deferred power command is removed together with the importing label, so the client has to send InsertMedia again and then the power command again.

I dropped it instead of keeping it because a power-on left on the VM would run after whatever insert succeeds next, which can be much later and for a different image. That seemed worse than asking for the power command again.

What the client sees after the failure: PowerState stays Off, Inserted is false, and the same InsertMedia is answered 202 and imports again. The insert task is no help here: it already reads Completed, because the job ends once the import pod is created.

I expect Ironic to time out waiting for the power state and retry the step, but I have not run this against a BareMetalHost.

If you prefer to keep the deferred command on the VM until a later insert succeeds, so that only the insert has to be repeated, I can change it. It is a small change in markImportFailed.

[MarSik]

And I merged some of the other patches and not where is a merge conflict that needs to be resolved.

[itayherzberg]

Rebased onto main; the only conflict was the one-line marker cleanup in EjectVirtualMedia, now inside the updateVM closure from #33.

I also added a small second commit: with #36 in the base, a request for a different image sent while a re-insert after a failed import was still pending was answered "in progress" instead of 409. CheckInsertedMedia now ignores the failed marker once a new import is recorded. Unit tests only; the cluster run in the description predates the rebase.