Worked example and make target for the kvm-ssh Secret

docs/kvm-provider.md walks through key generation, ssh-copy-id,
ssh-keyscan under the address the operator dials, and the Secret from
the private key plus ~/.ssh/kvm_known_hosts. make kvm-ssh-secret runs
the same as an apply with KVM_SSH_KEY / KVM_KNOWN_HOSTS overrides and
refuses a .pub, the classic mistake. README mirrors the short form.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>

CHANGELOG.md

@@ -1,5 +1,41 @@
 # Changelog
 
+## 2026-09-10 10:07 UTC — KVM provider validated on a real hypervisor; UEFI default; libvirt call tracing
+
+- `make test-integration-kvm` passes end to end against a libvirt 11.6 / QEMU 10.1
+  host (Debian 13 image, UEFI, guest agent reporting the IP after ~20 s). Four
+  defects found only on the real host, all fixed on the branch:
+  - domain disks are now `type="file"` with resolved paths: pool-volume references
+    get no AppArmor rule from `virt-aa-helper`, so QEMU was denied the disks;
+  - domain metadata is parsed by local name: libvirt returns the element without
+    its namespace declaration;
+  - guests boot **UEFI by default** (`images.<key>.firmware: uefi|bios`, OVMF now a
+    host prerequisite): Debian 13's image hangs in GRUB under SeaBIOS on a headless
+    VM with a serial console (Debian bug #1111240, open); bookworm is unaffected;
+  - the image cache's raw-upload path is confirmed to produce a byte-identical file.
+- Every libvirt RPC is logged at `--zap-log-level=debug` as one `libvirt call` line
+  (`rpc=virDomainCreate`, identifiers, duration, `libvirtError` on failure); level 2
+  adds XML, metadata and addresses; cloud-init is never logged. The integration test
+  shows the trace in `-v` output (`KVM_TEST_LOG_LEVEL`, default 1).
+- Key files: `internal/provider/kvm/{domainxml.go,metadata.go,trace.go,conn.go}`,
+  `internal/provider/config_kvm.go`, `docs/kvm-provider.md`.
+
+## 2026-09-08 11:00 UTC — KVM/libvirt provider
+
+- New `kvm` provider type: Managed proxies as VMs on your own libvirt/KVM hosts. Each
+  host is reached over SSH with the libvirt unix socket forwarded through the
+  connection (pure Go, nothing to expose on the hypervisors beyond sshd); one provider
+  instance can span several hosts, selected by `placement.zone`.
+- Base images (`images:` map or a direct URL in `placement.image`) are downloaded by the
+  operator into each host's storage pool on first use, verified by sha256 when configured,
+  and cached there. Per-VM disks are qcow2 overlays; cloud-init arrives on a NoCloud seed
+  ISO built in-process. GC identity lives in the domain's `<metadata>` element.
+- Wiring: `"kvm": kvm.New` in `cmd/main.go`; optional `kvm-ssh` Secret mounted at
+  `/etc/proxy-operator/kvm`; samples `config/samples/proxy_kvm.yaml` and a `kvm-home`
+  block in `providers-config.yaml`; `docs/kvm-provider.md`; opt-in integration test
+  (`make test-integration-kvm`) against a real hypervisor.
+- Not validated on a real host at the time of this entry; see 2026-09-10 above.
+
 ## 2026-08-10 09:34 CEST — kind e2e verified; fix Squid OOM in containers; quickstart goes in-cluster
 
 - Full end-to-end pass on a throwaway kind cluster: Squid pod Ready with a real CONNECT

Makefile

@@ -178,6 +178,20 @@ uninstall: manifests kustomize ## Uninstall CRDs from the K8s cluster specified
 	@out="$$( "$(KUSTOMIZE)" build config/crd 2>/dev/null || true )"; \
 	if [ -n "$$out" ]; then echo "$$out" | "$(KUBECTL)" delete --ignore-not-found=$(ignore-not-found) -f -; else echo "No CRDs to delete; skipping."; fi
 
+KVM_SSH_KEY ?= $(HOME)/.ssh/proxy-operator_ed25519
+KVM_KNOWN_HOSTS ?= $(HOME)/.ssh/kvm_known_hosts
+KVM_SSH_NAMESPACE ?= egress-proxies-operator-system
+
+.PHONY: kvm-ssh-secret
+kvm-ssh-secret: ## Create or update the kvm-ssh Secret from KVM_SSH_KEY (private key) and KVM_KNOWN_HOSTS.
+	@test -f "$(KVM_SSH_KEY)" || { echo "KVM_SSH_KEY=$(KVM_SSH_KEY) not found"; exit 1; }
+	@test -f "$(KVM_KNOWN_HOSTS)" || { echo "KVM_KNOWN_HOSTS=$(KVM_KNOWN_HOSTS) not found"; exit 1; }
+	@grep -q 'PRIVATE KEY' "$(KVM_SSH_KEY)" || { echo "KVM_SSH_KEY=$(KVM_SSH_KEY) is not a private key (did you pass the .pub?)"; exit 1; }
+	"$(KUBECTL)" -n $(KVM_SSH_NAMESPACE) create secret generic kvm-ssh \
+		--from-file=id_ed25519="$(KVM_SSH_KEY)" \
+		--from-file=known_hosts="$(KVM_KNOWN_HOSTS)" \
+		--dry-run=client -o yaml | "$(KUBECTL)" apply -f -
+
 .PHONY: deploy
 deploy: manifests kustomize ## Deploy controller to the K8s cluster specified in ~/.kube/config.
 	cd config/manager && "$(KUSTOMIZE)" edit set image controller=${IMG}

README.md

@@ -15,9 +15,10 @@ itself**, and hands out to crawler clients via an HTTP list/lease API.
   cattle**: any meaningful spec change (placement, cloud-init, port)
   deletes and recreates the VM — never in-place mutation.
 - **Providers** behind one minimal interface: `kubernetes` (a real Squid
-  pod in this cluster — local dev/CI) and `gcp` (Compute Engine VMs with
-  ephemeral external IPs — the real egress fleet). Config is a YAML file
-  (`--providers-config`) with named instances (`gcp-eu`, `gcp-us`, ...).
+  pod in this cluster — local dev/CI), `gcp` (Compute Engine VMs with
+  ephemeral external IPs — the real egress fleet) and `kvm` (VMs on your
+  own libvirt hypervisors, reached over SSH). Config is a YAML file
+  (`--providers-config`) with named instances (`gcp-eu`, `kvm-home`, ...).
 - **Health engine** probes every proxy by fetching a URL *through* it (a
   real CONNECT tunnel — a proxy that accepts TCP but can't egress goes
   Unhealthy), with threshold logic and transition-only status writes.
@@ -131,6 +132,33 @@ make deploy IMG=<registry>/egress-proxies-operator:dev
    which also installs Squid via cloud-init). A missing field fails the
    Proxy with a message naming it.
 
+## KVM setup
+
+Managed proxies as VMs on libvirt/KVM hosts you own. Full guide:
+[docs/kvm-provider.md](docs/kvm-provider.md).
+
+1. Each host needs `libvirtd`, an SSH user in the `libvirt` group, a
+   bridge to a network with DHCP, and a storage pool.
+2. Create the `kvm-ssh` Secret from the operator's **private** key and a
+   `known_hosts` with each host's key; the manager mounts it at
+   `/etc/proxy-operator/kvm`:
+
+   ```sh
+   ssh-keyscan -H <host> >> ~/.ssh/kvm_known_hosts
+   kubectl -n egress-proxies-operator-system create secret generic kvm-ssh \
+     --from-file=id_ed25519=$HOME/.ssh/proxy-operator_ed25519 \
+     --from-file=known_hosts=$HOME/.ssh/kvm_known_hosts
+   # or: make kvm-ssh-secret   (same paths by default; KVM_SSH_KEY / KVM_KNOWN_HOSTS to override)
+   ```
+
+3. Add a `kvm` entry to the providers config with `images`,
+   `machineTypes` and `hosts` (see
+   [config/samples/providers-config.yaml](config/samples/providers-config.yaml)).
+   Base images are downloaded into each host's pool on first use.
+4. A Proxy names a host (`placement.zone`, optional with one host), a
+   size (`placement.machineType`) and an image (`placement.image`) — see
+   [config/samples/proxy_kvm.yaml](config/samples/proxy_kvm.yaml).
+
 Cloud-init from a Secret: the Secret **must** carry the label
 `crawl.example.com/cloud-init: "true"` — the operator's cache only holds
 labelled Secrets, so an unlabelled one is invisible (the Proxy reports

cmd/main.go

@@ -58,6 +58,7 @@ import (
 	"gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/internal/provider"
 	"gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/internal/provider/gcp"
 	"gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/internal/provider/kubernetes"
+	"gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/internal/provider/kvm"
 	"gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/internal/provider/registry"
 	"gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/internal/tracing"
 	"gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/internal/version"
@@ -187,6 +188,7 @@ func main() {
 		"gcp": func(ctx context.Context, pc provider.ProviderConfig) (provider.Provider, error) {
 			return gcp.NewWithWireOptions(ctx, pc, gcp.WireLogOptions{FullPayloads: gcpWireFullPayloads})
 		},
+		"kvm": kvm.New,
 	})
 	if err != nil {
 		setupLog.Error(err, "Failed to build providers")

config/manager/manager.yaml

@@ -145,9 +145,22 @@ spec:
         - name: providers-config
           mountPath: /etc/proxy-operator
           readOnly: true
+        # SSH material for kvm providers (sshKeyFile / knownHostsFile in the
+        # providers config point here). Optional: the mount is empty when the
+        # Secret does not exist, and only kvm entries need it. Create it with:
+        #   kubectl -n egress-proxies-operator-system create secret generic kvm-ssh \
+        #     --from-file=id_ed25519=<private key> \
+        #     --from-file=known_hosts=<known_hosts with every host's key>
+        - name: kvm-ssh
+          mountPath: /etc/proxy-operator/kvm
+          readOnly: true
       volumes:
       - name: providers-config
         configMap:
           name: providers-config
+      - name: kvm-ssh
+        secret:
+          secretName: kvm-ssh
+          optional: true
       serviceAccountName: controller-manager
       terminationGracePeriodSeconds: 10

config/manager/providers_config.yaml

@@ -9,8 +9,9 @@ metadata:
 data:
   # Mounted at /etc/proxy-operator/providers.yaml (--providers-config).
   # The default ships only the kubernetes-pod provider so the operator runs
-  # out of the box; add gcp entries (type: gcp, gcp.project: ...) for real
-  # egress fleets — see config/samples/providers-config.yaml.
+  # out of the box; add gcp entries (type: gcp, gcp.project: ...) or kvm
+  # entries (type: kvm, hosts reached over SSH) for real egress fleets —
+  # see config/samples/providers-config.yaml.
   providers.yaml: |
     providers:
       - name: kubernetes

config/samples/kustomization.yaml

@@ -4,5 +4,6 @@
 resources:
 - proxy_kubernetes.yaml
 - proxy_gcp.yaml
+- proxy_kvm.yaml
 - proxy_external.yaml
 # +kubebuilder:scaffold:manifestskustomizesamples

config/samples/providers-config.yaml

@@ -19,3 +19,38 @@ providers:
       # diskSizeGb: 10
       # auth: Application Default Credentials (workload identity
       # in-cluster, gcloud ADC locally). No key-file plumbing.
+  - name: kvm-home
+    type: kvm
+    kvm:
+      # SSH to each host with the libvirt unix socket forwarded through the
+      # connection; nothing to open on the hypervisors beyond sshd. Both
+      # files come from the optional kvm-ssh Secret mounted by
+      # config/manager/manager.yaml — see docs/kvm-provider.md.
+      sshKeyFile: /etc/proxy-operator/kvm/id_ed25519
+      knownHostsFile: /etc/proxy-operator/kvm/known_hosts
+      # insecureIgnoreHostKey: true   # skip host-key checks (not recommended)
+      # diskSizeGb: 10                # per-VM overlay; cloud-init grows the root fs into it
+      # vendorData: |                 # default installs qemu-guest-agent for IP discovery
+      #   #cloud-config
+      #   ...
+      images:
+        # placement.image names a key here (or is an https:// URL directly).
+        # Fetched into each host's pool on first use and cached there as
+        # base-<key>.qcow2; do not change an entry while Proxies use it.
+        debian-13:
+          url: https://cloud.debian.org/images/cloud/trixie/latest/debian-13-generic-amd64.qcow2
+          # sha256: "<64 hex>"        # optional; verified after download
+          # firmware: uefi            # default; "bios" only for images with no EFI partition
+          #                           # (Debian 13 hangs in GRUB under BIOS headless: Debian bug #1111240)
+        ubuntu-24.04:
+          url: https://cloud-images.ubuntu.com/noble/current/noble-server-cloudimg-amd64.img
+      machineTypes:                   # placement.machineType names a key here
+        small:  {vcpus: 1, memoryMiB: 1024}
+        medium: {vcpus: 2, memoryMiB: 2048}
+      hosts:                          # placement.zone names a host; optional with one host
+        - name: nas1
+          address: nas1.home.lan:22
+          user: virt                  # must be in the libvirt group
+          bridge: br0                 # to a LAN with DHCP; the VM's IP comes from there
+          # socket: /var/run/libvirt/libvirt-sock
+          # pool: default

config/samples/proxy_kvm.yaml

@@ -0,0 +1,43 @@
+# A Managed proxy backed by a libvirt/KVM hypervisor on the home network:
+# the operator boots a stock Debian cloud image as a VM on the named host,
+# with a NIC on the host's bridge (IP from the LAN's DHCP), and installs
+# Squid via cloud-init. Requires a providers-config entry named "kvm-home"
+# (see providers-config.yaml) and the kvm-ssh Secret (docs/kvm-provider.md).
+#
+# placement.zone is the host name from kvm.hosts (optional when only one
+# host is configured); machineType and image are keys in the provider's
+# machineTypes and images maps. The first Proxy for an image on a host
+# waits for the image download; later ones reuse the cached copy.
+apiVersion: crawl.example.com/v1alpha1
+kind: Proxy
+metadata:
+  name: proxy-kvm-sample
+spec:
+  mode: Managed
+  provider: kvm-home
+  placement:
+    zone: nas1
+    machineType: small
+    image: debian-13
+  port: 3128
+  cloudInit:
+    inline: |
+      #cloud-config
+      packages:
+        - squid
+      write_files:
+        - path: /etc/squid/conf.d/proxy-operator.conf
+          content: |
+            http_port 3128
+            http_access allow all
+            via off
+            forwarded_for off
+      runcmd:
+        - systemctl restart squid
+      # Optional: log in with `ssh debian@<ip>` (the Debian image's default
+      # user) to look around; `virsh console <name>` on the host works too.
+      # ssh_authorized_keys:
+      #   - ssh-ed25519 AAAA... you@laptop
+  attributes:
+    geo: home
+    purpose: crawl

docs/architecture.md

@@ -9,6 +9,7 @@
 | Provider contract | `internal/provider` | library | — | `Provider` interface, error taxonomy, deterministic naming, config, metrics decorator |
 | kubernetes provider | `internal/provider/kubernetes` | library | — | real Squid pods in this cluster (local dev/CI) |
 | gcp provider | `internal/provider/gcp` | library | — | Compute Engine VMs, four API calls, fire-and-forget ops |
+| kvm provider | `internal/provider/kvm` | library | — | VMs on libvirt hosts over SSH-forwarded sockets; image cache, overlay disks, NoCloud seeds |
 | Health engine | `internal/health` | Runnable | yes | through-the-proxy probes, thresholds, transition events |
 | Lease store | `internal/lease` | Runnable (expiry sweep) | no | in-memory leases + cooldowns, single mutex |
 | Discovery API | `internal/discovery` | Runnable | no | HTTP list/lease/release/report on `:8090` |
@@ -147,6 +148,25 @@ prov.ListByTag ─► AggregatedList(label filter,                   ─┘ prov
                     ReturnPartialSuccess: true)
 providerID = zones/<zone>/instances/<name> — zone-qualified, so Get/Delete
 stay correct even mid-replacement after a zone edit
+
+kvm provider (internal/provider/kvm/) — libvirt RPC over an SSH-forwarded unix socket, per host
+prov.Create ──► DomainLookupByName: exists → start if needed, done      ─┐ every step tolerates
+                else: ensure base image in pool (download on first use) │ the previous attempt
+                      overlay volume (exists = reuse)                    │ having got that far;
+                      seed ISO (always rebuilt — a cut-off upload must   │ the seed is the one
+                        never be trusted)                                │ thing redone
+                      DomainDefineXML + DomainCreate                    ─┘
+prov.Get    ──► DomainGetState + DomainGetMetadata + DomainInterfaceAddresses
+                  (ARP, then guest agent; first routable IPv4)
+                  running without IP = Provisioning; nostate = Provisioning
+prov.Delete ──► destroy (not running = fine) → undefine → delete overlay + seed by name
+prov.ListByTag ─► ConnectListAllDomains on every host, keep domains whose
+                    <metadata> carries managed=true; one host down fails the sweep,
+                    one unreadable domain is skipped
+providerID = hosts/<host>/domains/<name>; GC identity lives in the domain's
+<metadata> element (libvirt has no labels). All RPCs run under a context-
+bounded call: go-libvirt never times out on its own, so a cancelled reconcile
+closes the SSH connection to unblock it.
 ```
 
 The reconciler never watches provider-side resources (Pods or GCP VMs).
@@ -415,6 +435,41 @@ they read as choices, not accidents. Chronological by build step.
 - **Unknown GCP instance statuses map to `Stopped`:** the reconciler's
   answer to Stopped is delete-and-recreate, the always-safe move for
   cattle when the API grows a new state.
+- **KVM hosts are reached over SSH with the libvirt socket forwarded,**
+  not libvirtd's TCP/TLS listener: nothing to configure or expose on the
+  hypervisors beyond sshd, pure Go on the operator side (no cgo, no
+  libvirt libraries in the image), and the hosts list can grow by a
+  config edit because the providerID carries the host name.
+- **KVM base images are fetched by the operator into the host's pool**
+  through libvirt's upload stream, rather than expected to be pre-placed:
+  the operator then needs no filesystem access on the host and a new
+  host is usable with zero manual staging. The cost is a synchronous
+  first-time download inside Create.
+- **The KVM seed ISO is rebuilt on every Create attempt** before the
+  domain exists, instead of "exists → skip": a reconcile cancelled mid
+  upload leaves a truncated seed, and the compensating delete cannot run
+  because the connection was already closed to unblock the RPC. Skipping
+  it would boot a VM with no cloud-init and no retry would ever repair it.
+- **KVM `nostate` maps to `Provisioning`, not `Stopped`:** unlike GCP's
+  unknown statuses, `nostate` means libvirt could not determine the
+  state at all; answering that with delete-and-recreate is too drastic,
+  so the next poll decides.
+- **KVM guests boot UEFI by default, secure boot off.** Found on the
+  first real host: Debian 13's generic image hangs in GRUB under SeaBIOS
+  on a headless VM (Debian bug #1111240: `terminal_output gfxterm
+  serial` with a serial console and no video device) regardless of CPU
+  model or seed, and boots under OVMF with the serial console working.
+  The alternatives were a virtio console (loses the kernel's serial
+  output) or a video device the VMs have no use for. Every
+  current distro cloud image supports UEFI, so it is the default and
+  `firmware: bios` is the per-image escape; libvirt's firmware
+  autoselection (`<os firmware="efi">`) keeps the OVMF path out of the
+  operator's config. Secure boot is off so unsigned images boot too.
+- **A KVM domain GC cannot read is skipped, a host it cannot reach fails
+  the sweep.** GC never deletes what it does not see, so leaving one
+  domain out is safe; one corrupt domain blocking GC for every other one
+  is not. A whole host missing from the view would hide many, so that
+  still aborts.
 - **Kubernetes 403s classify as `ErrPermanent`** even though quota
   exhaustion also surfaces as 403 (indistinguishable from RBAC denial in
   `apierrors`): not hammering an API server that may never allow the

docs/kvm-provider.md

@@ -0,0 +1,275 @@
+# The KVM provider
+
+Runs Managed proxies as VMs on your own libvirt/KVM hypervisors. The
+operator reaches each host over SSH, forwards the libvirt unix socket
+through that connection, and talks libvirt's own RPC over it — so the
+hosts need nothing beyond `sshd` and `libvirtd`, and the operator image
+carries no libvirt libraries. VMs boot a stock distro cloud image that the
+operator downloads into the host's storage pool on first use, with the
+Proxy's cloud-init delivered on a NoCloud seed ISO built in-process.
+
+## Hypervisor prerequisites
+
+Per host, once:
+
+1. **libvirt + KVM** (`libvirtd` running, `/dev/kvm` present).
+2. **An SSH user in the `libvirt` group**, so it may open
+   `/var/run/libvirt/libvirt-sock`. The operator authenticates with a
+   private key; nothing else on the host is touched.
+3. **A bridge to a network with DHCP** (e.g. `br0` bridged onto the LAN).
+   Each VM gets one virtio NIC on it and takes its IP from that network's
+   DHCP; the cluster must be able to reach those IPs for health probes
+   and for crawlers to use the proxy.
+4. **A storage pool** (default `default`, usually `/var/lib/libvirt/images`)
+   with room for one base image per distro (a few hundred MB) plus the
+   per-VM overlays (`diskSizeGb` each, thin-provisioned).
+5. **UEFI firmware for guests**: the `ovmf` package on Debian/Ubuntu,
+   `edk2-ovmf` on Fedora/RHEL. VMs boot UEFI by default (libvirt picks
+   the OVMF binary itself); a domain start fails with "no firmware
+   found" without it. Only `firmware: bios` images skip this.
+6. Optionally, **outbound internet from the VMs**: the default
+   vendor-data installs `qemu-guest-agent` from the distro mirrors on
+   first boot. Without it the VM still works — the operator falls back to
+   the host's ARP table to find the IP, which fills in once the guest
+   sends traffic.
+
+Check from the operator's point of view before wiring it in:
+
+```sh
+ssh virt@nas1.home.lan virsh -c qemu:///system list --all   # user can drive libvirt
+ssh virt@nas1.home.lan virsh -c qemu:///system pool-info default
+ssh virt@nas1.home.lan ip link show br0
+```
+
+## Cluster-side setup
+
+1. Create the SSH Secret from a key pair dedicated to the operator and a
+   `known_hosts` file holding every host's key. The worked example below
+   uses `~/.ssh/proxy-operator_ed25519` and `~/.ssh/kvm_known_hosts`,
+   the same paths the integration test and `make kvm-ssh-secret` default
+   to.
+
+   ```sh
+   # once: a key pair for the operator; the .pub goes on every host
+   ssh-keygen -t ed25519 -f ~/.ssh/proxy-operator_ed25519 -N '' -C proxy-operator
+   ssh-copy-id -i ~/.ssh/proxy-operator_ed25519.pub virt@nas1.home.lan
+
+   # once per host: its host key, under the address the *operator* will
+   # dial (hosts[].address), which may differ from what your laptop uses
+   ssh-keyscan -H nas1.home.lan >> ~/.ssh/kvm_known_hosts
+
+   # the Secret: the PRIVATE key (not the .pub) plus known_hosts
+   kubectl -n egress-proxies-operator-system create secret generic kvm-ssh \
+     --from-file=id_ed25519=$HOME/.ssh/proxy-operator_ed25519 \
+     --from-file=known_hosts=$HOME/.ssh/kvm_known_hosts
+   ```
+
+   `make kvm-ssh-secret` runs that last command as an apply, so it also
+   updates an existing Secret; override the paths with
+   `KVM_SSH_KEY=... KVM_KNOWN_HOSTS=...`. Putting the `.pub` in the
+   Secret is the classic mistake: the operator then fails at startup
+   with a "not a private key" error. Without `known_hosts`, set
+   `insecureIgnoreHostKey: true` and accept that a MITM could hand you a
+   fake hypervisor.
+
+   `config/manager/manager.yaml` mounts the Secret (optional) at
+   `/etc/proxy-operator/kvm` as two files, `id_ed25519` and
+   `known_hosts`, which is what `sshKeyFile` and `knownHostsFile` in the
+   provider config point at. The deployment starts fine without the
+   Secret as long as no `kvm` provider is configured. Rotating the key:
+   re-run the command (or the make target) and restart the manager; it
+   reads both files once at startup.
+
+2. Add a provider entry to the providers config
+   (`config/manager/providers_config.yaml` in-cluster; full sample in
+   `config/samples/providers-config.yaml`):
+
+   ```yaml
+   - name: kvm-home
+     type: kvm
+     kvm:
+       sshKeyFile: /etc/proxy-operator/kvm/id_ed25519
+       knownHostsFile: /etc/proxy-operator/kvm/known_hosts
+       images:
+         debian-13:
+           url: https://cloud.debian.org/images/cloud/trixie/latest/debian-13-generic-amd64.qcow2
+       machineTypes:
+         small: {vcpus: 1, memoryMiB: 1024}
+       hosts:
+         - name: nas1
+           address: nas1.home.lan:22
+           user: virt
+           bridge: br0
+   ```
+
+   The operator reads the key and known_hosts at startup and refuses to
+   start if either is missing — a bad path fails fast, not on the first
+   Proxy.
+
+3. Apply a Proxy (`config/samples/proxy_kvm.yaml`) and watch it:
+
+   ```sh
+   kubectl get px -w
+   # NAME               MODE      PROVIDER   PHASE          IP             HEALTHY
+   # proxy-kvm-sample   Managed   kvm-home   Provisioning
+   # proxy-kvm-sample   Managed   kvm-home   Running        192.168.1.73
+   # proxy-kvm-sample   Managed   kvm-home   Ready          192.168.1.73   True
+   ```
+
+   The first Proxy for a given image on a given host sits in
+   `Provisioning` for the length of the image download; the operator log
+   shows `fetching base image into host pool` and `base image cached`
+   with the size and duration.
+
+## Config reference
+
+| Field | Required | Default | Meaning |
+|---|---|---|---|
+| `sshKeyFile` | yes | | private key used for every host |
+| `knownHostsFile` | unless `insecureIgnoreHostKey` | | OpenSSH `known_hosts` to verify host keys against |
+| `insecureIgnoreHostKey` | | `false` | skip host-key verification entirely |
+| `diskSizeGb` | | `10` | capacity of each VM's overlay disk; cloud-init's growpart expands the root fs into it |
+| `vendorData` | | installs `qemu-guest-agent` | cloud-init vendor-data placed on every seed next to the Proxy's user-data |
+| `images.<key>.url` | yes per entry | | http(s) URL of a cloud image (qcow2 or raw) |
+| `images.<key>.sha256` | | | expected digest; verified after download, a change triggers a re-download |
+| `images.<key>.format` | | `qcow2` | `qcow2` or `raw` |
+| `images.<key>.firmware` | | `uefi` | `uefi` (OVMF, secure boot off) or `bios` (SeaBIOS) for images without an EFI system partition; Debian 13 hangs in GRUB under BIOS on a headless VM, see *Known gaps* |
+| `machineTypes.<key>` | ≥ 1 | | `{vcpus, memoryMiB}` size profile |
+| `hosts[].name` | yes | | the `placement.zone` value that selects this host; unique |
+| `hosts[].address` | yes | | SSH endpoint, `host:port` |
+| `hosts[].user` | yes | | SSH user, member of the `libvirt` group |
+| `hosts[].socket` | | `/var/run/libvirt/libvirt-sock` | libvirt socket path on the host |
+| `hosts[].pool` | | `default` | storage pool for base images, overlays and seeds |
+| `hosts[].bridge` | yes | | host bridge for the VM's NIC |
+
+## Placement
+
+| Proxy field | Meaning for kvm |
+|---|---|
+| `placement.zone` | host name from `hosts`. May be omitted when exactly one host is configured; otherwise required. Unknown → `Failed` |
+| `placement.machineType` | key in `machineTypes`. Unknown → `Failed` |
+| `placement.image` | key in `images`, or an `http(s)://` URL used directly. Anything else → `Failed` |
+| `placement.region` | ignored |
+
+`Failed` here means the reconciler stops retrying and the message names
+the offending value; fix the spec (which replaces the VM) or the config.
+
+## What lands on the host
+
+For a Proxy whose deterministic name is `proxy-abc…`, on the chosen
+host's pool:
+
+| Object | Name | Lifetime |
+|---|---|---|
+| base image | `base-<key>.qcow2` (or `base-<url-hash>.qcow2` for a URL) | cached; survives Proxy deletion |
+| image marker | `base-<key>.qcow2.sha256` | with the base image |
+| overlay disk | `proxy-abc….qcow2`, qcow2 backed by the base | with the Proxy |
+| seed ISO | `proxy-abc…-seed.iso` | with the Proxy |
+| domain | `proxy-abc…` | with the Proxy |
+
+The domain is a q35 machine with host-passthrough CPU, the overlay on
+virtio, the seed on a SATA cdrom, one virtio NIC on the bridge, a serial
+console, the guest-agent channel, a virtio RNG and no graphics. Its
+`<metadata>` carries the operator's element (managed flag, owning UID,
+creation time) — that is how orphan GC recognises its own VMs, since
+libvirt has no labels.
+
+## The image cache
+
+The base image is downloaded **by the operator, through libvirt**, into
+the host's pool the first time a Proxy asks for it on that host — nothing
+is pre-placed on the hypervisor, and the operator needs no filesystem
+access there. The bytes stream from the URL through the operator into
+the pool with a running sha256; nothing is buffered. The marker volume is
+written last and holds the digest, so a crash mid-download leaves a base
+volume without a marker, which the next attempt deletes and redoes.
+
+A re-download happens when: the marker is missing, or `sha256` is
+configured and differs from the marker's content. Otherwise the cached
+copy is used for as long as it exists, even if the URL's content changed
+upstream (a `latest` URL is pinned at the moment of first fetch, per
+host).
+
+To evict manually:
+
+```sh
+ssh virt@nas1 virsh -c qemu:///system vol-delete --pool default base-debian-13.qcow2.sha256
+ssh virt@nas1 virsh -c qemu:///system vol-delete --pool default base-debian-13.qcow2
+```
+
+⚠️ **Do not change an image entry's `url` or `sha256`, and do not evict
+its base volume, while Proxies using that image exist on the host.** The
+overlays back onto the base file; deleting or replacing it corrupts every
+VM that uses it. Delete those Proxies first, or add the new image under a
+new key and move Proxies over by changing their `placement.image` (which
+replaces the VM).
+
+## Logging into a VM
+
+- Put your key in the Proxy's cloud-init (`ssh_authorized_keys`) and
+  `ssh debian@<ip>` (Debian) / `ssh ubuntu@<ip>` (Ubuntu).
+- Or on the host: `virsh console proxy-abc…` attaches to the serial
+  console; cloud-init's output scrolls by there on first boot.
+- `virsh domifaddr proxy-abc… --source arp` / `--source agent` shows what
+  the operator sees when it looks for the IP.
+
+## Logging
+
+The provider logs through controller-runtime's logger, named `kvm`, with
+`provider`, `host` and `name` (the domain) on every line.
+
+- `--zap-log-level=debug` (logr V(1)): one line per provider operation
+  (`domain defined`, `KVM domain ensured running`, ...) **and one
+  `libvirt call` line per libvirt RPC**, named `kvm.libvirt`, with
+  `rpc` (the libvirt API function, e.g. `virDomainLookupByName`), the
+  identifiers it was given (`domain`, `pool`, `volume`), curated results
+  (`state`, `path`, `interfaces`), `duration`, and on failure `error`
+  plus `libvirtError` (the code name, e.g. `ErrNoDomain`) and
+  `libvirtCode`. Connection events (`libvirt host connected`, dial
+  failures, `libvirt connection dropped` with a reason) log at the same
+  level. A Create is about ten RPCs; a Get is four.
+- `--zap-log-level=2`: the same lines also carry the domain and volume
+  `xml`, the `metadata` element, the interface `addresses` and the
+  domain `names` from a listing.
+- Cloud-init is never logged at any level: the seed ISO upload reports
+  only `length` and `duration`. There is no raw wire tier like the GCP
+  provider's V(5); go-libvirt exposes no hook for it.
+
+## Known gaps
+
+- **No quota or capacity detection.** libvirt reports an out-of-space
+  pool or an over-committed host as an ordinary error; the reconciler
+  treats it as transient and retries with backoff rather than the slower
+  quota backoff.
+- **Orphan volumes without a domain are invisible to GC.** A crash
+  between creating the volumes and defining the domain leaves an overlay
+  and seed that `ListByTag` cannot see (it lists domains). They are
+  cleaned when the same Proxy reconciles again (Delete removes volumes by
+  name even with no domain), but a Proxy CR that is gone for good leaves
+  them for `virsh vol-list` to find.
+- **The first image fetch is synchronous.** It holds a reconcile worker
+  for the download (LAN speed, a few hundred MB, once per image per
+  host). Other Proxies keep reconciling on the remaining workers.
+- **Replacing an image in use breaks running VMs** — see the warning
+  under *The image cache*.
+- **IP discovery needs either guest traffic or the agent.** A VM on a
+  bridge with no DHCP never gets an address and stays `Provisioning`
+  forever; check `virsh console`.
+- **Debian 13 cloud images hang in GRUB under BIOS on a headless VM**
+  ([Debian bug #1111240](https://bugs.debian.org/1111240), open, in
+  `grub2`): trixie's image ships `terminal_output gfxterm serial` in its
+  GRUB config, and with a serial console but no video device (exactly
+  the domain this provider defines) GRUB prints "Booting" and never
+  hands over to the kernel. Not host-specific; reproduced by the Debian
+  cloud team. The same image boots under UEFI with the serial console
+  intact, which is why `firmware` defaults to `uefi`. Debian 12
+  (bookworm) images are unaffected and boot either way. Images that
+  need `firmware: bios` are the exception, not the rule.
+
+## Testing
+
+Unit tests run over an in-memory fake of the libvirt API. The optional
+integration test against a real host is described in
+[testing.md](testing.md#the-kvm-integration-test-real-hypervisor); its
+`-v` output includes the `libvirt call` trace above, at the verbosity
+`KVM_TEST_LOG_LEVEL` selects (default 1).

docs/plans-executions/2026-09-04-1404-kvm-provider.md

@@ -8,7 +8,7 @@ Plan: [2026-09-04-1404-kvm-provider.md](../plans/2026-09-04-1404-kvm-provider.md
 - [x] Step 3 — Transport + errors (`conn.go`, `errors.go`)
 - [x] Step 3b — Image cache (`image.go`)
 - [x] Step 4 — Provider methods (`kvm.go`) over a fake API
-- [ ] Step 5 — Wiring, manifests, samples, docs, CHANGELOG
+- [x] Step 5 — Wiring, manifests, samples, docs, CHANGELOG
 - [x] Step 6 — Integration test against a real hypervisor (written and compiled; first real run is part of Step 7)
 - [ ] Step 7 — Manual validation + MR
 
@@ -69,6 +69,9 @@ Two design choices differ from the plan text:
   `<disk type="volume"><source pool=... volume=.../>`, so only the *base*
   image path is ever looked up (the overlay's `<backingStore>` needs a real
   path). Fewer RPCs and the builder's inputs are all names.
+  **Reverted in Step 7**: volume-referenced disks cannot start on an
+  AppArmor host, see there. The domain XML is back to `type="file"` with
+  the two `StorageVolGetPath` calls the plan had.
 - **Capacities are always `unit="bytes"`.** libvirt's `G` means GiB but
   `GB` means 10^9; spelling the byte count out removes the ambiguity from
   both the overlay and the seed/base volumes.
@@ -78,7 +81,9 @@ The metadata element is written with a default namespace
 marshal. libvirt may hand it back prefixed; `parseInstanceMetadata` is
 tested against both spellings since `encoding/xml` matches on the namespace
 URI. Whether libvirt accepts the default-namespace form on `DomainDefineXML`
-is confirmed in Step 6 against a real host, not here.
+is confirmed in Step 6 against a real host, not here. (Step 7: it does,
+but `DomainGetMetadata` returns the element with no namespace at all; the
+parser now matches on local name only.)
 
 Checked before relying on `github.com/kdomanski/iso9660` for the seed: its
 filename mangling lowercases and keeps `-`, so `user-data`/`meta-data`/
@@ -338,3 +343,217 @@ Step 3b "confirm on a real host" notes get answered. The test's config
 is built directly rather than through the provider package's validation
 (unexported), so a typo in an env var surfaces from `New` or from
 libvirt, not from a validation message.
+
+## Step 5 — Wiring, manifests, samples, docs, CHANGELOG
+
+Done after Step 6 (see that entry for why the order flipped). Everything
+the plan listed, plus a few things it did not:
+
+- `cmd/main.go`: `"kvm": kvm.New` in the builtins map. No RBAC change —
+  the provider talks to hypervisors, not the API server.
+- `config/manager/manager.yaml`: `kvm-ssh` Secret mounted read-only at
+  `/etc/proxy-operator/kvm` with `optional: true`, so deployments without
+  a kvm provider are unaffected. It nests under the providers-config
+  mount at `/etc/proxy-operator`; kustomize renders it (`kubectl
+  kustomize config/default` checked). The container runs as uid 65532
+  and Secret files default to 0644, so the key is readable without an
+  `fsGroup`; the `kubectl create secret` recipe is in a comment next to
+  the mount, in `docs/kvm-provider.md` and in the README.
+- `config/samples/providers-config.yaml`: `kvm-home` block with Debian 13
+  and Ubuntu 24.04 official image URLs, two machine types, one host, and
+  every optional field shown commented out. Parsed through
+  `provider.LoadConfigFile` in a throwaway test to make sure the sample
+  validates. `config/samples/proxy_kvm.yaml` uses the GCP sample's squid
+  cloud-init and shows `ssh_authorized_keys` commented out rather than
+  set — a sample with a placeholder key would either fail cloud-init or
+  invite pasting a real key into a committed file. Added to the samples
+  kustomization; `config/manager/providers_config.yaml`'s comment now
+  mentions kvm.
+- `docs/kvm-provider.md`: prerequisites with a three-line preflight
+  (`virsh list`, `pool-info`, `ip link` over ssh), cluster setup, the full
+  config reference table, placement table, a table of what lands on the
+  host and its lifetime, how the image cache works and how to evict, the
+  **warning not to change or evict an image while Proxies use it** (the
+  reviewer's finding from Step 4, carried as a documented rule since the
+  content-addressed-naming alternative was not chosen), how to log in,
+  and the known gaps.
+- README: providers bullet and a "KVM setup" section mirroring the GCP
+  one. `docs/architecture.md`: components row, a §5 block for the kvm
+  call flow in the same style as the other two, and five decision-log
+  entries (SSH transport, operator-fetched images, seed always rebuilt,
+  `nostate` → Provisioning, skip-vs-fail in the GC sweep).
+- `CHANGELOG.md` entry at the top, stating explicitly that the provider
+  is not yet validated on a real host.
+
+Verification: `go build ./...`, `go vet ./...`, `go test -short` on
+`cmd` and `internal/provider/...`, and both kustomizations rendered.
+`hack/providers-dev.yaml` untouched, as planned.
+
+Worth noting: the CRD has no rule requiring all three placement fields
+(that is GCP's own check), so the single-host "zone may be omitted"
+behaviour works without an API change. And with this step the branch is
+feature-complete but **unproven**: Step 7 runs the integration test and
+the end-to-end checklist against a real hypervisor before the MR.
+
+## Step 7 — Manual validation + MR (in progress)
+
+Host: `beelink` (Ubuntu, libvirt 11.6.0, QEMU 10.1.0, pool `default` at
+`/srv/vms/images` on local ext4, bridge `br0`), reached over Tailscale as
+`beelink.tail8c69c.ts.net`, SSH user `novakj`. Not the `nas1.home.lan`
+the plan and samples name; that host does not resolve from the dev box.
+
+```bash
+export KVM_TEST_HOST=beelink.tail8c69c.ts.net:22
+export KVM_TEST_USER=novakj
+export KVM_TEST_SSH_KEY=$HOME/.ssh/proxy-operator_ed25519
+export KVM_TEST_KNOWN_HOSTS=$HOME/.ssh/kvm_known_hosts
+export KVM_TEST_BRIDGE=br0
+export KVM_TEST_IMAGE_URL=https://cloud.debian.org/images/cloud/trixie/latest/debian-13-generic-amd64.qcow2
+make test-integration-kvm
+```
+
+### Run 1 and 2: `Could not open '/srv/vms/images/base-test-image.qcow2': Permission denied`
+
+Everything up to `DomainCreate` worked on the first try against a real
+host, which answers the open notes from Steps 2 and 3b: the SSH-forwarded
+libvirt handshake, the raw qcow2 upload plus pool refresh as a backing
+image, the default-namespace metadata element, and `DomainDefineXML` for
+the generated XML were all accepted by libvirt 11.6. QEMU then exited at
+start with `Permission denied` on the base image.
+
+Ownership was ruled out the slow way: the file was `root:root 0600` (the
+dir-pool default; libvirt's DAC driver chowns the chain at start and
+restores it after a failed start, so that observation meant nothing),
+`qemu.conf` was all defaults (`libvirt-qemu`, `dynamic_ownership=1`), and
+after a manual `chown libvirt-qemu:kvm` the second run failed identically.
+
+The actual cause is the Step 2 choice of `<disk type="volume">`.
+libvirt's AppArmor helper builds each domain's profile from the domain XML
+without consulting the storage driver, and its `add_file_path` only emits a
+rule when the source has a `path`; a volume-referenced disk has pool and
+volume names instead, so neither the overlay nor its backing image gets a
+rule and QEMU is denied on the first one it opens. Every stock Debian and
+Ubuntu hypervisor confines QEMU this way. The unit tests could not have
+caught it: the fake accepts either form.
+
+Fix, in this step: `buildDomainXML` takes `DiskPath`/`SeedPath` and emits
+`type="file"` disks; `ensureOverlay` and `writeSeed` return the volume
+handles (the exists-already branch now does a `StorageVolLookupByName`),
+and Create resolves both paths with `StorageVolGetPath` before defining
+the domain. Two extra cheap RPCs per Create. `TestBuildDomainXML_fieldByField`
+now fails on any `type="volume"` or `pool=` attribute so the design cannot
+drift back, and `TestCreate_freshHost` asserts the disk sources equal the
+paths the fake reports.
+
+Worth noting: the first two runs left the base image and its marker in
+the pool as designed, so later runs skip the 435 MB download.
+
+### Run 3: `parsing domain metadata: expected element <instance> in name space … but have no name space`
+
+With file-backed disks, Create returned in 1 s (image cached) and the
+domain started. Get then failed to parse the metadata: libvirt 11.6 finds
+the element by our URI but returns it as a bare `<instance>` with no
+namespace declaration at all. Step 2 had tested the default-namespace and
+prefixed spellings and left "does libvirt accept the default-namespace
+form" for the real host; it does, it just does not give it back that way.
+
+Fix: `parseInstanceMetadata` matches on the local name only, since the
+lookup already selected the element by URI. The fake now strips the
+declaration when storing metadata, so the provider's Get and ListByTag
+tests parse the shape libvirt really returns, and a new
+`TestParseInstanceMetadata_libvirtBareForm` pins it.
+
+### Run 4: guest hangs at GRUB's "Booting" line
+
+Create and start passed; Get polled `Provisioning` with no IP while the
+VM sat at 100 % CPU after GRUB printed "Booting `Debian GNU/Linux`" and
+before the kernel wrote anything to the serial console. The domain XML
+matches a working VM on the same host (q35, BIOS, host-passthrough,
+virtio disk, SATA cdrom, br0), so the difference is the disk content:
+the cached image was downloaded without a checksum and never verified.
+Diagnosis was handed to the user (sha512 against Debian's published
+sums, `qemu-img check`, and a `virt-install --import` of the same image
+outside the operator). Because the provider's own logs were invisible in
+the test output, this run also produced a side plan:
+[2026-09-10-0805-kvm-libvirt-tracing](2026-09-10-0805-kvm-libvirt-tracing.md),
+which traces every libvirt RPC at V(1) and routes it into `-v` output.
+
+### Run 5: the guest hang is Debian 13's BIOS boot path; UEFI fixes it
+
+The cached image's sha512 matched Debian's published sum, and
+`qemu-img info` showed a sound 3 GiB qcow2, which also confirms that
+the raw upload over a libvirt-created volume plus pool refresh yields a
+byte-identical file (the Step 3b note is answered). Bisected by hand on
+beelink with `virt-install --import` on a fresh overlay of the same
+image:
+
+| variant | seed | CPU | firmware | result |
+|---|---|---|---|---|
+| operator's domain | ours | host-passthrough | SeaBIOS | hangs after GRUB "Booting", 100 % CPU |
+| bare | none | host-passthrough | SeaBIOS | same hang |
+| bare | none | host-model | SeaBIOS | same hang |
+| bare | none | host-passthrough | **OVMF (`--boot uefi`)** | **boots to login** |
+
+So neither the seed ISO, the domain XML nor the CPU model was the
+problem: the image's legacy GRUB → kernel handoff does not work on this
+host, while its EFI stub path does. Not diagnosed further; it is
+Debian's chain, not ours, and every current cloud image boots UEFI.
+
+Change: `images.<key>.firmware` (`uefi` default, `bios` escape),
+threaded through `withDefaults` → `imageSource` → `domainParams`, and
+`buildDomainXML` emits `<os firmware="efi"><firmware><feature
+enabled="no" name="secure-boot"/></firmware>` so libvirt selects the
+OVMF binary and creates the NVRAM file; the `nvram` undefine flag Delete
+already passes removes it (seen on the host: `virsh undefine` without
+`--nvram` refuses such a domain). Direct-URL images default to UEFI
+too. Docs: OVMF is a new hypervisor prerequisite, config table row,
+sample comment, known-gaps entry, decision-log entry.
+
+Worth noting: the first image download went through with no checksum
+configured, and the cache reuses a base image by key, so switching
+`KVM_TEST_IMAGE_URL` requires deleting `base-test-image.qcow2` and its
+marker by hand first. That is the reviewer's Step 4 finding showing up
+in practice; still documented rather than fixed.
+
+Follow-up, same day: the cause is known upstream. [Debian bug
+#1111240](https://bugs.debian.org/1111240) (filed 2025-08-16 against
+the cloud image, reassigned to `grub2`, still open as of 2026-09-10;
+trixie ships grub2 2.12-9+deb13u2) reports exactly this with a domain
+XML almost identical to ours: BIOS, virtio disk, SATA cdrom seed, bridge
+NIC, `<console><target type='serial'/>`, no `<graphics>`/`<video>`.
+The cloud team reproduced it: trixie's grub.cfg has `terminal_output
+gfxterm serial`, and with a serial port present but no video adapter
+GRUB never hands over to the kernel. Their fix in the image
+(`terminal_output serial`) is not something an operator can apply;
+the reporter's workaround (console `target type='virtio'`) boots but
+takes the kernel's `console=ttyS0` output with it. UEFI sidesteps the
+gfxterm path and keeps the serial console, so the decision stands, but
+the docs now name the bug rather than blaming the host, and note that
+bookworm images are unaffected. `latest` on cloud.debian.org was the
+2026-08-31 build when this was hit, so every trixie point release to
+date carries it.
+
+### Run 6: pass
+
+With UEFI the full lifecycle passed in 23 s on a warm cache: Create 2 s
+(domain start 0.9 s), guest agent answering with `192.168.0.89` after
+20 s (ARP never did; the host had not talked to the guest), TCP 22
+reachable from the dev machine, ListByTag seeing it, Delete leaving only
+the base image and marker in the pool, second Delete a no-op. Trace
+excerpt worth keeping for the record:
+
+```
+09:44:28.603 libvirt virDomainDefineXML xmlBytes=1509 domain=proxy-hk5oavoqk45n3twq duration=13.51ms
+09:44:28.603 kvm domain defined uid=9bbceb41-… firmware=uefi
+09:44:29.542 libvirt virDomainCreate domain=proxy-hk5oavoqk45n3twq duration=938.705ms
+09:44:49.573 libvirt virDomainInterfaceAddresses domain=proxy-hk5oavoqk45n3twq source=DomainInterfaceAddressesSrcAgent interfaces=2 duration=1.742ms
+09:44:49.573 kvm KVM domain fetched state=Running ip=192.168.0.89 uid=9bbceb41-…
+```
+
+Worth noting: the sweep listed a second managed domain,
+`proxy-qxge3dbm2mnpc3ih`, shut off, left behind by an earlier failed
+run whose cleanup never ran. That is exactly the orphan GC exists for;
+on the host it needs `virsh undefine --nvram` plus its two volumes by
+hand. The `ListByTag` sweep costs one `virDomainGetMetadata` per
+domain on the host (21 here, ~0.4 ms each over the tunnel), which is
+fine at this scale but is the call to watch on a busy hypervisor.

docs/plans-executions/2026-09-10-0805-kvm-libvirt-tracing.md

@@ -0,0 +1,109 @@
+# Execution: Trace every libvirt call in the KVM provider
+
+Plan: [2026-09-10-0805-kvm-libvirt-tracing.md](../plans/2026-09-10-0805-kvm-libvirt-tracing.md)
+
+- [x] Step 0 — Save plan
+- [x] Step 1 — `errors.go`: shared error fields
+- [x] Step 2 — `trace.go`: the `tracingAPI` decorator
+- [x] Step 3 — `conn.go`: pool logging and wrapping
+- [x] Step 4 — Call sites
+- [x] Step 5 — Integration test output
+- [x] Step 6 — Unit tests
+- [x] Step 7 — Docs, execution log, CHANGELOG
+
+## Steps 1–6 — Tracer, pool logging, tests, integration wiring
+
+Done as one commit on `feat/kvm-provider`; the plan's assumption that
+this belongs on the KVM branch rather than its own feature branch was
+accepted at plan approval.
+
+The code follows the plan closely. Things that came out differently
+or are worth knowing:
+
+- **Logger names join with `/` in funcr, `.` in zap.** The trace lines
+  are `kvm/libvirt` in the unit-test capture and in `testr` output, and
+  `kvm.libvirt` under the operator's zap logger. The docs use the zap
+  spelling; the unit test asserts the funcr one. First run of the tier
+  test failed on exactly this.
+- **Cancel is not reported as a transport error.** The original `call`
+  dropped the connection twice on cancellation (once from the abort
+  closure, once from the "not a libvirt error" branch, harmlessly, since
+  drop is idempotent). With a log line on each drop that would have
+  printed both `context cancelled` and `transport error` for one event,
+  so the transport branch now skips `ctx.Err()`. Covered by
+  `TestHostPool_call_logsDropReason`.
+- **`ConnectListAllDomains` in the fake includes every defined domain**,
+  so the trace test's fixture (one running managed domain plus one
+  stopped domain for `DomainCreate` to start) lists two; the V(2)
+  assertion checks for the `names` key rather than an exact list.
+- **`libvirtErrorFields` also feeds `logAPIError`**, which therefore
+  gains `libvirtCodeName` (e.g. `ErrNoDomain`) next to the numeric code.
+- The seam-coverage guard (`reflect` count of `libvirtAPI` methods vs
+  the test table) is the only thing standing between a future 18th RPC
+  and a silently untraced call; keep it.
+
+Verification run before committing:
+
+```bash
+go build ./... && go vet ./... && go vet -tags=integration ./internal/provider/kvm/
+go test -short ./...
+go test -race -count=1 -cover ./internal/provider/kvm/   # 90.2 %, up from 88.2
+go test -tags=integration -count=1 -run TestKVM ./internal/provider/kvm/   # self-skips without env
+```
+
+Worth noting: the live run (`make test-integration-kvm` against beelink)
+had not happened when this was written; it is what Step 7 of the KVM
+provider plan is waiting on, and its output is the acceptance test for
+this feature. Expected shape is in the plan's Verification section.
+
+## Revision after the first live run — less noise, libvirt names
+
+The first live run on beelink showed the trace working but hard to read:
+`testr` printed `"ts"`, `"level"`, `"msg"` and the three per-run
+constants on every line, the error text appeared twice (`error` and
+`libvirtMessage`), `host` appeared twice on image-cache lines (the
+logger already carried it), and `method=DomainLookupByName` was
+go-libvirt's name rather than something to look up in libvirt's docs.
+The user asked for "less verbose but more informative". Changes:
+
+- The tracer's headline field is now `rpc=virDomainLookupByName`: the
+  public libvirt API function, which go-libvirt's method names are
+  exactly minus the `vir` prefix (they come from the same
+  `remote_protocol.x`). Not gRPC, for the record: libvirt's own
+  XDR-based RPC over the forwarded unix socket.
+- Errors are one `error` field plus `libvirtError=ErrNoDomain` and
+  `libvirtCode=42`; `libvirtMessage` is gone from both the tracer and
+  `logAPIError`, since it is the error text.
+- `image.go` no longer adds `host` to lines whose logger has it.
+- The integration test replaces `testr` with a small `compactSink`
+  (`logr.LogSink` plus `GetCallStackHelper`, so `t.Log` still
+  attributes lines to `trace.go`): `HH:MM:SS.mmm libvirt
+  virDomainCreate domain=… duration=… error=… libvirtError=…`. The
+  `rpc` value becomes the headline, `provider`/`host`/`name` are
+  dropped (the run's first `t.Log` line states them), and values with
+  spaces are quoted. Production zap output is unchanged apart from the
+  field renames; structured logs are meant to repeat context.
+
+Previewed by driving the sink through the fake provider with an
+injected `DomainCreate` failure (a throwaway integration-tagged test,
+not committed):
+
+```
+trace.go:55: 09:04:33.165 libvirt virDomainLookupByName domain=proxy-abc123def456ghij duration=4µs error="Domain not found: …" libvirtError=ErrNoDomain libvirtCode=42
+trace.go:55: 09:04:33.165 libvirt virStorageVolUpload pool=default volume=proxy-abc123def456ghij-seed.iso offset=0 length=0 duration=71µs
+kvm.go:262:  09:04:33.165 kvm seed volume uploaded volume=proxy-abc123def456ghij-seed.iso bytes=45056
+trace.go:55: 09:04:33.165 libvirt virDomainCreate domain=proxy-abc123def456ghij duration=0s error="internal error: process exited…" libvirtError=ErrResourceBusy libvirtCode=87
+```
+
+Worth noting: `length=0` on `virStorageVolUpload` is what the provider
+passes (libvirt reads to EOF); the following `seed volume uploaded`
+line has the byte count.
+
+## Step 7 — Live run confirmed; CHANGELOG
+
+The compact trace was accepted on the first passing live run
+(2026-09-10, beelink): one line per RPC with the libvirt function name,
+the provider's own lines between them, `Provisioning` polls readable at
+a glance (`SrcArp interfaces=0`, `SrcAgent … ErrAgentUnresponsive`
+until the agent came up at +20 s), and a full `ListByTag` sweep over 21
+domains in 15 ms. CHANGELOG entry added under the KVM validation entry.

docs/plans/2026-09-10-0805-kvm-libvirt-tracing.md

@@ -0,0 +1,186 @@
+# Plan: Trace every libvirt call in the KVM provider
+**Created:** 2026-09-10 08:05
+
+## Context
+
+Step 7 of the KVM provider plan (live validation on `beelink`) has gone through
+three fixes found only on the real host, and the current failure (guest hangs at
+GRUB's "Booting" line) is being diagnosed blind: the provider logs at V(1)/V(2)
+but nothing shows them. The integration test never installs a logger, so
+controller-runtime prints "log.SetLogger(...) was never called" and swallows
+everything; and even with a logger, the provider only logs per *operation*
+(Create, Get…), not per libvirt RPC, so the sequence and timing of what was
+actually sent to the hypervisor is invisible.
+
+Goal: one log line per libvirt call at debug level (`--zap-log-level=debug`, logr
+V(1) in this repo's scheme: V(1) = outcome per operation, V(2) = curated detail,
+V(5) = raw wire, per the GCP verbose-logging plans), with method, host, domain or
+volume, duration and the libvirt error code on failure; and those lines visible in
+`make test-integration-kvm` output.
+
+Assumption: this lands on the current `feat/kvm-provider` branch, since it exists
+to finish that branch's validation, and the plan file plus execution log follow
+CLAUDE.md conventions (plan committed alone first, execution summary alongside
+each step). Say so if you want a separate branch instead.
+
+## Design
+
+- **Decorator, not call-site logging.** New `tracingAPI` implements the 17-method
+  `libvirtAPI` seam (`internal/provider/kvm/conn.go:26-44`), wrapping the real
+  client. Every method logs one V(1) line after the inner call returns. Applied in
+  `hostPool.call`, so every provider method, `image.go`'s cache and the
+  integration test's own `p.hosts.call` are traced with no per-site changes.
+- **Logger passed explicitly.** `call(ctx, log, host, fn)` and `get(ctx, log, host)`
+  gain a `logr.Logger` parameter, matching how this package already threads `log`
+  into every helper. The five call sites (`kvm.go:169, 322, 458, 530`,
+  `kvm_integration_test.go:220`) already hold the right logger with
+  provider/host/name values. `call` does `log = log.WithName("libvirt")`, so trace
+  lines are named `kvm.libvirt`.
+- **Wrap only when `log.V(1).Enabled()`.** Zero cost at info level; the
+  controller-runtime unfulfilled root sink reports disabled, so unit tests and
+  `conn_test.go`'s `hostClient{api: nil}` cases are unaffected.
+- **One line per RPC at every level.** At V(2) the same line gains extra keys
+  (`xml`, `metadata`, `addresses`, `names`) instead of a second line. Upload and
+  download log offset/length/duration only, never bytes (the seed ISO carries
+  cloud-init). Domain and volume XML contain no secrets, so V(2) is fine for them.
+- **Connection events traced too** in the pool: dial with duration, dial failure,
+  dead cached client redial, and both drop reasons (context cancelled, transport
+  error). `dialSSH`/`connectLibvirt`/`keepalive` stay untouched: changing
+  `hostDialer`'s signature would ripple into every test dialer, and the pool
+  already observes every event.
+- **Rendering.** Handles by name only (`domain`, `pool`, `volume`), never UUID/Key.
+  `libvirt.DomainState` and `DomainInterfaceAddressesSource` have stringers, pass
+  them typed. Bitmask flags don't stringify, log as integers only when non-zero.
+  `libvirt.OptString` → first element or `""` under `uri`.
+- **awaitOrCancel.** `done` runs inside fn's goroutine; on the normal path it logs
+  before `call` returns. On cancel, the abandoned RPC logs one late line when the
+  closed connection makes it fail: desirable in production, and in the integration
+  test only reachable in an already-failing timeout run (testr panics on a log after
+  the test ends; note that in the header, don't engineer around it).
+
+## Steps
+
+### Step 0 — Save plan
+Copy this file to `docs/plans/2026-09-10-0805-kvm-libvirt-tracing.md`, commit alone.
+
+### Step 1 — `errors.go`: shared error fields
+Factor `libvirtErrorFields(err error) []any` out of `logAPIError` (`errors.go:62-72`):
+returns `libvirtCode` (uint32), `libvirtCodeName` (`libvirt.ErrorNumber(code)`,
+e.g. `ErrNoDomain`), `libvirtMessage`; nil for non-libvirt errors; works through
+`%w` wrapping via `errors.As`. `logAPIError` keeps its message and gains
+`libvirtCodeName`. Test `TestLibvirtErrorFields` (table: libvirt.Error, wrapped,
+plain error) in `errors_test.go`.
+
+### Step 2 — new `trace.go`
+```go
+type tracingAPI struct { inner libvirtAPI; log logr.Logger }
+type tracedCall struct { t *tracingAPI; method string; start time.Time; kv []any }
+func (t *tracingAPI) begin(method string, kv ...any) *tracedCall
+func (c *tracedCall) detail(kv ...any) *tracedCall // appended only if V(2) enabled
+func (c *tracedCall) done(err error, kv ...any)    // one V(1) line
+```
+`done` emits `log.V(1).Info("libvirt call", ...)` with keys in order: `method`,
+begin args, result kv, `duration` (rounded to µs), then on error `error` plus
+`libvirtErrorFields`. Per-method keys:
+
+| method | V(1) args | V(1) results | V(2) extra |
+|---|---|---|---|
+| DomainLookupByName | domain | | |
+| DomainDefineXML | xmlBytes | domain | xml |
+| DomainCreate, DomainDestroy | domain | | |
+| DomainUndefineFlags | domain, flags | | |
+| DomainGetState | domain | state, reason | |
+| DomainGetMetadata | domain, type, uri | metadataBytes | metadata |
+| DomainInterfaceAddresses | domain, source | interfaces (count) | addresses |
+| ConnectListAllDomains | | count | names |
+| StoragePoolLookupByName, StoragePoolRefresh | pool | | |
+| StorageVolLookupByName | pool, volume | | |
+| StorageVolGetPath | pool, volume | path | |
+| StorageVolCreateXML | pool, xmlBytes | volume | xml |
+| StorageVolUpload, StorageVolDownload | pool, volume, offset, length | | (never content) |
+| StorageVolDelete | pool, volume | | |
+
+Return values pass through untouched.
+
+### Step 3 — `conn.go`: pool logging and wrapping
+- `get(ctx, log, host)`: dead cached client → `"libvirt connection lost, redialing"`;
+  time the dial; `"libvirt host connected"` with `address`, `duration`; failure →
+  `"libvirt host dial failed"` with `address`, `duration`, `error`.
+- `call(ctx, log, host, fn)`: `log = log.WithName("libvirt")`; wrap when
+  `log.V(1).Enabled()`; abort closure logs `"libvirt connection dropped"`
+  `reason="context cancelled"` before `drop`; transport-error branch logs the same
+  message with `reason="transport error"`. Update `call`'s doc comment.
+
+### Step 4 — call sites
+`kvm.go` Create/Get/Delete pass `log`, ListByTag passes `hlog`;
+`kvm_integration_test.go:220` passes `p.logger(ctx).WithValues("host", host.Name)`;
+`conn_test.go` (12 `p.call(` sites) gets `var discard = logr.Discard()`.
+
+### Step 5 — integration test output
+- `integrationLogger(t)`: `KVM_TEST_LOG_LEVEL` (default `1`, `strconv.Atoi`,
+  `t.Fatalf` on garbage) → `testr.NewWithOptions(t, testr.Options{LogTimestamp:
+  true, Verbosity: n})` (`github.com/go-logr/logr/testr`, present in logr v1.4.3,
+  no go.mod change); `logf.SetLogger(log)` once so nothing falls back to the
+  unfulfilled root.
+- `TestKVM_lifecycle`: `ctx = logr.NewContext(ctx, log)` after `WithTimeout`; the
+  cleanup ctx gets the same logger.
+- Header comment: document `KVM_TEST_LOG_LEVEL` (1 = one line per RPC, 2 adds
+  XML/metadata/addresses, 0 = only `t.Log`) and the late-line-after-timeout caveat.
+
+### Step 6 — unit tests
+- `kvm_test.go`: `captureContext(verbosity)` like `gcp_test.go:277-286` but with a
+  mutex around the slice; `TestLogging_verbosityTiers` (mirror `gcp_test.go:322-399`):
+  V0 → no lines; V1 → `"msg"="libvirt call"`, `"method"="DomainDefineXML"`,
+  `"method"="StorageVolUpload"`, `"msg"="libvirt host connected"`, provider/host/name
+  values, `"libvirtCodeName"="ErrNoDomain"` from the first lookup, no `"xml"=`;
+  V2 → `"xml"="<domain` and `"metadata"=`; a cloud-init sentinel absent at every tier.
+- `trace_test.go`: `TestTracingAPI_logsEveryMethod` (table of 17 calls over a
+  `readyHost()` fake, exactly one line each, plus
+  `reflect.TypeOf((*libvirtAPI)(nil)).Elem().NumMethod() == len(cases)` so a new
+  interface method without tracing fails); `TestTracingAPI_passesResultsThrough`;
+  `TestTracingAPI_errorFields` (libvirt error → code/name/message; `io.EOF` →
+  `"error"="EOF"`, no code); `TestTracingAPI_detailOnlyAtV2`;
+  `TestTracingAPI_uploadLogsSizeNotContent`.
+- `conn_test.go`: `fakeDialer` gains an `api` field; `TestHostPool_call_tracesAtV1`
+  (V1 → connected + method lines; V0 → no lines and fn receives the bare
+  `*fakeAPI`); `TestHostPool_call_logsDropReason` (transport error, cancel).
+
+### Step 7 — docs, execution log, CHANGELOG
+- `docs/kvm-provider.md`: `## Logging` section before "Known gaps":
+  `--zap-log-level=debug` = one `libvirt call` line per RPC plus connect/drop lines;
+  `--zap-log-level=2` adds XML, metadata, addresses; cloud-init never logged; no
+  V(5) wire tier because go-libvirt exposes no hook. Mention `KVM_TEST_LOG_LEVEL`
+  in its Testing paragraph.
+- `docs/testing.md`: `KVM_TEST_LOG_LEVEL` in the optional vars; `-v` now shows every
+  RPC; extend the `kvm_test.go` table row.
+- `docs/plans-executions/2026-09-10-0805-kvm-libvirt-tracing.md` with the checklist
+  and per-step entries; also a short cross-reference line in the KVM provider
+  execution log's Step 7 section.
+- `CHANGELOG.md` entry once the user confirms the live run shows the trace.
+
+## Verification
+
+```bash
+go build ./... && go vet ./... && go vet -tags=integration ./internal/provider/kvm/
+go test -race -count=1 ./internal/provider/kvm/
+go test -short ./...
+```
+Live, with the usual env: `make test-integration-kvm`. Expect, interleaved with
+`t.Log` lines and attributed to `trace.go:<line>`, lines like
+
+```
+kvm.libvirt: "level"=1 "msg"="libvirt call" "provider"="kvm-integration" "host"="kvm-test" "name"="proxy-…" "method"="DomainLookupByName" "domain"="proxy-…" "duration"="2.1ms" "error"="…" "libvirtCode"=42 "libvirtCodeName"="ErrNoDomain" "libvirtMessage"="…"
+```
+
+plus one `libvirt host connected` line with `duration`, a `StorageVolUpload` line
+whose duration is the seed upload, and no "log.SetLogger(...) was never called"
+text. `KVM_TEST_LOG_LEVEL=2` shows `"xml"="<domain` and `"addresses"=`;
+`KVM_TEST_LOG_LEVEL=0` shows only `t.Log` output. No line at any level contains
+`#cloud-config`.
+
+## Critical files
+- `internal/provider/kvm/conn.go`, `trace.go` (new), `trace_test.go` (new)
+- `internal/provider/kvm/errors.go`, `errors_test.go`
+- `internal/provider/kvm/kvm.go`, `kvm_test.go`, `conn_test.go`
+- `internal/provider/kvm/kvm_integration_test.go`
+- `docs/kvm-provider.md`, `docs/testing.md`

docs/testing.md

@@ -56,7 +56,8 @@ manual runs too.
 | `internal/provider/gcp` | `insert_test.go`, `errors_test.go`, `gcp_test.go` | field-by-field `buildInsertRequest`; HTTP-code classification table; zone-qualified IDs, 409-is-success, 9-row state mapping, ListByTag filter + `ReturnPartialSuccess` | pure builder needs **no fake**; the rest uses the flattened `instancesAPI` seam |
 | `internal/provider/kvm` | `domainxml_test.go`, `volume_test.go`, `seed_test.go`, `id_test.go`, `metadata_test.go` | pure builders: domain/volume XML unmarshalled back and checked field by field, seed ISO reopened with the same library, providerID round-trip, metadata in both namespace spellings | pure |
 | | `errors_test.go`, `conn_test.go` | libvirt-code classification table; connection pool (reuse, redial, drop on transport error, cancel releases a blocked RPC, one dial per host under concurrency); SSH dial, host-key policy, keepalive | fake dialer; a **real in-process `x/crypto/ssh` server** forwarding a unix socket |
-| | `image_test.go`, `kvm_test.go` | image cache (fresh fetch, ready, marker missing, checksum change/mismatch, 4xx/5xx, concurrent callers); Create resume after every partial step, leftover truncated seed, state/IP mapping, every Delete already-gone case, ListByTag across hosts / one down / unreadable domain | `httptest` image server + in-memory `fakeAPI` behind the `libvirtAPI` seam |
+| | `image_test.go`, `kvm_test.go` | image cache (fresh fetch, ready, marker missing, checksum change/mismatch, 4xx/5xx, concurrent callers); Create resume after every partial step, leftover truncated seed, state/IP mapping, every Delete already-gone case, ListByTag across hosts / one down / unreadable domain; logging tiers (V0 silent, V1 one line per RPC, V2 XML) with cloud-init never logged | `httptest` image server + in-memory `fakeAPI` behind the `libvirtAPI` seam |
+| | `trace_test.go`, `conn_test.go`, `errors_test.go` | every `libvirtAPI` method traced exactly once (guarded by reflection on the interface), results and errors pass through, libvirt error fields, detail keys only at V2, upload content never logged; pool connect/drop lines, no wrapping below V1 | `fakeAPI` + `funcr` capture |
 | | `kvm_integration_test.go` (`-tags=integration`) | one real VM: image fetch, Create, idempotent re-Create, Running with IP, ListByTag, Delete, pool state afterwards | a **real hypervisor** — see below |
 | `internal/health` | `probe_test.go` | probes through a **real CONNECT-capable proxy stub** to a real TLS server: tunnel success, refused CONNECT, wrong status, dead proxy, plain-http forward | `httptest` + hijacked bidirectional tunnel |
 | | `engine_test.go` | thresholds, first-verdict, latency suppression matrix, dropped-event retry, stale-probe UID guard, tick scheduling/seeding/pruning, `Start` end-to-end | fake `client.Reader` + injected `probeFn` |
@@ -116,8 +117,16 @@ make test-integration-kvm
 Optional: `KVM_TEST_KNOWN_HOSTS` (without it host keys are **not**
 verified — the log says so), `KVM_TEST_IMAGE_SHA256`, `KVM_TEST_POOL`
 (default `default`), `KVM_TEST_SOCKET`, `KVM_TEST_TIMEOUT` (default
-`20m`, must cover the first-time image download), and `KVM_TEST_KEEP`
-to leave the VM behind for `virsh console` when something goes wrong.
+`20m`, must cover the first-time image download), `KVM_TEST_KEEP`
+to leave the VM behind for `virsh console` when something goes wrong,
+and `KVM_TEST_LOG_LEVEL` (default `1`) for how much of the provider's
+logging the `-v` output shows: at `1` every libvirt RPC is one compact
+line (`HH:MM:SS.mmm libvirt virDomainLookupByName domain=... duration=...
+error=... libvirtError=ErrNoDomain`), interleaved with the test's own
+`t.Log` lines; `2` adds the domain and volume XML, metadata and
+addresses; `0` leaves only `t.Log`. The per-run constants (provider,
+host, domain name) are left off each line. See the Logging section of
+[kvm-provider.md](kvm-provider.md#logging).
 
 What one run asserts, in order: `New` dials the host; `Create` returns a
 `hosts/<host>/domains/<name>` ID (downloading the image on a cold host —

internal/provider/config_kvm.go

@@ -47,6 +47,11 @@ type KVMImage struct {
 	SHA256 string `json:"sha256,omitempty"`
 	// Format is the image's disk format, "qcow2" (default) or "raw".
 	Format string `json:"format,omitempty"`
+	// Firmware is how VMs from this image boot: "uefi" (default; OVMF with
+	// secure boot off) or "bios" (SeaBIOS) for images with no EFI system
+	// partition. Current Debian, Ubuntu, Fedora and Rocky cloud images all
+	// boot UEFI, and Debian 13's BIOS path was found not to boot at all.
+	Firmware string `json:"firmware,omitempty"`
 }
 
 // KVMMachineType is a VM size profile.
@@ -102,6 +107,9 @@ func validateKVM(prefix string, c *KVMConfig) error {
 		if img.Format != "" && img.Format != "qcow2" && img.Format != "raw" {
 			return fmt.Errorf("%s.format must be qcow2 or raw (got %q)", p, img.Format)
 		}
+		if img.Firmware != "" && img.Firmware != "uefi" && img.Firmware != "bios" {
+			return fmt.Errorf("%s.firmware must be uefi or bios (got %q)", p, img.Firmware)
+		}
 	}
 	if len(c.MachineTypes) == 0 {
 		return fmt.Errorf("%s: kvm.machineTypes must define at least one profile", prefix)

internal/provider/config_kvm_test.go

@@ -154,6 +154,11 @@ hosts:
 			yaml:       minimal("sshKeyFile: /key\nknownHostsFile: /kh\nimages:\n  d: {url: https://x/y.qcow2, sha256: abc}\n" + hostsAndTypes),
 			wantErrSub: `images["d"].sha256 must be 64 hex characters`,
 		},
+		{
+			name:       "image with unknown firmware",
+			yaml:       minimal("sshKeyFile: /key\nknownHostsFile: /kh\nimages:\n  d: {url: https://x/y.qcow2, firmware: coreboot}\n" + hostsAndTypes),
+			wantErrSub: `images["d"].firmware must be uefi or bios`,
+		},
 		{
 			name:       "image with unknown format",
 			yaml:       minimal("sshKeyFile: /key\nknownHostsFile: /kh\nimages:\n  d: {url: https://x/y.vmdk, format: vmdk}\n" + hostsAndTypes),

internal/provider/kvm/conn.go

@@ -2,6 +2,7 @@ package kvm
 
 import (
 	"context"
+	"errors"
 	"fmt"
 	"io"
 	"net"
@@ -10,6 +11,7 @@ import (
 	"time"
 
 	libvirt "github.com/digitalocean/go-libvirt"
+	"github.com/go-logr/logr"
 	"golang.org/x/crypto/ssh"
 	"golang.org/x/crypto/ssh/knownhosts"
 
@@ -95,7 +97,7 @@ func (p *hostPool) entry(name string) *hostEntry {
 	return e
 }
 
-func (p *hostPool) get(ctx context.Context, host provider.KVMHost) (*hostClient, error) {
+func (p *hostPool) get(ctx context.Context, log logr.Logger, host provider.KVMHost) (*hostClient, error) {
 	e := p.entry(host.Name)
 	e.mu.Lock()
 	defer e.mu.Unlock()
@@ -103,13 +105,17 @@ func (p *hostPool) get(ctx context.Context, host provider.KVMHost) (*hostClient,
 		if e.client.alive() {
 			return e.client, nil
 		}
+		log.V(1).Info("libvirt connection lost, redialing", "address", host.Address)
 		e.client.close()
 		e.client = nil
 	}
+	start := time.Now()
 	c, err := p.dial(ctx, host)
 	if err != nil {
+		log.V(1).Info("libvirt host dial failed", "address", host.Address, "duration", time.Since(start).Round(time.Millisecond), "error", err.Error())
 		return nil, fmt.Errorf("connecting to host %s (%s): %w", host.Name, host.Address, err)
 	}
+	log.V(1).Info("libvirt host connected", "address", host.Address, "duration", time.Since(start).Round(time.Millisecond))
 	e.client = c
 	return c, nil
 }
@@ -131,14 +137,24 @@ func (p *hostPool) drop(host string, c *hostClient) {
 // is closed — which unblocks fn with an error — and ctx.Err() is returned.
 // A transport error (anything that is not a libvirt.Error) also drops the
 // cached connection so the next call redials instead of reusing a dead
-// link.
-func (p *hostPool) call(ctx context.Context, host provider.KVMHost, fn func(api libvirtAPI) error) error {
-	c, err := p.get(ctx, host)
+// link. When log has V(1) enabled, every RPC fn makes is traced through it
+// (see tracingAPI), as are connection events.
+func (p *hostPool) call(ctx context.Context, log logr.Logger, host provider.KVMHost, fn func(api libvirtAPI) error) error {
+	log = log.WithName("libvirt")
+	c, err := p.get(ctx, log, host)
 	if err != nil {
 		return err
 	}
-	err = awaitOrCancel(ctx, func() error { return fn(c.api) }, func() { p.drop(host.Name, c) })
-	if err != nil && !isLibvirtError(err) {
+	api := c.api
+	if log.V(1).Enabled() {
+		api = &tracingAPI{inner: c.api, log: log}
+	}
+	err = awaitOrCancel(ctx, func() error { return fn(api) }, func() {
+		log.V(1).Info("libvirt connection dropped", "reason", "context cancelled", "error", ctx.Err().Error())
+		p.drop(host.Name, c)
+	})
+	if err != nil && !isLibvirtError(err) && !errors.Is(err, ctx.Err()) {
+		log.V(1).Info("libvirt connection dropped", "reason", "transport error", "error", err.Error())
 		p.drop(host.Name, c)
 	}
 	return err

internal/provider/kvm/conn_test.go

@@ -18,6 +18,7 @@ import (
 	"time"
 
 	libvirt "github.com/digitalocean/go-libvirt"
+	"github.com/go-logr/logr"
 	"golang.org/x/crypto/ssh"
 	"golang.org/x/crypto/ssh/knownhosts"
 
@@ -43,6 +44,8 @@ type fakeDialer struct {
 	err     error
 	delay   time.Duration
 	clients []*fakeClient
+	// api is what the dialled client exposes; nil for pool-only tests.
+	api libvirtAPI
 }
 
 func (d *fakeDialer) dial(ctx context.Context, _ provider.KVMHost) (*hostClient, error) {
@@ -61,7 +64,7 @@ func (d *fakeDialer) dial(ctx context.Context, _ provider.KVMHost) (*hostClient,
 	}
 	fc := &fakeClient{done: make(chan struct{})}
 	d.clients = append(d.clients, fc)
-	return &hostClient{api: nil, done: fc.done, close: fc.close}, nil
+	return &hostClient{api: d.api, done: fc.done, close: fc.close}, nil
 }
 
 func (d *fakeDialer) dialCount() int {
@@ -72,6 +75,8 @@ func (d *fakeDialer) dialCount() int {
 
 var testHost = provider.KVMHost{Name: "nas1", Address: "nas1:22", User: "virt", Socket: defaultSocket, Pool: "default", Bridge: "br0"}
 
+var discard = logr.Discard()
+
 func noop(libvirtAPI) error { return nil }
 
 func TestHostPool_call_reusesConnection(t *testing.T) {
@@ -79,7 +84,7 @@ func TestHostPool_call_reusesConnection(t *testing.T) {
 	d := &fakeDialer{}
 	p := newHostPool(d.dial)
 	for range 3 {
-		if err := p.call(context.Background(), testHost, noop); err != nil {
+		if err := p.call(context.Background(), discard, testHost, noop); err != nil {
 			t.Fatalf("call() error = %v", err)
 		}
 	}
@@ -92,11 +97,11 @@ func TestHostPool_call_redialsAfterDisconnect(t *testing.T) {
 	t.Parallel()
 	d := &fakeDialer{}
 	p := newHostPool(d.dial)
-	if err := p.call(context.Background(), testHost, noop); err != nil {
+	if err := p.call(context.Background(), discard, testHost, noop); err != nil {
 		t.Fatalf("call() error = %v", err)
 	}
 	d.clients[0].close()
-	if err := p.call(context.Background(), testHost, noop); err != nil {
+	if err := p.call(context.Background(), discard, testHost, noop); err != nil {
 		t.Fatalf("second call() error = %v", err)
 	}
 	if d.dialCount() != 2 {
@@ -108,14 +113,14 @@ func TestHostPool_call_transportErrorDropsConnection(t *testing.T) {
 	t.Parallel()
 	d := &fakeDialer{}
 	p := newHostPool(d.dial)
-	err := p.call(context.Background(), testHost, func(libvirtAPI) error { return io.ErrUnexpectedEOF })
+	err := p.call(context.Background(), discard, testHost, func(libvirtAPI) error { return io.ErrUnexpectedEOF })
 	if !errors.Is(err, io.ErrUnexpectedEOF) {
 		t.Fatalf("call() error = %v, want the transport error passed through", err)
 	}
 	if !d.clients[0].closed.Load() {
 		t.Error("connection not closed after a transport error")
 	}
-	if err := p.call(context.Background(), testHost, noop); err != nil {
+	if err := p.call(context.Background(), discard, testHost, noop); err != nil {
 		t.Fatalf("call() after transport error = %v", err)
 	}
 	if d.dialCount() != 2 {
@@ -127,11 +132,11 @@ func TestHostPool_call_libvirtErrorKeepsConnection(t *testing.T) {
 	t.Parallel()
 	d := &fakeDialer{}
 	p := newHostPool(d.dial)
-	err := p.call(context.Background(), testHost, func(libvirtAPI) error { return lvErr(libvirt.ErrNoDomain) })
+	err := p.call(context.Background(), discard, testHost, func(libvirtAPI) error { return lvErr(libvirt.ErrNoDomain) })
 	if !hasCode(err, libvirt.ErrNoDomain) {
 		t.Fatalf("call() error = %v, want the libvirt error passed through", err)
 	}
-	if err := p.call(context.Background(), testHost, noop); err != nil {
+	if err := p.call(context.Background(), discard, testHost, noop); err != nil {
 		t.Fatalf("call() error = %v", err)
 	}
 	if d.dialCount() != 1 {
@@ -146,7 +151,7 @@ func TestHostPool_call_dialErrorPropagates(t *testing.T) {
 	t.Parallel()
 	d := &fakeDialer{err: errors.New("ssh: handshake failed")}
 	p := newHostPool(d.dial)
-	err := p.call(context.Background(), testHost, noop)
+	err := p.call(context.Background(), discard, testHost, noop)
 	if err == nil || !strings.Contains(err.Error(), "nas1") || !strings.Contains(err.Error(), "handshake failed") {
 		t.Errorf("call() error = %v, want the dial error naming the host", err)
 	}
@@ -162,7 +167,7 @@ func TestHostPool_call_cancelAbandonsBlockedCall(t *testing.T) {
 		time.Sleep(20 * time.Millisecond)
 		cancel()
 	}()
-	err := p.call(ctx, testHost, func(libvirtAPI) error {
+	err := p.call(ctx, discard, testHost, func(libvirtAPI) error {
 		// Simulates an RPC stuck on a hung hypervisor: it only returns once
 		// the pool closes the connection out from under it.
 		<-d.clients[0].done
@@ -177,7 +182,7 @@ func TestHostPool_call_cancelAbandonsBlockedCall(t *testing.T) {
 	case <-time.After(time.Second):
 		t.Fatal("blocked call was not released by closing the connection")
 	}
-	if err := p.call(context.Background(), testHost, noop); err != nil {
+	if err := p.call(context.Background(), discard, testHost, noop); err != nil {
 		t.Fatalf("call() after cancel = %v", err)
 	}
 	if d.dialCount() != 2 {
@@ -192,7 +197,7 @@ func TestHostPool_call_concurrentCallersShareOneDial(t *testing.T) {
 	var wg sync.WaitGroup
 	for range 8 {
 		wg.Go(func() {
-			if err := p.call(context.Background(), testHost, noop); err != nil {
+			if err := p.call(context.Background(), discard, testHost, noop); err != nil {
 				t.Errorf("call() error = %v", err)
 			}
 		})
@@ -210,7 +215,7 @@ func TestHostPool_call_hostsAreIndependent(t *testing.T) {
 	other := testHost
 	other.Name = "lab2"
 	for _, h := range []provider.KVMHost{testHost, other, testHost, other} {
-		if err := p.call(context.Background(), h, noop); err != nil {
+		if err := p.call(context.Background(), discard, h, noop); err != nil {
 			t.Fatalf("call(%s) error = %v", h.Name, err)
 		}
 	}
@@ -567,3 +572,83 @@ func TestKeepalive_keepsHealthyClientOpen(t *testing.T) {
 	}
 	conn.Close()
 }
+
+func TestHostPool_call_tracesAtV1(t *testing.T) {
+	t.Parallel()
+	d := &fakeDialer{api: readyHost()}
+	p := newHostPool(d.dial)
+	log, snapshot := captureLogger(1)
+	err := p.call(context.Background(), log, testHost, func(api libvirtAPI) error {
+		_, err := api.StoragePoolLookupByName("default")
+		return err
+	})
+	if err != nil {
+		t.Fatalf("call() error = %v", err)
+	}
+	joined := strings.Join(snapshot(), "\n")
+	for _, want := range []string{`"msg"="libvirt host connected"`, `"address"="nas1:22"`, `"rpc"="virStoragePoolLookupByName"`, `"pool"="default"`, "libvirt "} {
+		if !strings.Contains(joined, want) {
+			t.Errorf("output missing %s:\n%s", want, joined)
+		}
+	}
+}
+
+func TestHostPool_call_noTracingBelowV1(t *testing.T) {
+	t.Parallel()
+	inner := readyHost()
+	d := &fakeDialer{api: inner}
+	p := newHostPool(d.dial)
+	log, snapshot := captureLogger(0)
+	err := p.call(context.Background(), log, testHost, func(api libvirtAPI) error {
+		if api != libvirtAPI(inner) {
+			t.Errorf("fn received %T, want the bare fake when V(1) is off", api)
+		}
+		return nil
+	})
+	if err != nil {
+		t.Fatalf("call() error = %v", err)
+	}
+	if lines := snapshot(); len(lines) != 0 {
+		t.Errorf("verbosity 0 logged %d lines:\n%s", len(lines), strings.Join(lines, "\n"))
+	}
+}
+
+func TestHostPool_call_logsDropReason(t *testing.T) {
+	t.Parallel()
+	t.Run("transport error", func(t *testing.T) {
+		t.Parallel()
+		d := &fakeDialer{}
+		p := newHostPool(d.dial)
+		log, snapshot := captureLogger(1)
+		_ = p.call(context.Background(), log, testHost, func(libvirtAPI) error { return io.ErrUnexpectedEOF })
+		joined := strings.Join(snapshot(), "\n")
+		if !strings.Contains(joined, `"msg"="libvirt connection dropped"`) || !strings.Contains(joined, `"reason"="transport error"`) {
+			t.Errorf("output missing the drop line:\n%s", joined)
+		}
+	})
+	t.Run("context cancelled", func(t *testing.T) {
+		t.Parallel()
+		d := &fakeDialer{}
+		p := newHostPool(d.dial)
+		log, snapshot := captureLogger(1)
+		ctx, cancel := context.WithCancel(context.Background())
+		cancel()
+		released := make(chan struct{})
+		err := p.call(ctx, log, testHost, func(libvirtAPI) error {
+			<-d.clients[0].done
+			close(released)
+			return io.EOF
+		})
+		if !errors.Is(err, context.Canceled) {
+			t.Fatalf("call() error = %v, want context.Canceled", err)
+		}
+		<-released
+		joined := strings.Join(snapshot(), "\n")
+		if !strings.Contains(joined, `"reason"="context cancelled"`) {
+			t.Errorf("output missing the cancel drop line:\n%s", joined)
+		}
+		if strings.Contains(joined, `"reason"="transport error"`) {
+			t.Errorf("cancel was also reported as a transport error:\n%s", joined)
+		}
+	})
+}

internal/provider/kvm/domainxml.go

@@ -9,35 +9,54 @@ import (
 const guestAgentChannel = "org.qemu.guest_agent.0"
 
 // domainParams is everything buildDomainXML needs, already resolved from the
-// config and placement so the builder stays a pure function.
+// config and placement so the builder stays a pure function. DiskPath and
+// SeedPath are the volumes' host paths as reported by libvirt; Firmware is
+// firmwareUEFI or firmwareBIOS.
 type domainParams struct {
 	Name      string
 	UID       string
 	CreatedAt time.Time
 	VCPUs     int32
 	MemoryMiB int64
-	Pool      string
+	Firmware  string
 	Bridge    string
-	DiskVol   string
-	SeedVol   string
+	DiskPath  string
+	SeedPath  string
 }
 
 // buildDomainXML renders a q35 KVM guest: host-passthrough CPU, a virtio
-// overlay disk and a SATA cdrom for the seed (both referenced as pool
-// volumes so no host paths are needed), one virtio NIC on the host bridge,
-// a serial console, the guest-agent channel, a virtio RNG, no graphics, and
-// the operator's metadata element.
+// overlay disk and a SATA cdrom for the seed, one virtio NIC on the host
+// bridge, a serial console, the guest-agent channel, a virtio RNG, no
+// graphics, and the operator's metadata element.
+//
+// Disks are type="file" with host paths, not type="volume" with pool/volume
+// names: libvirt's AppArmor helper (virt-aa-helper) only grants QEMU access
+// to sources that carry a path, so a volume-referenced disk fails to start
+// with "Permission denied" on any AppArmor-confined host (stock Debian and
+// Ubuntu). The paths cost one StorageVolGetPath round-trip each per Create.
+//
+// UEFI is expressed as <os firmware="efi"> with secure boot off, and libvirt
+// picks the OVMF binary and creates the NVRAM file itself (removed again by
+// the nvram undefine flag). Under SeaBIOS, Debian 13's GRUB hangs on a
+// headless domain with a serial console (Debian bug #1111240:
+// "terminal_output gfxterm serial" with no video device); the same image
+// boots under UEFI with the serial console intact.
 func buildDomainXML(p domainParams) (string, error) {
+	os := osXML{
+		Type: osTypeXML{Arch: "x86_64", Machine: "q35", Value: "hvm"},
+		Boot: bootXML{Dev: "hd"},
+	}
+	if p.Firmware == firmwareUEFI {
+		os.Firmware = "efi"
+		os.FirmwareFeatures = &firmwareXML{Features: []firmwareFeatureXML{{Enabled: "no", Name: "secure-boot"}}}
+	}
 	d := domainXML{
-		Type:     "kvm",
-		Name:     p.Name,
-		Metadata: domainMetadataXML{Instance: newInstanceMetadata(p.UID, p.CreatedAt)},
-		Memory:   sizeXML{Unit: "MiB", Value: p.MemoryMiB},
-		VCPU:     p.VCPUs,
-		OS: osXML{
-			Type: osTypeXML{Arch: "x86_64", Machine: "q35", Value: "hvm"},
-			Boot: bootXML{Dev: "hd"},
-		},
+		Type:       "kvm",
+		Name:       p.Name,
+		Metadata:   domainMetadataXML{Instance: newInstanceMetadata(p.UID, p.CreatedAt)},
+		Memory:     sizeXML{Unit: "MiB", Value: p.MemoryMiB},
+		VCPU:       p.VCPUs,
+		OS:         os,
 		Features:   featuresXML{ACPI: &struct{}{}, APIC: &struct{}{}},
 		CPU:        cpuXML{Mode: "host-passthrough"},
 		Clock:      clockXML{Offset: "utc"},
@@ -47,17 +66,17 @@ func buildDomainXML(p domainParams) (string, error) {
 		Devices: devicesXML{
 			Disks: []diskXML{
 				{
-					Type:   "volume",
+					Type:   "file",
 					Device: "disk",
 					Driver: driverXML{Name: "qemu", Type: formatQcow2},
-					Source: diskSourceXML{Pool: p.Pool, Volume: p.DiskVol},
+					Source: diskSourceXML{File: p.DiskPath},
 					Target: targetXML{Dev: "vda", Bus: "virtio"},
 				},
 				{
-					Type:     "volume",
+					Type:     "file",
 					Device:   "cdrom",
 					Driver:   driverXML{Name: "qemu", Type: formatRaw},
-					Source:   diskSourceXML{Pool: p.Pool, Volume: p.SeedVol},
+					Source:   diskSourceXML{File: p.SeedPath},
 					Target:   targetXML{Dev: "sda", Bus: "sata"},
 					ReadOnly: &struct{}{},
 				},
@@ -110,8 +129,19 @@ type sizeXML struct {
 }
 
 type osXML struct {
-	Type osTypeXML `xml:"type"`
-	Boot bootXML   `xml:"boot"`
+	Firmware         string       `xml:"firmware,attr,omitempty"`
+	Type             osTypeXML    `xml:"type"`
+	FirmwareFeatures *firmwareXML `xml:"firmware"`
+	Boot             bootXML      `xml:"boot"`
+}
+
+type firmwareXML struct {
+	Features []firmwareFeatureXML `xml:"feature"`
+}
+
+type firmwareFeatureXML struct {
+	Enabled string `xml:"enabled,attr"`
+	Name    string `xml:"name,attr"`
 }
 
 type osTypeXML struct {
@@ -161,8 +191,7 @@ type driverXML struct {
 }
 
 type diskSourceXML struct {
-	Pool   string `xml:"pool,attr"`
-	Volume string `xml:"volume,attr"`
+	File string `xml:"file,attr"`
 }
 
 type targetXML struct {

internal/provider/kvm/domainxml_test.go

@@ -14,10 +14,10 @@ func testDomainParams() domainParams {
 		CreatedAt: time.Date(2026, 9, 4, 12, 0, 0, 0, time.UTC),
 		VCPUs:     2,
 		MemoryMiB: 2048,
-		Pool:      "default",
+		Firmware:  firmwareUEFI,
 		Bridge:    "br0",
-		DiskVol:   "proxy-abc123def456ghij.qcow2",
-		SeedVol:   "proxy-abc123def456ghij-seed.iso",
+		DiskPath:  "/var/lib/libvirt/images/proxy-abc123def456ghij.qcow2",
+		SeedPath:  "/var/lib/libvirt/images/proxy-abc123def456ghij-seed.iso",
 	}
 }
 
@@ -41,6 +41,10 @@ func TestBuildDomainXML_fieldByField(t *testing.T) {
 	if d.OS.Type.Value != "hvm" || d.OS.Type.Arch != "x86_64" || d.OS.Type.Machine != "q35" || d.OS.Boot.Dev != "hd" {
 		t.Errorf("os = %+v", d.OS)
 	}
+	if d.OS.Firmware != "efi" || d.OS.FirmwareFeatures == nil || len(d.OS.FirmwareFeatures.Features) != 1 ||
+		d.OS.FirmwareFeatures.Features[0] != (firmwareFeatureXML{Enabled: "no", Name: "secure-boot"}) {
+		t.Errorf("os firmware = %q %+v, want efi with secure-boot disabled", d.OS.Firmware, d.OS.FirmwareFeatures)
+	}
 	if d.Features.ACPI == nil || d.Features.APIC == nil {
 		t.Errorf("features = %+v, want acpi and apic", d.Features)
 	}
@@ -63,16 +67,19 @@ func TestBuildDomainXML_fieldByField(t *testing.T) {
 		t.Fatalf("disks = %d, want 2", len(d.Devices.Disks))
 	}
 	disk, seed := d.Devices.Disks[0], d.Devices.Disks[1]
-	if disk.Type != "volume" || disk.Device != "disk" || disk.Driver.Type != "qcow2" ||
-		disk.Source.Pool != "default" || disk.Source.Volume != "proxy-abc123def456ghij.qcow2" ||
+	if disk.Type != "file" || disk.Device != "disk" || disk.Driver.Type != "qcow2" ||
+		disk.Source.File != "/var/lib/libvirt/images/proxy-abc123def456ghij.qcow2" ||
 		disk.Target.Dev != "vda" || disk.Target.Bus != "virtio" || disk.ReadOnly != nil {
 		t.Errorf("overlay disk = %+v", disk)
 	}
-	if seed.Type != "volume" || seed.Device != "cdrom" || seed.Driver.Type != "raw" ||
-		seed.Source.Pool != "default" || seed.Source.Volume != "proxy-abc123def456ghij-seed.iso" ||
+	if seed.Type != "file" || seed.Device != "cdrom" || seed.Driver.Type != "raw" ||
+		seed.Source.File != "/var/lib/libvirt/images/proxy-abc123def456ghij-seed.iso" ||
 		seed.Target.Bus != "sata" || seed.ReadOnly == nil {
 		t.Errorf("seed cdrom = %+v", seed)
 	}
+	if strings.Contains(raw, `type="volume"`) || strings.Contains(raw, " pool=") {
+		t.Errorf("disks reference pool volumes; virt-aa-helper cannot grant QEMU access to those:\n%s", raw)
+	}
 
 	if len(d.Devices.Interfaces) != 1 {
 		t.Fatalf("interfaces = %d, want 1", len(d.Devices.Interfaces))
@@ -111,3 +118,20 @@ func TestBuildDomainXML_escapesUserValues(t *testing.T) {
 		t.Errorf("bridge = %q, want the raw value back", d.Devices.Interfaces[0].Source.Bridge)
 	}
 }
+
+func TestBuildDomainXML_biosFirmware(t *testing.T) {
+	t.Parallel()
+	p := testDomainParams()
+	p.Firmware = firmwareBIOS
+	raw, err := buildDomainXML(p)
+	if err != nil {
+		t.Fatalf("buildDomainXML() error = %v", err)
+	}
+	var d domainXML
+	if err := xml.Unmarshal([]byte(raw), &d); err != nil {
+		t.Fatalf("output is not well-formed XML: %v", err)
+	}
+	if d.OS.Firmware != "" || d.OS.FirmwareFeatures != nil || strings.Contains(raw, "firmware") {
+		t.Errorf("bios domain still carries firmware settings:\n%s", raw)
+	}
+}

internal/provider/kvm/errors.go

@@ -63,10 +63,18 @@ func logAPIError(log logr.Logger, op string, err error) {
 	if !log.V(1).Enabled() {
 		return
 	}
-	kv := []any{"op", op, "error", err.Error()}
-	var lerr libvirt.Error
-	if errors.As(err, &lerr) {
-		kv = append(kv, "libvirtCode", lerr.Code, "libvirtMessage", lerr.Message)
-	}
+	kv := append([]any{"op", op, "error", err.Error()}, libvirtErrorFields(err)...)
 	log.V(1).Info("libvirt call failed", kv...)
 }
+
+// libvirtErrorFields renders a daemon-reported error as log key/values:
+// its constant name (ErrNoDomain, ...) and numeric code. The daemon's
+// message is already the error text. Nil for transport and other
+// non-libvirt errors.
+func libvirtErrorFields(err error) []any {
+	var lerr libvirt.Error
+	if !errors.As(err, &lerr) {
+		return nil
+	}
+	return []any{"libvirtError", libvirt.ErrorNumber(lerr.Code).String(), "libvirtCode", lerr.Code}
+}

internal/provider/kvm/errors_test.go

@@ -5,6 +5,7 @@ import (
 	"errors"
 	"fmt"
 	"io"
+	"reflect"
 	"testing"
 
 	libvirt "github.com/digitalocean/go-libvirt"
@@ -67,3 +68,26 @@ func TestHasCode(t *testing.T) {
 		t.Error("io.EOF classified as a libvirt error")
 	}
 }
+
+func TestLibvirtErrorFields(t *testing.T) {
+	t.Parallel()
+	tests := []struct {
+		name string
+		err  error
+		want []any
+	}{
+		{"libvirt error", lvErr(libvirt.ErrNoDomain), []any{"libvirtError", "ErrNoDomain", "libvirtCode", uint32(42)}},
+		{"wrapped libvirt error", fmt.Errorf("looking up: %w", lvErr(libvirt.ErrNoDomain)), []any{"libvirtError", "ErrNoDomain", "libvirtCode", uint32(42)}},
+		{"transport error", io.EOF, nil},
+		{"cancelled", context.Canceled, nil},
+	}
+	for _, tc := range tests {
+		t.Run(tc.name, func(t *testing.T) {
+			t.Parallel()
+			got := libvirtErrorFields(tc.err)
+			if !reflect.DeepEqual(got, tc.want) {
+				t.Errorf("libvirtErrorFields() = %#v, want %#v", got, tc.want)
+			}
+		})
+	}
+}

internal/provider/kvm/fake_test.go

@@ -6,6 +6,7 @@ import (
 	"fmt"
 	"io"
 	"slices"
+	"strings"
 	"sync"
 
 	libvirt "github.com/digitalocean/go-libvirt"
@@ -151,8 +152,11 @@ func (f *fakeAPI) DomainDefineXML(raw string) (libvirt.Domain, error) {
 	if err != nil {
 		return libvirt.Domain{}, lvError(libvirt.ErrXMLError, "%v", err)
 	}
+	// libvirt hands the element back without its namespace declaration
+	// (seen on 11.6); mimic that so Get/ListByTag parse the real shape.
+	stored := strings.Replace(string(meta), ` xmlns="`+metadataURI+`"`, "", 1)
 	existing := f.domains[d.Name]
-	nd := &fakeDomain{name: d.Name, xml: raw, metadata: string(meta)}
+	nd := &fakeDomain{name: d.Name, xml: raw, metadata: stored}
 	if existing != nil {
 		nd.running = existing.running
 		nd.addrs = existing.addrs

internal/provider/kvm/image.go

@@ -22,10 +22,11 @@ import (
 // imageSource is a resolved placement.image: either an entry from the
 // provider's images map (Key set) or a URL given directly.
 type imageSource struct {
-	Key    string
-	URL    string
-	SHA256 string
-	Format string
+	Key      string
+	URL      string
+	SHA256   string
+	Format   string
+	Firmware string
 }
 
 // resolveImage maps placement.image to a source. Anything that is neither a
@@ -33,11 +34,11 @@ type imageSource struct {
 // surface, not retry.
 func resolveImage(cfg provider.KVMConfig, image string) (imageSource, error) {
 	if img, ok := cfg.Images[image]; ok {
-		return imageSource{Key: image, URL: img.URL, SHA256: img.SHA256, Format: img.Format}, nil
+		return imageSource{Key: image, URL: img.URL, SHA256: img.SHA256, Format: img.Format, Firmware: img.Firmware}, nil
 	}
 	u, err := url.Parse(image)
 	if err == nil && (u.Scheme == "http" || u.Scheme == "https") && u.Host != "" {
-		return imageSource{URL: image, Format: formatQcow2}, nil
+		return imageSource{URL: image, Format: formatQcow2, Firmware: firmwareUEFI}, nil
 	}
 	return imageSource{}, fmt.Errorf("%w: placement.image %q is neither a key in kvm.images nor an http(s) URL",
 		provider.ErrPermanent, image)
@@ -101,7 +102,7 @@ func (c *imageCache) ensure(ctx context.Context, log logr.Logger, api libvirtAPI
 		return "", err
 	}
 	if ready {
-		log.V(1).Info("base image already cached", "host", hostName, "volume", src.volumeName())
+		log.V(1).Info("base image already cached", "volume", src.volumeName())
 		return api.StorageVolGetPath(base)
 	}
 	if err := deleteIfExists(api, pool, src.markerName()); err != nil {
@@ -170,7 +171,7 @@ func (c *imageCache) fetch(ctx context.Context, log logr.Logger, api libvirtAPI,
 	}
 
 	log.Info("fetching base image into host pool",
-		"host", hostName, "pool", pool.Name, "volume", src.volumeName(),
+		"pool", pool.Name, "volume", src.volumeName(),
 		"url", src.URL, "bytes", resp.ContentLength)
 	start := time.Now()
 
@@ -212,7 +213,7 @@ func (c *imageCache) fetch(ctx context.Context, log logr.Logger, api libvirtAPI,
 		return libvirt.StorageVol{}, fmt.Errorf("writing image marker: %w", err)
 	}
 	log.Info("base image cached",
-		"host", hostName, "volume", src.volumeName(), "sha256", digest,
+		"volume", src.volumeName(), "sha256", digest,
 		"bytes", resp.ContentLength, "duration", time.Since(start).Round(time.Second))
 	return base, nil
 }

internal/provider/kvm/image_test.go

@@ -88,9 +88,9 @@ func TestResolveImage(t *testing.T) {
 		want    imageSource
 		wantErr bool
 	}{
-		{"configured key", "debian-13", imageSource{Key: "debian-13", URL: "https://cloud.debian.org/d.qcow2", SHA256: "abc", Format: "qcow2"}, false},
-		{"direct https url", "https://x.example/img.qcow2", imageSource{URL: "https://x.example/img.qcow2", Format: "qcow2"}, false},
-		{"direct http url", "http://mirror/img.qcow2", imageSource{URL: "http://mirror/img.qcow2", Format: "qcow2"}, false},
+		{"configured key", "debian-13", imageSource{Key: "debian-13", URL: "https://cloud.debian.org/d.qcow2", SHA256: "abc", Format: "qcow2", Firmware: "uefi"}, false},
+		{"direct https url", "https://x.example/img.qcow2", imageSource{URL: "https://x.example/img.qcow2", Format: "qcow2", Firmware: "uefi"}, false},
+		{"direct http url", "http://mirror/img.qcow2", imageSource{URL: "http://mirror/img.qcow2", Format: "qcow2", Firmware: "uefi"}, false},
 		{"unknown key", "ubuntu", imageSource{}, true},
 		{"file url", "file:///tmp/x.qcow2", imageSource{}, true},
 		{"empty", "", imageSource{}, true},

internal/provider/kvm/kvm.go

@@ -28,6 +28,8 @@ const (
 	defaultPool       = "default"
 	formatQcow2       = "qcow2"
 	formatRaw         = "raw"
+	firmwareUEFI      = "uefi"
+	firmwareBIOS      = "bios"
 
 	// undefineFlags removes everything libvirt may keep alongside a domain
 	// definition, so an undefine never fails on leftover state.
@@ -48,6 +50,9 @@ func withDefaults(cfg provider.KVMConfig) provider.KVMConfig {
 		if img.Format == "" {
 			img.Format = formatQcow2
 		}
+		if img.Firmware == "" {
+			img.Firmware = firmwareUEFI
+		}
 		images[k] = img
 	}
 	cfg.Images = images
@@ -166,7 +171,7 @@ func (p *Provider) Create(ctx context.Context, req provider.CreateRequest) (stri
 		"vcpus", mt.VCPUs, "memoryMiB", mt.MemoryMiB, "diskSizeGb", p.cfg.DiskSizeGB,
 		"image", src.volumeName(), "cloudInitBytes", len(req.CloudInit))
 
-	err = p.hosts.call(ctx, host, func(api libvirtAPI) error {
+	err = p.hosts.call(ctx, log, host, func(api libvirtAPI) error {
 		dom, err := api.DomainLookupByName(req.Name)
 		if err == nil {
 			log.V(1).Info("domain already defined")
@@ -183,13 +188,23 @@ func (p *Provider) Create(ctx context.Context, req provider.CreateRequest) (stri
 		if err != nil {
 			return err
 		}
-		if err := p.ensureOverlay(log, api, pool, req.Name, basePath, src.Format); err != nil {
+		overlay, err := p.ensureOverlay(log, api, pool, req.Name, basePath, src.Format)
+		if err != nil {
 			return err
 		}
-		if err := p.writeSeed(log, api, pool, req.Name, req.CloudInit); err != nil {
+		seed, err := p.writeSeed(log, api, pool, req.Name, req.CloudInit)
+		if err != nil {
 			return err
 		}
-		dom, err = p.defineDomain(log, api, host, req, mt)
+		diskPath, err := api.StorageVolGetPath(overlay)
+		if err != nil {
+			return fmt.Errorf("resolving overlay path: %w", err)
+		}
+		seedPath, err := api.StorageVolGetPath(seed)
+		if err != nil {
+			return fmt.Errorf("resolving seed path: %w", err)
+		}
+		dom, err = p.defineDomain(log, api, host, req, mt, src.Firmware, diskPath, seedPath)
 		if err != nil {
 			return err
 		}
@@ -203,60 +218,67 @@ func (p *Provider) Create(ctx context.Context, req provider.CreateRequest) (stri
 	return id, nil
 }
 
-func (p *Provider) ensureOverlay(log logr.Logger, api libvirtAPI, pool libvirt.StoragePool, name, basePath, baseFormat string) error {
+// ensureOverlay creates the per-VM overlay volume, or returns the existing
+// one: creation is atomic, so an overlay that exists is complete.
+func (p *Provider) ensureOverlay(log logr.Logger, api libvirtAPI, pool libvirt.StoragePool, name, basePath, baseFormat string) (libvirt.StorageVol, error) {
 	xml, err := buildVolumeXML(overlayVolume(name, p.cfg.DiskSizeGB, basePath, baseFormat))
 	if err != nil {
-		return err
+		return libvirt.StorageVol{}, err
 	}
-	_, err = api.StorageVolCreateXML(pool, xml, 0)
+	vol, err := api.StorageVolCreateXML(pool, xml, 0)
 	switch {
 	case err == nil:
 		log.V(1).Info("overlay volume created", "volume", overlayVolumeName(name), "base", basePath)
+		return vol, nil
 	case hasCode(err, libvirt.ErrStorageVolExist):
 		log.V(1).Info("overlay volume already exists", "volume", overlayVolumeName(name))
+		vol, err := api.StorageVolLookupByName(pool, overlayVolumeName(name))
+		if err != nil {
+			return libvirt.StorageVol{}, fmt.Errorf("looking up existing overlay volume: %w", err)
+		}
+		return vol, nil
 	default:
-		return fmt.Errorf("creating overlay volume: %w", err)
+		return libvirt.StorageVol{}, fmt.Errorf("creating overlay volume: %w", err)
 	}
-	return nil
 }
 
 // writeSeed replaces the seed volume with a freshly built NoCloud ISO.
 // Only called while no domain references it.
-func (p *Provider) writeSeed(log logr.Logger, api libvirtAPI, pool libvirt.StoragePool, name, userData string) error {
+func (p *Provider) writeSeed(log logr.Logger, api libvirtAPI, pool libvirt.StoragePool, name, userData string) (libvirt.StorageVol, error) {
 	seedName := seedVolumeName(name)
 	if err := deleteIfExists(api, pool, seedName); err != nil {
-		return err
+		return libvirt.StorageVol{}, err
 	}
 	iso, err := buildSeedISO(name, userData, p.cfg.VendorData)
 	if err != nil {
-		return fmt.Errorf("%w: %v", provider.ErrPermanent, err)
+		return libvirt.StorageVol{}, fmt.Errorf("%w: %v", provider.ErrPermanent, err)
 	}
 	xml, err := buildVolumeXML(rawVolume(seedName, int64(len(iso))))
 	if err != nil {
-		return err
+		return libvirt.StorageVol{}, err
 	}
 	vol, err := api.StorageVolCreateXML(pool, xml, 0)
 	if err != nil {
-		return fmt.Errorf("creating seed volume: %w", err)
+		return libvirt.StorageVol{}, fmt.Errorf("creating seed volume: %w", err)
 	}
 	if err := api.StorageVolUpload(vol, bytes.NewReader(iso), 0, 0, 0); err != nil {
-		return fmt.Errorf("uploading seed volume: %w", err)
+		return libvirt.StorageVol{}, fmt.Errorf("uploading seed volume: %w", err)
 	}
 	log.V(1).Info("seed volume uploaded", "volume", seedName, "bytes", len(iso))
-	return nil
+	return vol, nil
 }
 
-func (p *Provider) defineDomain(log logr.Logger, api libvirtAPI, host provider.KVMHost, req provider.CreateRequest, mt provider.KVMMachineType) (libvirt.Domain, error) {
+func (p *Provider) defineDomain(log logr.Logger, api libvirtAPI, host provider.KVMHost, req provider.CreateRequest, mt provider.KVMMachineType, firmware, diskPath, seedPath string) (libvirt.Domain, error) {
 	xml, err := buildDomainXML(domainParams{
 		Name:      req.Name,
 		UID:       req.UID,
 		CreatedAt: p.now(),
 		VCPUs:     mt.VCPUs,
 		MemoryMiB: mt.MemoryMiB,
-		Pool:      host.Pool,
+		Firmware:  firmware,
 		Bridge:    host.Bridge,
-		DiskVol:   overlayVolumeName(req.Name),
-		SeedVol:   seedVolumeName(req.Name),
+		DiskPath:  diskPath,
+		SeedPath:  seedPath,
 	})
 	if err != nil {
 		return libvirt.Domain{}, err
@@ -265,7 +287,7 @@ func (p *Provider) defineDomain(log logr.Logger, api libvirtAPI, host provider.K
 	if err != nil {
 		return libvirt.Domain{}, fmt.Errorf("defining domain: %w", err)
 	}
-	log.V(1).Info("domain defined", "uid", req.UID)
+	log.V(1).Info("domain defined", "uid", req.UID, "firmware", firmware)
 	return dom, nil
 }
 
@@ -303,7 +325,7 @@ func (p *Provider) Get(ctx context.Context, providerID string) (*provider.Instan
 	}
 	log := p.logger(ctx).WithValues("host", host.Name, "name", name)
 	var inst *provider.Instance
-	err = p.hosts.call(ctx, host, func(api libvirtAPI) error {
+	err = p.hosts.call(ctx, log, host, func(api libvirtAPI) error {
 		dom, err := api.DomainLookupByName(name)
 		if err != nil {
 			return fmt.Errorf("looking up domain: %w", err)
@@ -439,7 +461,7 @@ func (p *Provider) Delete(ctx context.Context, providerID string) error {
 		return p.wrapErr("delete", providerID, err)
 	}
 	log := p.logger(ctx).WithValues("host", host.Name, "name", name)
-	err = p.hosts.call(ctx, host, func(api libvirtAPI) error {
+	err = p.hosts.call(ctx, log, host, func(api libvirtAPI) error {
 		if err := p.removeDomain(log, api, name); err != nil {
 			return err
 		}
@@ -511,7 +533,7 @@ func (p *Provider) ListByTag(ctx context.Context) ([]provider.Instance, error) {
 	var out []provider.Instance
 	for _, host := range p.cfg.Hosts {
 		hlog := log.WithValues("host", host.Name)
-		err := p.hosts.call(ctx, host, func(api libvirtAPI) error {
+		err := p.hosts.call(ctx, hlog, host, func(api libvirtAPI) error {
 			doms, _, err := api.ConnectListAllDomains(1, 0)
 			if err != nil {
 				return fmt.Errorf("listing domains: %w", err)

internal/provider/kvm/kvm_integration_test.go

@@ -25,6 +25,17 @@ package kvm
 //	KVM_TEST_SOCKET        libvirt socket path on the host
 //	KVM_TEST_TIMEOUT       overall budget incl. the image download (default 20m)
 //	KVM_TEST_KEEP          set to anything to leave the VM behind for inspection
+//	KVM_TEST_LOG_LEVEL     provider log verbosity shown in -v output (default 1:
+//	                       one line per libvirt call; 2 adds XML, metadata and
+//	                       addresses; 0 leaves only the t.Log lines)
+//
+// Provider logs are printed through t.Log in a compact form: time, logger
+// name, then the libvirt API function (or the message) and its fields.
+// The provider/host/name values that are the same on every line of a run
+// are dropped; the first t.Log line of the run states them. A run that
+// hits its timeout may log one more line from the RPC the pool abandoned,
+// after the test has ended; that is a symptom of the timeout, not a bug
+// in the tracer.
 
 import (
 	"context"
@@ -34,11 +45,15 @@ import (
 	"fmt"
 	"net"
 	"os"
+	"strconv"
+	"strings"
 	"testing"
 	"time"
 
 	libvirt "github.com/digitalocean/go-libvirt"
+	"github.com/go-logr/logr"
 	"k8s.io/apimachinery/pkg/types"
+	logf "sigs.k8s.io/controller-runtime/pkg/log"
 
 	"gitea.home.hrajfrisbee.cz/kacerr/egress-proxies-operator/internal/provider"
 )
@@ -50,9 +65,10 @@ const (
 )
 
 type integrationEnv struct {
-	cfg     provider.ProviderConfig
-	timeout time.Duration
-	keep    bool
+	cfg      provider.ProviderConfig
+	timeout  time.Duration
+	keep     bool
+	logLevel int
 }
 
 func loadIntegrationEnv(t *testing.T) integrationEnv {
@@ -97,7 +113,95 @@ func loadIntegrationEnv(t *testing.T) integrationEnv {
 		}
 		timeout = d
 	}
-	return integrationEnv{cfg: pc, timeout: timeout, keep: os.Getenv("KVM_TEST_KEEP") != ""}
+	logLevel := 1
+	if v := os.Getenv("KVM_TEST_LOG_LEVEL"); v != "" {
+		n, err := strconv.Atoi(v)
+		if err != nil {
+			t.Fatalf("KVM_TEST_LOG_LEVEL: %v", err)
+		}
+		logLevel = n
+	}
+	return integrationEnv{cfg: pc, timeout: timeout, keep: os.Getenv("KVM_TEST_KEEP") != "", logLevel: logLevel}
+}
+
+// integrationLogger routes provider logs into the test output at the
+// requested verbosity, and installs it as controller-runtime's root logger
+// so nothing falls back to the unfulfilled delegating sink (which would
+// print its "SetLogger was never called" warning and swallow the lines).
+func integrationLogger(t *testing.T, verbosity int) logr.Logger {
+	t.Helper()
+	log := logr.New(&compactSink{t: t, verbosity: verbosity})
+	logf.SetLogger(log)
+	return log
+}
+
+// compactSink is a logr sink for test output: one line per record as
+// "HH:MM:SS.mmm name headline k=v ...", where the headline is the rpc
+// field when present (the libvirt API function) and the message
+// otherwise. Keys that are constant for the whole run are omitted.
+type compactSink struct {
+	t         *testing.T
+	verbosity int
+	name      string
+	values    []any
+}
+
+var compactOmit = map[string]bool{"provider": true, "host": true, "name": true}
+
+func (s *compactSink) Init(logr.RuntimeInfo) {}
+
+func (s *compactSink) Enabled(level int) bool { return level <= s.verbosity }
+
+// GetCallStackHelper lets logr mark its frames as helpers, so t.Log
+// attributes each line to the provider code that logged it.
+func (s *compactSink) GetCallStackHelper() func() { return s.t.Helper }
+
+func (s *compactSink) Info(_ int, msg string, kv ...any) {
+	s.t.Helper()
+	s.t.Log(s.format(msg, kv))
+}
+
+func (s *compactSink) Error(err error, msg string, kv ...any) {
+	s.t.Helper()
+	s.t.Log(s.format(msg, append(kv, "error", err)))
+}
+
+func (s *compactSink) WithValues(kv ...any) logr.LogSink {
+	c := *s
+	c.values = append(append([]any(nil), s.values...), kv...)
+	return &c
+}
+
+func (s *compactSink) WithName(name string) logr.LogSink {
+	c := *s
+	if c.name != "" {
+		name = c.name + "/" + name
+	}
+	c.name = name
+	return &c
+}
+
+func (s *compactSink) format(msg string, kv []any) string {
+	all := append(append([]any(nil), s.values...), kv...)
+	headline := msg
+	var b strings.Builder
+	for i := 0; i+1 < len(all); i += 2 {
+		key := fmt.Sprint(all[i])
+		if key == "rpc" {
+			headline = fmt.Sprint(all[i+1])
+			continue
+		}
+		if compactOmit[key] {
+			continue
+		}
+		val := fmt.Sprint(all[i+1])
+		if strings.ContainsAny(val, " \t\"=") {
+			val = strconv.Quote(val)
+		}
+		b.WriteString(" " + key + "=" + val)
+	}
+	name := s.name[strings.LastIndex(s.name, "/")+1:]
+	return fmt.Sprintf("%s %s %s%s", time.Now().Format("15:04:05.000"), name, headline, b.String())
 }
 
 func randomUID(t *testing.T) string {
@@ -114,7 +218,8 @@ func randomUID(t *testing.T) string {
 // stage depends on the state the previous one left on the hypervisor.
 func TestKVM_lifecycle(t *testing.T) {
 	env := loadIntegrationEnv(t)
-	ctx, cancel := context.WithTimeout(context.Background(), env.timeout)
+	log := integrationLogger(t, env.logLevel)
+	ctx, cancel := context.WithTimeout(logr.NewContext(context.Background(), log), env.timeout)
 	defer cancel()
 
 	prov, err := New(ctx, env.cfg)
@@ -143,7 +248,7 @@ func TestKVM_lifecycle(t *testing.T) {
 			t.Logf("KVM_TEST_KEEP set: leaving domain %s and its volumes on %s", req.Name, host.Address)
 			return
 		}
-		cctx, ccancel := context.WithTimeout(context.Background(), 2*time.Minute)
+		cctx, ccancel := context.WithTimeout(logr.NewContext(context.Background(), log), 2*time.Minute)
 		defer ccancel()
 		if err := p.Delete(cctx, formatProviderID(host.Name, req.Name)); err != nil {
 			t.Errorf("cleanup Delete: %v", err)
@@ -217,7 +322,7 @@ func TestKVM_lifecycle(t *testing.T) {
 	if err != nil {
 		t.Fatal(err)
 	}
-	err = p.hosts.call(ctx, host, func(api libvirtAPI) error {
+	err = p.hosts.call(ctx, p.logger(ctx).WithValues("host", host.Name), host, func(api libvirtAPI) error {
 		pool, err := api.StoragePoolLookupByName(host.Pool)
 		if err != nil {
 			return err

internal/provider/kvm/kvm_test.go

@@ -20,7 +20,7 @@ func TestWithDefaults(t *testing.T) {
 	cfg := withDefaults(provider.KVMConfig{
 		Images: map[string]provider.KVMImage{
 			"debian": {URL: "https://x/d.qcow2"},
-			"raw":    {URL: "https://x/r.img", Format: "raw"},
+			"raw":    {URL: "https://x/r.img", Format: "raw", Firmware: "bios"},
 		},
 		Hosts: []provider.KVMHost{
 			{Name: "a", Address: "a:22", User: "virt", Bridge: "br0"},
@@ -36,6 +36,9 @@ func TestWithDefaults(t *testing.T) {
 	if cfg.Images["debian"].Format != "qcow2" || cfg.Images["raw"].Format != "raw" {
 		t.Errorf("image formats = %q/%q, want qcow2 default and raw kept", cfg.Images["debian"].Format, cfg.Images["raw"].Format)
 	}
+	if cfg.Images["debian"].Firmware != firmwareUEFI || cfg.Images["raw"].Firmware != firmwareBIOS {
+		t.Errorf("image firmware = %q/%q, want uefi default and bios kept", cfg.Images["debian"].Firmware, cfg.Images["raw"].Firmware)
+	}
 	if a := cfg.Hosts[0]; a.Socket != defaultSocket || a.Pool != defaultPool {
 		t.Errorf("host a = %+v, want default socket and pool", a)
 	}
@@ -210,6 +213,13 @@ func TestCreate_freshHost(t *testing.T) {
 	if d.Devices.Interfaces[0].Source.Bridge != "br0" {
 		t.Errorf("bridge = %q, want br0", d.Devices.Interfaces[0].Source.Bridge)
 	}
+	wantDisk, wantSeed := api.poolPath+"/"+overlayVolumeName(testName), api.poolPath+"/"+seedVolumeName(testName)
+	if got := d.Devices.Disks[0].Source.File; got != wantDisk {
+		t.Errorf("overlay disk source = %q, want the path libvirt reported, %q", got, wantDisk)
+	}
+	if got := d.Devices.Disks[1].Source.File; got != wantSeed {
+		t.Errorf("seed cdrom source = %q, want the path libvirt reported, %q", got, wantSeed)
+	}
 	if m := d.Metadata.Instance; m.UID != testUID || !m.managed() || !m.createdAt().Equal(testNow) {
 		t.Errorf("metadata = %+v, want managed, uid %s, createdAt %s", m, testUID, testNow)
 	}
@@ -878,3 +888,96 @@ func TestNew_badKeyPathFailsFast(t *testing.T) {
 		t.Fatal("New succeeded with a missing key file")
 	}
 }
+
+// runAllOps drives one full lifecycle over a ready fake host so logging
+// tests see every provider method and every libvirt call.
+func runAllOps(t *testing.T, ctx context.Context, req provider.CreateRequest) {
+	t.Helper()
+	p := newTestProvider(hostFakes{"nas1": readyHost()}, "nas1")
+	id, err := p.Create(ctx, req)
+	if err != nil {
+		t.Fatalf("Create: %v", err)
+	}
+	if _, err := p.Get(ctx, id); err != nil {
+		t.Fatalf("Get: %v", err)
+	}
+	if _, err := p.ListByTag(ctx); err != nil {
+		t.Fatalf("ListByTag: %v", err)
+	}
+	if err := p.Delete(ctx, id); err != nil {
+		t.Fatalf("Delete: %v", err)
+	}
+}
+
+func TestLogging_verbosityTiers(t *testing.T) {
+	t.Parallel()
+	tests := []struct {
+		name        string
+		verbosity   int
+		wantLines   []string
+		absentLines []string
+	}{
+		{
+			name:        "v0 stays silent",
+			verbosity:   0,
+			absentLines: []string{"libvirt call", "KVM domain ensured running"},
+		},
+		{
+			name:      "v1 logs one line per libvirt call plus the operation outcomes",
+			verbosity: 1,
+			wantLines: []string{
+				`kvm/libvirt "level"=1 "msg"="libvirt host connected"`,
+				`"msg"="libvirt call"`,
+				`"rpc"="virDomainLookupByName"`,
+				`"libvirtError"="ErrNoDomain"`,
+				`"rpc"="virStorageVolUpload"`,
+				`"rpc"="virDomainDefineXML"`,
+				`"rpc"="virDomainCreate"`,
+				`"rpc"="virDomainInterfaceAddresses"`,
+				`"rpc"="virConnectListAllDomains"`,
+				`"rpc"="virDomainUndefineFlags"`,
+				`"rpc"="virStorageVolDelete"`,
+				`"provider"="kvm-home"`,
+				`"host"="nas1"`,
+				`"name"="` + testName + `"`,
+				`"msg"="KVM domain ensured running"`,
+			},
+			absentLines: []string{`"xml"=`, `"metadata"=`},
+		},
+		{
+			name:      "v2 adds xml, metadata and addresses on the same lines",
+			verbosity: 2,
+			wantLines: []string{`"xml"="<domain`, `"xml"="<volume`, `"metadata"="<instance`, `"names"=[`},
+		},
+	}
+	for _, tc := range tests {
+		t.Run(tc.name, func(t *testing.T) {
+			t.Parallel()
+			ctx, snapshot := captureContext(tc.verbosity)
+			req := testRequest()
+			const sentinel = "SENTINEL-cloud-init-must-never-be-logged"
+			req.CloudInit = "#cloud-config\n" + sentinel + "\n"
+
+			runAllOps(t, ctx, req)
+
+			lines := snapshot()
+			joined := strings.Join(lines, "\n")
+			if tc.verbosity == 0 && len(lines) != 0 {
+				t.Errorf("verbosity 0 logged %d lines:\n%s", len(lines), joined)
+			}
+			for _, want := range tc.wantLines {
+				if !strings.Contains(joined, want) {
+					t.Errorf("output missing %s:\n%s", want, joined)
+				}
+			}
+			for _, absent := range tc.absentLines {
+				if strings.Contains(joined, absent) {
+					t.Errorf("output unexpectedly contains %s:\n%s", absent, joined)
+				}
+			}
+			if strings.Contains(joined, sentinel) {
+				t.Errorf("cloud-init content leaked into logs:\n%s", joined)
+			}
+		})
+	}
+}

internal/provider/kvm/metadata.go

@@ -31,15 +31,21 @@ func newInstanceMetadata(uid string, createdAt time.Time) instanceMetadata {
 }
 
 // parseInstanceMetadata decodes the element as DomainGetMetadata returns it.
-// libvirt may re-serialise it with a namespace prefix rather than the default
-// namespace it was defined with; encoding/xml matches on namespace URI, so
-// both spellings decode.
+// libvirt selects the element by namespace URI but serialises it without the
+// declaration (observed on libvirt 11.6: a bare <instance>), and other
+// versions may keep a default or prefixed form. The URI is already checked
+// by the lookup, so only the local name is matched here.
 func parseInstanceMetadata(s string) (instanceMetadata, error) {
-	var m instanceMetadata
-	if err := xml.Unmarshal([]byte(s), &m); err != nil {
+	var raw struct {
+		XMLName   xml.Name `xml:"instance"`
+		Managed   string   `xml:"managed"`
+		UID       string   `xml:"uid"`
+		CreatedAt string   `xml:"createdAt"`
+	}
+	if err := xml.Unmarshal([]byte(s), &raw); err != nil {
 		return instanceMetadata{}, fmt.Errorf("parsing domain metadata: %w", err)
 	}
-	return m, nil
+	return instanceMetadata{Managed: raw.Managed, UID: raw.UID, CreatedAt: raw.CreatedAt}, nil
 }
 
 func (m instanceMetadata) managed() bool {

internal/provider/kvm/metadata_test.go

@@ -45,6 +45,21 @@ func TestParseInstanceMetadata_libvirtPrefixedForm(t *testing.T) {
 	}
 }
 
+func TestParseInstanceMetadata_libvirtBareForm(t *testing.T) {
+	t.Parallel()
+	// What libvirt 11.6 actually returns from DomainGetMetadata: the element
+	// selected by our URI, serialised without any namespace declaration.
+	in := `<instance><managed>true</managed><uid>uid-3</uid>` +
+		`<createdAt>2026-09-10T07:30:00Z</createdAt></instance>`
+	m, err := parseInstanceMetadata(in)
+	if err != nil {
+		t.Fatalf("parseInstanceMetadata() error = %v", err)
+	}
+	if !m.managed() || m.UID != "uid-3" || m.createdAt().Minute() != 30 {
+		t.Errorf("parsed = %+v", m)
+	}
+}
+
 func TestParseInstanceMetadata_notManaged(t *testing.T) {
 	t.Parallel()
 	tests := []struct {

internal/provider/kvm/trace.go

@@ -0,0 +1,205 @@
+package kvm
+
+import (
+	"fmt"
+	"io"
+	"time"
+
+	libvirt "github.com/digitalocean/go-libvirt"
+	"github.com/go-logr/logr"
+)
+
+// tracingAPI wraps a libvirtAPI and logs one V(1) line per call after it
+// returns: the libvirt API function (rpc=virDomainLookupByName, ...), the
+// identifiers it was given, curated results, duration, and on failure the
+// error with libvirt's code name. At V(2) the same line also carries XML
+// bodies, metadata and address lists. Upload and download bodies are never
+// logged: the seed ISO carries cloud-init.
+type tracingAPI struct {
+	inner libvirtAPI
+	log   logr.Logger
+}
+
+type tracedCall struct {
+	t      *tracingAPI
+	method string
+	start  time.Time
+	kv     []any
+}
+
+// begin names the call by its libvirt API function: go-libvirt's method
+// names are the remote procedure names, which are the public vir* API
+// names without the prefix.
+func (t *tracingAPI) begin(method string, kv ...any) *tracedCall {
+	return &tracedCall{t: t, method: "vir" + method, start: time.Now(), kv: kv}
+}
+
+// detail adds key/values that are only worth the bytes at V(2).
+func (c *tracedCall) detail(kv ...any) *tracedCall {
+	if c.t.log.V(2).Enabled() {
+		c.kv = append(c.kv, kv...)
+	}
+	return c
+}
+
+func (c *tracedCall) done(err error, kv ...any) {
+	fields := make([]any, 0, 2+len(c.kv)+len(kv)+10)
+	fields = append(fields, "rpc", c.method)
+	fields = append(fields, c.kv...)
+	fields = append(fields, kv...)
+	fields = append(fields, "duration", time.Since(c.start).Round(time.Microsecond))
+	if err != nil {
+		fields = append(fields, "error", err.Error())
+		fields = append(fields, libvirtErrorFields(err)...)
+	}
+	c.t.log.V(1).Info("libvirt call", fields...)
+}
+
+// flagKV renders a flags value only when something is set; go-libvirt's
+// generated stringers do not know bitmask combinations.
+func flagKV(v int64) []any {
+	if v == 0 {
+		return nil
+	}
+	return []any{"flags", v}
+}
+
+func optString(s libvirt.OptString) string {
+	if len(s) == 0 {
+		return ""
+	}
+	return s[0]
+}
+
+func (t *tracingAPI) DomainLookupByName(name string) (libvirt.Domain, error) {
+	c := t.begin("DomainLookupByName", "domain", name)
+	d, err := t.inner.DomainLookupByName(name)
+	c.done(err)
+	return d, err
+}
+
+func (t *tracingAPI) DomainDefineXML(xml string) (libvirt.Domain, error) {
+	c := t.begin("DomainDefineXML", "xmlBytes", len(xml)).detail("xml", xml)
+	d, err := t.inner.DomainDefineXML(xml)
+	c.done(err, "domain", d.Name)
+	return d, err
+}
+
+func (t *tracingAPI) DomainCreate(d libvirt.Domain) error {
+	c := t.begin("DomainCreate", "domain", d.Name)
+	err := t.inner.DomainCreate(d)
+	c.done(err)
+	return err
+}
+
+func (t *tracingAPI) DomainDestroy(d libvirt.Domain) error {
+	c := t.begin("DomainDestroy", "domain", d.Name)
+	err := t.inner.DomainDestroy(d)
+	c.done(err)
+	return err
+}
+
+func (t *tracingAPI) DomainUndefineFlags(d libvirt.Domain, flags libvirt.DomainUndefineFlagsValues) error {
+	c := t.begin("DomainUndefineFlags", append([]any{"domain", d.Name}, flagKV(int64(flags))...)...)
+	err := t.inner.DomainUndefineFlags(d, flags)
+	c.done(err)
+	return err
+}
+
+func (t *tracingAPI) DomainGetState(d libvirt.Domain, flags uint32) (int32, int32, error) {
+	c := t.begin("DomainGetState", "domain", d.Name)
+	state, reason, err := t.inner.DomainGetState(d, flags)
+	c.done(err, "state", libvirt.DomainState(state), "reason", reason)
+	return state, reason, err
+}
+
+func (t *tracingAPI) DomainGetMetadata(d libvirt.Domain, typ int32, uri libvirt.OptString, flags libvirt.DomainModificationImpact) (string, error) {
+	c := t.begin("DomainGetMetadata", "domain", d.Name, "type", typ, "uri", optString(uri))
+	s, err := t.inner.DomainGetMetadata(d, typ, uri, flags)
+	c.detail("metadata", s).done(err, "metadataBytes", len(s))
+	return s, err
+}
+
+func (t *tracingAPI) DomainInterfaceAddresses(d libvirt.Domain, source uint32, flags uint32) ([]libvirt.DomainInterface, error) {
+	c := t.begin("DomainInterfaceAddresses", "domain", d.Name, "source", libvirt.DomainInterfaceAddressesSource(source))
+	ifaces, err := t.inner.DomainInterfaceAddresses(d, source, flags)
+	c.detail("addresses", formatAddresses(ifaces)).done(err, "interfaces", len(ifaces))
+	return ifaces, err
+}
+
+func formatAddresses(ifaces []libvirt.DomainInterface) []string {
+	var out []string
+	for _, iface := range ifaces {
+		for _, a := range iface.Addrs {
+			out = append(out, fmt.Sprintf("%s=%s/%d", iface.Name, a.Addr, a.Prefix))
+		}
+	}
+	return out
+}
+
+func (t *tracingAPI) ConnectListAllDomains(needResults int32, flags libvirt.ConnectListAllDomainsFlags) ([]libvirt.Domain, uint32, error) {
+	c := t.begin("ConnectListAllDomains", flagKV(int64(flags))...)
+	doms, n, err := t.inner.ConnectListAllDomains(needResults, flags)
+	names := make([]string, 0, len(doms))
+	for _, d := range doms {
+		names = append(names, d.Name)
+	}
+	c.detail("names", names).done(err, "count", len(doms))
+	return doms, n, err
+}
+
+func (t *tracingAPI) StoragePoolLookupByName(name string) (libvirt.StoragePool, error) {
+	c := t.begin("StoragePoolLookupByName", "pool", name)
+	pool, err := t.inner.StoragePoolLookupByName(name)
+	c.done(err)
+	return pool, err
+}
+
+func (t *tracingAPI) StoragePoolRefresh(pool libvirt.StoragePool, flags uint32) error {
+	c := t.begin("StoragePoolRefresh", "pool", pool.Name)
+	err := t.inner.StoragePoolRefresh(pool, flags)
+	c.done(err)
+	return err
+}
+
+func (t *tracingAPI) StorageVolLookupByName(pool libvirt.StoragePool, name string) (libvirt.StorageVol, error) {
+	c := t.begin("StorageVolLookupByName", "pool", pool.Name, "volume", name)
+	vol, err := t.inner.StorageVolLookupByName(pool, name)
+	c.done(err)
+	return vol, err
+}
+
+func (t *tracingAPI) StorageVolGetPath(vol libvirt.StorageVol) (string, error) {
+	c := t.begin("StorageVolGetPath", "pool", vol.Pool, "volume", vol.Name)
+	path, err := t.inner.StorageVolGetPath(vol)
+	c.done(err, "path", path)
+	return path, err
+}
+
+func (t *tracingAPI) StorageVolCreateXML(pool libvirt.StoragePool, xml string, flags libvirt.StorageVolCreateFlags) (libvirt.StorageVol, error) {
+	c := t.begin("StorageVolCreateXML", append([]any{"pool", pool.Name, "xmlBytes", len(xml)}, flagKV(int64(flags))...)...).detail("xml", xml)
+	vol, err := t.inner.StorageVolCreateXML(pool, xml, flags)
+	c.done(err, "volume", vol.Name)
+	return vol, err
+}
+
+func (t *tracingAPI) StorageVolUpload(vol libvirt.StorageVol, r io.Reader, offset, length uint64, flags libvirt.StorageVolUploadFlags) error {
+	c := t.begin("StorageVolUpload", append([]any{"pool", vol.Pool, "volume", vol.Name, "offset", offset, "length", length}, flagKV(int64(flags))...)...)
+	err := t.inner.StorageVolUpload(vol, r, offset, length, flags)
+	c.done(err)
+	return err
+}
+
+func (t *tracingAPI) StorageVolDownload(vol libvirt.StorageVol, w io.Writer, offset, length uint64, flags libvirt.StorageVolDownloadFlags) error {
+	c := t.begin("StorageVolDownload", append([]any{"pool", vol.Pool, "volume", vol.Name, "offset", offset, "length", length}, flagKV(int64(flags))...)...)
+	err := t.inner.StorageVolDownload(vol, w, offset, length, flags)
+	c.done(err)
+	return err
+}
+
+func (t *tracingAPI) StorageVolDelete(vol libvirt.StorageVol, flags libvirt.StorageVolDeleteFlags) error {
+	c := t.begin("StorageVolDelete", append([]any{"pool", vol.Pool, "volume", vol.Name}, flagKV(int64(flags))...)...)
+	err := t.inner.StorageVolDelete(vol, flags)
+	c.done(err)
+	return err
+}

internal/provider/kvm/trace_test.go

@@ -0,0 +1,300 @@
+package kvm
+
+import (
+	"bytes"
+	"context"
+	"errors"
+	"io"
+	"reflect"
+	"strings"
+	"sync"
+	"testing"
+
+	libvirt "github.com/digitalocean/go-libvirt"
+	"github.com/go-logr/logr"
+	"github.com/go-logr/logr/funcr"
+)
+
+// captureLogger returns a funcr logger capped at verbosity (the test
+// stand-in for --zap-log-level=<verbosity>) and a snapshot function for the
+// lines it recorded. The sink is mutex-guarded: a cancelled call logs from
+// the abandoned goroutine.
+func captureLogger(verbosity int) (logr.Logger, func() []string) {
+	var mu sync.Mutex
+	var lines []string
+	log := funcr.New(func(prefix, args string) {
+		mu.Lock()
+		defer mu.Unlock()
+		lines = append(lines, prefix+" "+args)
+	}, funcr.Options{Verbosity: verbosity})
+	return log, func() []string {
+		mu.Lock()
+		defer mu.Unlock()
+		return append([]string(nil), lines...)
+	}
+}
+
+func captureContext(verbosity int) (context.Context, func() []string) {
+	log, snapshot := captureLogger(verbosity)
+	return logr.NewContext(context.Background(), log), snapshot
+}
+
+const stoppedName = "proxy-stopped"
+
+// tracedHost is a fake with one managed running domain and its volumes, so
+// every method of the seam has something to act on.
+func tracedHost(t *testing.T) *fakeAPI {
+	t.Helper()
+	api := readyHost()
+	managedDomain(t, api, testName, testUID, true, map[uint32][]libvirt.DomainInterface{
+		uint32(libvirt.DomainInterfaceAddressesSrcArp): {{Name: "vnet0", Addrs: []libvirt.DomainIPAddr{ipv4("192.168.1.50")}}},
+	})
+	api.putDomain(&fakeDomain{name: stoppedName})
+	return api
+}
+
+func TestTracingAPI_logsEveryMethod(t *testing.T) {
+	t.Parallel()
+	pool := libvirt.StoragePool{Name: "default"}
+	dom := libvirt.Domain{Name: testName}
+	overlay := libvirt.StorageVol{Pool: "default", Name: overlayVolumeName(testName)}
+	cases := []struct {
+		method string
+		call   func(api libvirtAPI) error
+	}{
+		{"DomainLookupByName", func(api libvirtAPI) error { _, err := api.DomainLookupByName(testName); return err }},
+		{"DomainDefineXML", func(api libvirtAPI) error {
+			xml, err := buildDomainXML(testDomainParams())
+			if err != nil {
+				return err
+			}
+			_, err = api.DomainDefineXML(xml)
+			return err
+		}},
+		{"DomainCreate", func(api libvirtAPI) error { return api.DomainCreate(libvirt.Domain{Name: stoppedName}) }},
+		{"DomainDestroy", func(api libvirtAPI) error { return api.DomainDestroy(dom) }},
+		{"DomainUndefineFlags", func(api libvirtAPI) error { return api.DomainUndefineFlags(dom, undefineFlags) }},
+		{"DomainGetState", func(api libvirtAPI) error { _, _, err := api.DomainGetState(dom, 0); return err }},
+		{"DomainGetMetadata", func(api libvirtAPI) error {
+			_, err := api.DomainGetMetadata(dom, int32(libvirt.DomainMetadataElement), libvirt.OptString{metadataURI}, 0)
+			return err
+		}},
+		{"DomainInterfaceAddresses", func(api libvirtAPI) error {
+			_, err := api.DomainInterfaceAddresses(dom, uint32(libvirt.DomainInterfaceAddressesSrcArp), 0)
+			return err
+		}},
+		{"ConnectListAllDomains", func(api libvirtAPI) error { _, _, err := api.ConnectListAllDomains(1, 0); return err }},
+		{"StoragePoolLookupByName", func(api libvirtAPI) error { _, err := api.StoragePoolLookupByName("default"); return err }},
+		{"StoragePoolRefresh", func(api libvirtAPI) error { return api.StoragePoolRefresh(pool, 0) }},
+		{"StorageVolLookupByName", func(api libvirtAPI) error { _, err := api.StorageVolLookupByName(pool, overlay.Name); return err }},
+		{"StorageVolGetPath", func(api libvirtAPI) error { _, err := api.StorageVolGetPath(overlay); return err }},
+		{"StorageVolCreateXML", func(api libvirtAPI) error {
+			xml, err := buildVolumeXML(rawVolume("new.iso", 3))
+			if err != nil {
+				return err
+			}
+			_, err = api.StorageVolCreateXML(pool, xml, 0)
+			return err
+		}},
+		{"StorageVolUpload", func(api libvirtAPI) error {
+			return api.StorageVolUpload(overlay, strings.NewReader("abc"), 0, 3, 0)
+		}},
+		{"StorageVolDownload", func(api libvirtAPI) error {
+			return api.StorageVolDownload(overlay, io.Discard, 0, 0, 0)
+		}},
+		{"StorageVolDelete", func(api libvirtAPI) error { return api.StorageVolDelete(overlay, 0) }},
+	}
+	if n := reflect.TypeOf((*libvirtAPI)(nil)).Elem().NumMethod(); n != len(cases) {
+		t.Fatalf("libvirtAPI has %d methods, this test covers %d; trace the new one", n, len(cases))
+	}
+	for _, tc := range cases {
+		t.Run(tc.method, func(t *testing.T) {
+			t.Parallel()
+			log, snapshot := captureLogger(1)
+			api := &tracingAPI{inner: tracedHost(t), log: log}
+			if err := tc.call(api); err != nil {
+				t.Fatalf("%s: %v", tc.method, err)
+			}
+			lines := snapshot()
+			if len(lines) != 1 {
+				t.Fatalf("logged %d lines, want exactly 1:\n%s", len(lines), strings.Join(lines, "\n"))
+			}
+			for _, want := range []string{`"msg"="libvirt call"`, `"rpc"="vir` + tc.method + `"`, `"duration"=`} {
+				if !strings.Contains(lines[0], want) {
+					t.Errorf("line missing %s:\n%s", want, lines[0])
+				}
+			}
+			if strings.Contains(lines[0], `"error"=`) {
+				t.Errorf("successful call logged an error:\n%s", lines[0])
+			}
+		})
+	}
+}
+
+func TestTracingAPI_passesResultsThrough(t *testing.T) {
+	t.Parallel()
+	inner := tracedHost(t)
+	log, _ := captureLogger(1)
+	traced := &tracingAPI{inner: inner, log: log}
+	dom := libvirt.Domain{Name: testName}
+
+	wantState, wantReason, err := inner.DomainGetState(dom, 0)
+	if err != nil {
+		t.Fatal(err)
+	}
+	state, reason, err := traced.DomainGetState(dom, 0)
+	if err != nil || state != wantState || reason != wantReason {
+		t.Errorf("DomainGetState = %d/%d/%v, want %d/%d/nil", state, reason, err, wantState, wantReason)
+	}
+
+	overlay := libvirt.StorageVol{Pool: "default", Name: overlayVolumeName(testName)}
+	wantPath, _ := inner.StorageVolGetPath(overlay)
+	if path, err := traced.StorageVolGetPath(overlay); err != nil || path != wantPath {
+		t.Errorf("StorageVolGetPath = %q/%v, want %q", path, err, wantPath)
+	}
+
+	wantDoms, _, _ := inner.ConnectListAllDomains(1, 0)
+	doms, _, err := traced.ConnectListAllDomains(1, 0)
+	if err != nil || !reflect.DeepEqual(doms, wantDoms) {
+		t.Errorf("ConnectListAllDomains = %v/%v, want %v", doms, err, wantDoms)
+	}
+
+	inner.fail["DomainCreate"] = lvError(libvirt.ErrOperationInvalid, "already running")
+	if err := traced.DomainCreate(dom); !hasCode(err, libvirt.ErrOperationInvalid) {
+		t.Errorf("DomainCreate error = %v, want the injected libvirt error unchanged", err)
+	}
+}
+
+func TestTracingAPI_errorFields(t *testing.T) {
+	t.Parallel()
+	tests := []struct {
+		name    string
+		inject  error
+		want    []string
+		notWant []string
+	}{
+		{
+			name:   "libvirt error carries code, name and message",
+			inject: lvError(libvirt.ErrNoDomain, "Domain not found: no domain with matching name"),
+			want:   []string{`"error"="Domain not found`, `"libvirtError"="ErrNoDomain"`, `"libvirtCode"=42`},
+		},
+		{
+			name:    "transport error has no libvirt fields",
+			inject:  io.EOF,
+			want:    []string{`"error"="EOF"`},
+			notWant: []string{`"libvirtError"`, `"libvirtCode"`},
+		},
+	}
+	for _, tc := range tests {
+		t.Run(tc.name, func(t *testing.T) {
+			t.Parallel()
+			inner := tracedHost(t)
+			inner.fail["DomainLookupByName"] = tc.inject
+			log, snapshot := captureLogger(1)
+			api := &tracingAPI{inner: inner, log: log}
+			if _, err := api.DomainLookupByName(testName); !errors.Is(err, tc.inject) {
+				t.Fatalf("error = %v, want the injected one", err)
+			}
+			joined := strings.Join(snapshot(), "\n")
+			for _, want := range tc.want {
+				if !strings.Contains(joined, want) {
+					t.Errorf("output missing %s:\n%s", want, joined)
+				}
+			}
+			for _, absent := range tc.notWant {
+				if strings.Contains(joined, absent) {
+					t.Errorf("output unexpectedly contains %s:\n%s", absent, joined)
+				}
+			}
+		})
+	}
+}
+
+func TestTracingAPI_detailOnlyAtV2(t *testing.T) {
+	t.Parallel()
+	dom := libvirt.Domain{Name: testName}
+	calls := []struct {
+		method string
+		call   func(api libvirtAPI) error
+		always string
+		detail string
+	}{
+		{"DomainDefineXML", func(api libvirtAPI) error {
+			xml, err := buildDomainXML(testDomainParams())
+			if err != nil {
+				return err
+			}
+			_, err = api.DomainDefineXML(xml)
+			return err
+		}, `"xmlBytes"=`, `"xml"="<domain`},
+		{"StorageVolCreateXML", func(api libvirtAPI) error {
+			xml, err := buildVolumeXML(rawVolume("new.iso", 3))
+			if err != nil {
+				return err
+			}
+			_, err = api.StorageVolCreateXML(libvirt.StoragePool{Name: "default"}, xml, 0)
+			return err
+		}, `"xmlBytes"=`, `"xml"="<volume`},
+		{"DomainGetMetadata", func(api libvirtAPI) error {
+			_, err := api.DomainGetMetadata(dom, int32(libvirt.DomainMetadataElement), libvirt.OptString{metadataURI}, 0)
+			return err
+		}, `"metadataBytes"=`, `"metadata"="<instance`},
+		{"DomainInterfaceAddresses", func(api libvirtAPI) error {
+			_, err := api.DomainInterfaceAddresses(dom, uint32(libvirt.DomainInterfaceAddressesSrcArp), 0)
+			return err
+		}, `"interfaces"=1`, `"addresses"=["vnet0=192.168.1.50/24"]`},
+		{"ConnectListAllDomains", func(api libvirtAPI) error {
+			_, _, err := api.ConnectListAllDomains(1, 0)
+			return err
+		}, `"count"=2`, `"names"=[`},
+	}
+	for _, verbosity := range []int{1, 2} {
+		for _, tc := range calls {
+			t.Run(tc.method+"/v"+string(rune('0'+verbosity)), func(t *testing.T) {
+				t.Parallel()
+				log, snapshot := captureLogger(verbosity)
+				api := &tracingAPI{inner: tracedHost(t), log: log}
+				if err := tc.call(api); err != nil {
+					t.Fatal(err)
+				}
+				joined := strings.Join(snapshot(), "\n")
+				if !strings.Contains(joined, tc.always) {
+					t.Errorf("v%d output missing %s:\n%s", verbosity, tc.always, joined)
+				}
+				if has := strings.Contains(joined, tc.detail); has != (verbosity >= 2) {
+					t.Errorf("v%d output contains %s = %v, want %v:\n%s", verbosity, tc.detail, has, verbosity >= 2, joined)
+				}
+			})
+		}
+	}
+}
+
+func TestTracingAPI_uploadLogsSizeNotContent(t *testing.T) {
+	t.Parallel()
+	const sentinel = "SENTINEL-seed-content-must-never-be-logged"
+	log, snapshot := captureLogger(2)
+	api := &tracingAPI{inner: tracedHost(t), log: log}
+	vol := libvirt.StorageVol{Pool: "default", Name: seedVolumeName(testName)}
+	if err := api.StorageVolUpload(vol, bytes.NewReader([]byte(sentinel)), 0, uint64(len(sentinel)), 0); err != nil {
+		t.Fatal(err)
+	}
+	joined := strings.Join(snapshot(), "\n")
+	if !strings.Contains(joined, `"length"=42`) {
+		t.Errorf("upload line missing the length:\n%s", joined)
+	}
+	if strings.Contains(joined, sentinel) {
+		t.Errorf("upload content leaked into logs:\n%s", joined)
+	}
+}
+
+func TestTracingAPI_silentBelowV1(t *testing.T) {
+	t.Parallel()
+	log, snapshot := captureLogger(0)
+	api := &tracingAPI{inner: tracedHost(t), log: log}
+	if _, err := api.DomainLookupByName(testName); err != nil {
+		t.Fatal(err)
+	}
+	if lines := snapshot(); len(lines) != 0 {
+		t.Errorf("verbosity 0 logged %d lines:\n%s", len(lines), strings.Join(lines, "\n"))
+	}
+}