kubevirt: Cannot create VirtualMachineInstances on k3s

Is this a BUG REPORT or FEATURE REQUEST?:

/kind bug

What happened:

I tried to use KubeVirt on k3s, and after some changes to the mount paths I managed to get it to run:

kubectl create namespace kubevirt
kubectl create configmap -n kubevirt kubevirt-config \
    --from-literal debug.useEmulation=true
kubectl apply -f https://gitlab.com/snippets/1893008/raw # this is `kubevirt.yaml`, but with a different hostPath for the device plugins

Everything appears to be working OK:

[root@vscode infractl]# kubectl get pod -n kubevirt
NAME                               READY   STATUS    RESTARTS   AGE
virt-handler-4hbgf                 1/1     Running   0          33m
virt-api-544b78bf44-mk8jq          1/1     Running   0          33m
virt-handler-zqg4j                 1/1     Running   0          33m
virt-handler-p5w56                 1/1     Running   0          33m
virt-api-544b78bf44-g9gdd          1/1     Running   0          33m
virt-controller-5479b6c869-h9r97   1/1     Running   0          33m
virt-handler-65ctr                 1/1     Running   0          33m
virt-controller-5479b6c869-9fk4r   1/1     Running   0          33m

The handlers, on which I changed the hostPaths, also appear to be working:

[root@vscode infractl]# kubectl logs -n kubevirt virt-handler-zqg4j
{"component":"virt-handler","hostname":"node-4","level":"info","pos":"virt-handler.go:187","timestamp":"2019-09-07T11:55:05.316279Z"}
{"component":"virt-handler","level":"info","msg":"Starting collector: node name=node-4","pos":"prometheus.go:395","timestamp":"2019-09-07T11:55:06.767441Z"}
{"component":"virt-handler","level":"info","msg":"STARTING informer vmiInformer","pos":"virtinformers.go:197","timestamp":"2019-09-07T11:55:06.767672Z"}
{"component":"virt-handler","level":"info","msg":"STARTING informer configMapInformer","pos":"virtinformers.go:197","timestamp":"2019-09-07T11:55:06.767704Z"}
{"component":"virt-handler","level":"info","msg":"STARTING informer CRDInformer","pos":"virtinformers.go:197","timestamp":"2019-09-07T11:55:06.767716Z"}
{"component":"virt-handler","level":"info","msg":"Starting virt-handler controller.","pos":"vm.go:516","timestamp":"2019-09-07T11:55:06.868536Z"}
{"component":"virt-handler","level":"info","msg":"metrics: max concurrent requests=3","pos":"virt-handler.go:341","timestamp":"2019-09-07T11:55:06.869842Z"}
{"component":"virt-handler","level":"info","msg":"Starting device plugin controller","pos":"device_controller.go:92","timestamp":"2019-09-07T11:55:06.968801Z"}
{"component":"virt-handler","level":"info","msg":"tun device plugin started","pos":"generic_device.go:156","timestamp":"2019-09-07T11:55:06.979846Z"}
{"component":"virt-handler","level":"info","msg":"vhost-net device plugin started","pos":"generic_device.go:156","timestamp":"2019-09-07T11:55:07.029438Z"}
{"component":"virt-handler","level":"info","msg":"kvm device plugin started","pos":"generic_device.go:156","timestamp":"2019-09-07T11:55:07.197759Z"}
{"component":"virt-handler","level":"info","msg":"Updating cluster config to resource version '1480'","pos":"config-map.go:400","timestamp":"2019-09-07T11:55:07.283757Z"}

So I tried to use the virtctl CLI:

[root@vscode pojntfx]# virtctl version
Client Version: version.Info{GitVersion:"v0.20.5", GitCommit:"5b0ba3b29247fd584a491b89381fcffc057446c1", GitTreeState:"clean", BuildDate:"2019-09-05T12:20:37Z", GoVersion:"go1.11.5", Compiler:"gc", Platform:"linux/amd64"}
the server is currently unable to handle the request

Which does not work, so I tried manually creating a VM:

[root@vscode pojntfx]# kubectl apply -f https://gitlab.com/snippets/1892983/raw -v 8
(...)
I0907 14:30:39.935187    2806 round_trippers.go:416] GET https://116.203.82.252:6443/apis/subresources.kubevirt.io/v1alpha3?timeout=32s
I0907 14:30:39.935269    2806 round_trippers.go:423] Request Headers:
I0907 14:30:39.935297    2806 round_trippers.go:426]     Accept: application/json, */*
I0907 14:30:39.935317    2806 round_trippers.go:426]     User-Agent: kubectl/v1.15.3 (linux/amd64) kubernetes/2d3c76f
I0907 14:30:39.935332    2806 round_trippers.go:426]     Authorization: Basic YWRtaW46YTI0ZThmODRkYjZjZWQzYTIzNzZkMzIzMmRmMGJhZTA=
I0907 14:30:39.943486    2806 round_trippers.go:441] Response Status: 503 Service Unavailable in 8 milliseconds
I0907 14:30:39.943527    2806 round_trippers.go:444] Response Headers:
I0907 14:30:39.943539    2806 round_trippers.go:447]     Content-Length: 20
I0907 14:30:39.943551    2806 round_trippers.go:447]     Content-Type: text/plain; charset=utf-8
I0907 14:30:39.943562    2806 round_trippers.go:447]     X-Content-Type-Options: nosniff
I0907 14:30:39.943573    2806 round_trippers.go:447]     Date: Sat, 07 Sep 2019 12:30:39 GMT
I0907 14:30:39.947558    2806 request.go:947] Response Body: service unavailable
I0907 14:30:39.951098    2806 request.go:1150] body was not decodable (unable to check for Status): couldn't get version/kind; json parse error: json: cannot unmarshal string into Go value of type struct { APIVersion string "json:\"apiVersion,omitempty\""; Kind string "json:\"kind,omitempty\"" }
I0907 14:30:39.951180    2806 cached_discovery.go:78] skipped caching discovery info due to the server is currently unable to handle the request
I0907 14:30:39.954497    2806 round_trippers.go:416] GET https://116.203.82.252:6443/apis/kubevirt.io/v1alpha3/namespaces/default/virtualmachineinstances/testvmi-nocloud
I0907 14:30:39.954531    2806 round_trippers.go:423] Request Headers:
I0907 14:30:39.954546    2806 round_trippers.go:426]     User-Agent: kubectl/v1.15.3 (linux/amd64) kubernetes/2d3c76f
I0907 14:30:39.954562    2806 round_trippers.go:426]     Authorization: Basic YWRtaW46YTI0ZThmODRkYjZjZWQzYTIzNzZkMzIzMmRmMGJhZTA=
I0907 14:30:39.954576    2806 round_trippers.go:426]     Accept: application/json
I0907 14:30:39.958890    2806 round_trippers.go:441] Response Status: 404 Not Found in 4 milliseconds
I0907 14:30:39.958944    2806 round_trippers.go:444] Response Headers:
I0907 14:30:39.958968    2806 round_trippers.go:447]     Content-Type: application/json
I0907 14:30:39.958989    2806 round_trippers.go:447]     Date: Sat, 07 Sep 2019 12:30:39 GMT
I0907 14:30:39.959010    2806 round_trippers.go:447]     Content-Length: 270
I0907 14:30:39.959141    2806 request.go:947] Response Body: {"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"virtualmachineinstances.kubevirt.io \"testvmi-nocloud\" not found","reason":"NotFound","details":{"name":"testvmi-nocloud","group":"kubevirt.io","kind":"virtualmachineinstances"},"code":404}
I0907 14:30:39.960757    2806 request.go:947] Request Body: {"apiVersion":"kubevirt.io/v1alpha3","kind":"VirtualMachineInstance","metadata":{"annotations":{"kubectl.kubernetes.io/last-applied-configuration":"{\"apiVersion\":\"kubevirt.io/v1alpha3\",\"kind\":\"VirtualMachineInstance\",\"metadata\":{\"annotations\":{},\"name\":\"testvmi-nocloud\",\"namespace\":\"default\"},\"spec\":{\"domain\":{\"devices\":{\"disks\":[{\"disk\":{\"bus\":\"virtio\"},\"name\":\"containerdisk\"},{\"disk\":{\"bus\":\"virtio\"},\"name\":\"emptydisk\"},{\"disk\":{\"bus\":\"virtio\"},\"name\":\"cloudinitdisk\"}]},\"resources\":{\"requests\":{\"memory\":\"1024M\"}}},\"terminationGracePeriodSeconds\":30,\"volumes\":[{\"containerDisk\":{\"image\":\"kubevirt/fedora-cloud-container-disk-demo:latest\"},\"name\":\"containerdisk\"},{\"emptyDisk\":{\"capacity\":\"2Gi\"},\"name\":\"emptydisk\"},{\"cloudInitNoCloud\":{\"userData\":\"#cloud-config\\npassword: fedora\\nchpasswd: { expire: False }\"},\"name\":\"cloudinitdisk\"}]}}\n"},"name":"testvmi-nocloud","namespace":"default"},"spec":{"domain":{"device [truncated 526 chars]
I0907 14:30:39.960889    2806 round_trippers.go:416] POST https://116.203.82.252:6443/apis/kubevirt.io/v1alpha3/namespaces/default/virtualmachineinstances
I0907 14:30:39.960911    2806 round_trippers.go:423] Request Headers:
I0907 14:30:39.960926    2806 round_trippers.go:426]     Accept: application/json
I0907 14:30:39.960941    2806 round_trippers.go:426]     Content-Type: application/json
I0907 14:30:39.960955    2806 round_trippers.go:426]     User-Agent: kubectl/v1.15.3 (linux/amd64) kubernetes/2d3c76f
I0907 14:30:39.960968    2806 round_trippers.go:426]     Authorization: Basic YWRtaW46YTI0ZThmODRkYjZjZWQzYTIzNzZkMzIzMmRmMGJhZTA=
I0907 14:31:39.967487    2806 round_trippers.go:441] Response Status: 504 Gateway Timeout in 60006 milliseconds
I0907 14:31:39.967579    2806 round_trippers.go:444] Response Headers:
I0907 14:31:39.967596    2806 round_trippers.go:447]     Date: Sat, 07 Sep 2019 12:31:39 GMT
I0907 14:31:39.967611    2806 round_trippers.go:447]     Content-Length: 136
I0907 14:31:39.967623    2806 round_trippers.go:447]     Content-Type: text/plain; charset=utf-8
I0907 14:31:39.967957    2806 request.go:947] Response Body: {"metadata":{},"status":"Failure","message":"Timeout: request did not complete within 1m0s","reason":"Timeout","details":{},"code":504}
I0907 14:31:39.968545    2806 helpers.go:199] server response object: [{
  "metadata": {},
  "status": "Failure",
  "message": "error when creating \"https://gitlab.com/snippets/1892983/raw\": the server was unable to return a response in the time allotted, but may still be processing the request (post virtualmachineinstances.kubevirt.io)",
  "reason": "Timeout",
  "details": {
    "group": "kubevirt.io",
    "kind": "virtualmachineinstances",
    "causes": [
      {
        "reason": "UnexpectedServerResponse",
        "message": "{\"metadata\":{},\"status\":\"Failure\",\"message\":\"Timeout: request did not complete within 1m0s\",\"reason\":\"Timeout\",\"details\":{},\"code\":504}"
      }
    ]
  },
  "code": 504
}]
F0907 14:31:39.968740    2806 helpers.go:114] Error from server (Timeout): error when creating "https://gitlab.com/snippets/1892983/raw": the server was unable to return a response in the time allotted, but may still be processing the request (post virtualmachineinstances.kubevirt.io)

Which in turn does also not work.

The API servers don’t show any information on the POST requests:

[root@vscode infractl]# kubectl logs -n kubevirt virt-api-544b78bf44-mk8jq | grep POST
[root@vscode infractl]# kubectl logs -n kubevirt virt-api-544b78bf44-g9gdd | grep POST
[root@vscode infractl]# 

What you expected to happen:

The VM gets created.

How to reproduce it (as minimally and precisely as possible):

kubectl create namespace kubevirt
kubectl create configmap -n kubevirt kubevirt-config \
    --from-literal debug.useEmulation=true
kubectl apply -f https://gitlab.com/snippets/1893008/raw
kubectl get pod -n kubevirt
# See above for the rest

Anything else we need to know?:

I’ve tried this with multiple releases of k3s (v0.9.0-rc2, v0.8.1) and the issue persists.

Environment:

• KubeVirt version (use virtctl version): [root@vscode infractl]# virtctl version Client Version: version.Info{GitVersion:“v0.20.5”, GitCommit:“5b0ba3b29247fd584a491b89381fcffc057446c1”, GitTreeState:“clean”, BuildDate:“2019-09-05T12:20:37Z”, GoVersion:“go1.11.5”, Compiler:“gc”, Platform:“linux/amd64”} the server is currently unable to handle the request

• Kubernetes version (use kubectl version): v1.15.3-k3s.1

• VM or VMI specifications: kubevirt/fedora-cloud-container-disk-demo:latest

• Cloud provider or hardware configuration: Hetzner Cloud CX21 instances

• OS (e.g. from /etc/os-release): CentOS 7

• Kernel (e.g. uname -a): Linux node-3 4.19.0-5-amd64 #1 SMP Debian 4.19.37-5 (2019-06-19) x86_64 GNU/Linux

• Install tools: Manual via SSH/infractl

• Others: Development OS is CentOS 7

Thanks to anyone looking into this!