Bug 1878118

Summary: [CNV 2.5] VM failed to start
Product: Container Native Virtualization (CNV) Reporter: Israel Pinto <ipinto>
Component: VirtualizationAssignee: Jed Lejosne <jlejosne>
Status: CLOSED ERRATA QA Contact: Israel Pinto <ipinto>
Severity: high Docs Contact:
Priority: high    
Version: 2.5.0CC: cnv-qe-bugs, dbelenky, jlejosne, lbednar, sgott, yadu
Target Milestone: ---Keywords: Regression
Target Release: 2.5.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: container-native-virtualization-virt-handler:v2.5.0-48 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-11-17 13:24:22 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Israel Pinto 2020-09-11 11:12:40 UTC
Description of problem:
With CNV 2.5 VM failed to start, error: 
 Warning  FailedCreatePodSandBox  2m55s  kubelet, verify-25-cxpp6-worker-0-smxx4  Failed to create pod sandbox: rpc error: code = Unknown desc = container create failed: time="2020-09-10T06:37:14Z" level=warning msg="exit status 1"
time="2020-09-10T06:37:14Z" level=error msg="container_linux.go:348: starting container process caused \"process_linux.go:438: container init caused \\\"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\\\"\""

Version-Release number of selected component (if applicable):
CNV 2.5
OCP 4.6

How reproducible:
100%

Steps to Reproduce:
1. Create VM
2. Start VM 

Actual results:
VMI failed to start


Additional info:
[root@cnvqe-01 vms]# oc describe pod virt-launcher-vm-cirros-rsf9l       
Name:           virt-launcher-vm-cirros-rsf9l
Namespace:      default
Priority:       0
Node:           verify-25-cxpp6-worker-0-smxx4/192.168.3.60
Start Time:     Fri, 11 Sep 2020 14:03:24 +0300
Labels:         kubevirt.io=virt-launcher
                kubevirt.io/created-by=cdf34f93-57ba-402b-82b5-b13fbd37d7c7
                kubevirt.io/vm=vm-cirros
Annotations:    k8s.v1.cni.cncf.io/network-status:
                  [{
                      "name": "",
                      "interface": "eth0",
                      "ips": [
                          "10.131.0.103"
                      ],
                      "default": true,
                      "dns": {}
                  }]
                k8s.v1.cni.cncf.io/networks-status:
                  [{
                      "name": "",
                      "interface": "eth0",
                      "ips": [
                          "10.131.0.103"
                      ],
                      "default": true,
                      "dns": {}
                  }]
                kubevirt.io/domain: vm-cirros
                traffic.sidecar.istio.io/kubevirtInterfaces: k6t-eth0
Status:         Pending
IP:             
IPs:            <none>
Controlled By:  VirtualMachineInstance/vm-cirros
Init Containers:
  container-disk-binary:
    Container ID:  
    Image:         registry.redhat.io/container-native-virtualization/virt-launcher@sha256:e2cc962033d834be67dbe0d47c13f45d9cd2f65a7c182f5caad3f2bea33c4123
    Image ID:      
    Port:          <none>
    Host Port:     <none>
    Command:
      /usr/bin/cp
      /usr/bin/container-disk
      /init/usr/bin/container-disk
    State:          Waiting
      Reason:       PodInitializing
    Ready:          False
    Restart Count:  0
    Limits:
      cpu:     100m
      memory:  40M
    Requests:
      cpu:        10m
      memory:     1M
    Environment:  <none>
    Mounts:
      /init/usr/bin from virt-bin-share-dir (rw)
Containers:
  compute:
    Container ID:  
    Image:         registry.redhat.io/container-native-virtualization/virt-launcher@sha256:e2cc962033d834be67dbe0d47c13f45d9cd2f65a7c182f5caad3f2bea33c4123
    Image ID:      
    Port:          <none>
    Host Port:     <none>
    Command:
      /usr/bin/virt-launcher
      --qemu-timeout
      5m
      --name
      vm-cirros
      --uid
      cdf34f93-57ba-402b-82b5-b13fbd37d7c7
      --namespace
      default
      --kubevirt-share-dir
      /var/run/kubevirt
      --ephemeral-disk-dir
      /var/run/kubevirt-ephemeral-disks
      --container-disk-dir
      /var/run/kubevirt/container-disks
      --grace-period-seconds
      15
      --hook-sidecars
      0
      --less-pvc-space-toleration
      10
      --ovmf-path
      /usr/share/OVMF
    State:          Waiting
      Reason:       PodInitializing
    Ready:          False
    Restart Count:  0
    Limits:
      devices.kubevirt.io/kvm:        1
      devices.kubevirt.io/tun:        1
      devices.kubevirt.io/vhost-net:  1
    Requests:
      cpu:                            100m
      devices.kubevirt.io/kvm:        1
      devices.kubevirt.io/tun:        1
      devices.kubevirt.io/vhost-net:  1
      memory:                         225679432
    Environment:                      <none>
    Mounts:
      /var/run/kubevirt-ephemeral-disks from ephemeral-disks (rw)
      /var/run/kubevirt/container-disks from container-disks (rw)
      /var/run/kubevirt/sockets from sockets (rw)
      /var/run/libvirt from libvirt-runtime (rw)
  volumecontainerdisk:
    Container ID:  
    Image:         kubevirt/cirros-container-disk-demo:latest
    Image ID:      
    Port:          <none>
    Host Port:     <none>
    Command:
      /usr/bin/container-disk
    Args:
      --copy-path
      /var/run/kubevirt-ephemeral-disks/container-disk-data/cdf34f93-57ba-402b-82b5-b13fbd37d7c7/disk_0
    State:          Waiting
      Reason:       PodInitializing
    Ready:          False
    Restart Count:  0
    Limits:
      cpu:     100m
      memory:  40M
    Requests:
      cpu:        10m
      memory:     1M
    Environment:  <none>
    Mounts:
      /usr/bin from virt-bin-share-dir (rw)
      /var/run/kubevirt-ephemeral-disks/container-disk-data/cdf34f93-57ba-402b-82b5-b13fbd37d7c7 from container-disks (rw)
Conditions:
  Type              Status
  Initialized       False 
  Ready             False 
  ContainersReady   False 
  PodScheduled      True 
Volumes:
  sockets:
    Type:       EmptyDir (a temporary directory that shares a pod's lifetime)
    Medium:     
    SizeLimit:  <unset>
  virt-bin-share-dir:
    Type:       EmptyDir (a temporary directory that shares a pod's lifetime)
    Medium:     
    SizeLimit:  <unset>
  libvirt-runtime:
    Type:       EmptyDir (a temporary directory that shares a pod's lifetime)
    Medium:     
    SizeLimit:  <unset>
  ephemeral-disks:
    Type:       EmptyDir (a temporary directory that shares a pod's lifetime)
    Medium:     
    SizeLimit:  <unset>
  container-disks:
    Type:        EmptyDir (a temporary directory that shares a pod's lifetime)
    Medium:      
    SizeLimit:   <unset>
QoS Class:       Burstable
Node-Selectors:  kubevirt.io/schedulable=true
Tolerations:     node.kubernetes.io/memory-pressure:NoSchedule op=Exists
                 node.kubernetes.io/not-ready:NoExecute op=Exists for 300s
                 node.kubernetes.io/unreachable:NoExecute op=Exists for 300s
Events:
  Type     Reason                  Age   From                                     Message
  ----     ------                  ----  ----                                     -------
  Normal   Scheduled               38s                                            Successfully assigned default/virt-launcher-vm-cirros-rsf9l to verify-25-cxpp6-worker-0-smxx4
  Normal   AddedInterface          36s   multus                                   Add eth0 [10.131.0.90/23]
  Warning  FailedCreatePodSandBox  35s   kubelet, verify-25-cxpp6-worker-0-smxx4  Failed to create pod sandbox: rpc error: code = Unknown desc = container create failed: time="2020-09-11T11:03:27Z" level=warning msg="exit status 1"
time="2020-09-11T11:03:27Z" level=error msg="container_linux.go:348: starting container process caused \"process_linux.go:438: container init caused \\\"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\\\"\""
container_linux.go:348: starting container process caused "process_linux.go:438: container init caused \"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\""
  Normal   AddedInterface          34s  multus                                   Add eth0 [10.131.0.91/23]
  Warning  FailedCreatePodSandBox  34s  kubelet, verify-25-cxpp6-worker-0-smxx4  Failed to create pod sandbox: rpc error: code = Unknown desc = container create failed: time="2020-09-11T11:03:29Z" level=warning msg="exit status 1"
time="2020-09-11T11:03:29Z" level=error msg="container_linux.go:348: starting container process caused \"process_linux.go:438: container init caused \\\"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\\\"\""
container_linux.go:348: starting container process caused "process_linux.go:438: container init caused \"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\""
  Normal   AddedInterface          32s  multus                                   Add eth0 [10.131.0.92/23]
  Warning  FailedCreatePodSandBox  31s  kubelet, verify-25-cxpp6-worker-0-smxx4  Failed to create pod sandbox: rpc error: code = Unknown desc = container create failed: time="2020-09-11T11:03:31Z" level=warning msg="exit status 1"
time="2020-09-11T11:03:31Z" level=error msg="container_linux.go:348: starting container process caused \"process_linux.go:438: container init caused \\\"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\\\"\""
container_linux.go:348: starting container process caused "process_linux.go:438: container init caused \"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\""
  Warning  FailedCreatePodSandBox  29s  kubelet, verify-25-cxpp6-worker-0-smxx4  Failed to create pod sandbox: rpc error: code = Unknown desc = container create failed: time="2020-09-11T11:03:34Z" level=warning msg="exit status 1"
time="2020-09-11T11:03:34Z" level=error msg="container_linux.go:348: starting container process caused \"process_linux.go:438: container init caused \\\"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\\\"\""
container_linux.go:348: starting container process caused "process_linux.go:438: container init caused \"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\""
  Normal   AddedInterface          29s  multus                                   Add eth0 [10.131.0.93/23]
  Normal   AddedInterface          26s  multus                                   Add eth0 [10.131.0.94/23]
  Warning  FailedCreatePodSandBox  26s  kubelet, verify-25-cxpp6-worker-0-smxx4  Failed to create pod sandbox: rpc error: code = Unknown desc = container create failed: time="2020-09-11T11:03:37Z" level=warning msg="exit status 1"
time="2020-09-11T11:03:37Z" level=error msg="container_linux.go:348: starting container process caused \"process_linux.go:438: container init caused \\\"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\\\"\""
container_linux.go:348: starting container process caused "process_linux.go:438: container init caused \"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\""
  Normal   AddedInterface          23s  multus                                   Add eth0 [10.131.0.95/23]
  Warning  FailedCreatePodSandBox  23s  kubelet, verify-25-cxpp6-worker-0-smxx4  Failed to create pod sandbox: rpc error: code = Unknown desc = container create failed: time="2020-09-11T11:03:40Z" level=warning msg="exit status 1"
time="2020-09-11T11:03:40Z" level=error msg="container_linux.go:348: starting container process caused \"process_linux.go:438: container init caused \\\"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\\\"\""
container_linux.go:348: starting container process caused "process_linux.go:438: container init caused \"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\""
  Warning  FailedCreatePodSandBox  21s  kubelet, verify-25-cxpp6-worker-0-smxx4  Failed to create pod sandbox: rpc error: code = Unknown desc = container create failed: time="2020-09-11T11:03:42Z" level=warning msg="exit status 1"
time="2020-09-11T11:03:42Z" level=error msg="container_linux.go:348: starting container process caused \"process_linux.go:438: container init caused \\\"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\\\"\""
container_linux.go:348: starting container process caused "process_linux.go:438: container init caused \"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\""
  Normal   AddedInterface          21s  multus                                   Add eth0 [10.131.0.96/23]
  Normal   AddedInterface          18s  multus                                   Add eth0 [10.131.0.97/23]
  Warning  FailedCreatePodSandBox  18s  kubelet, verify-25-cxpp6-worker-0-smxx4  Failed to create pod sandbox: rpc error: code = Unknown desc = container create failed: time="2020-09-11T11:03:45Z" level=warning msg="exit status 1"
time="2020-09-11T11:03:45Z" level=error msg="container_linux.go:348: starting container process caused \"process_linux.go:438: container init caused \\\"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\\\"\""
container_linux.go:348: starting container process caused "process_linux.go:438: container init caused \"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\""
  Normal   AddedInterface          15s  multus                                   Add eth0 [10.131.0.98/23]
  Warning  FailedCreatePodSandBox  14s  kubelet, verify-25-cxpp6-worker-0-smxx4  Failed to create pod sandbox: rpc error: code = Unknown desc = container create failed: time="2020-09-11T11:03:48Z" level=warning msg="exit status 1"
time="2020-09-11T11:03:48Z" level=error msg="container_linux.go:348: starting container process caused \"process_linux.go:438: container init caused \\\"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\\\"\""
container_linux.go:348: starting container process caused "process_linux.go:438: container init caused \"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\""
  Normal   AddedInterface          13s               multus                                   Add eth0 [10.131.0.99/23]
  Normal   AddedInterface          11s               multus                                   Add eth0 [10.131.0.100/23]
  Normal   AddedInterface          9s                multus                                   Add eth0 [10.131.0.101/23]
  Normal   AddedInterface          7s                multus                                   Add eth0 [10.131.0.102/23]
  Normal   AddedInterface          4s                multus                                   Add eth0 [10.131.0.103/23]
  Warning  FailedCreatePodSandBox  3s (x5 over 12s)  kubelet, verify-25-cxpp6-worker-0-smxx4  (combined from similar events): Failed to create pod sandbox: rpc error: code = Unknown desc = container create failed: time="2020-09-11T11:04:00Z" level=warning msg="exit status 1"
time="2020-09-11T11:04:00Z" level=error msg="container_linux.go:348: starting container process caused \"process_linux.go:438: container init caused \\\"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\\\"\""
container_linux.go:348: starting container process caused "process_linux.go:438: container init caused \"failed to set /proc/self/attr/keycreate on procfs: write /proc/self/attr/keycreate: invalid argument\""
  Normal  AddedInterface  0s  multus  Add eth0 [10.131.0.104/23]

  
#oc get pods   
virt-launcher-vm-cirros-rsf9l   0/2     Init:0/1   0          75s


# oc logs virt-launcher-vm-cirros-rsf9l --container=compute
Error from server (BadRequest): container "compute" in pod "virt-launcher-vm-cirros-rsf9l" is waiting to start: PodInitializing

Comment 2 Daniel Belenky 2020-09-14 07:41:35 UTC
PR was merged and propagated to a downstream build
registry-proxy.engineering.redhat.com/rh-osbs/container-native-virtualization-virt-handler:v2.5.0-48

Comment 4 Lukas Bednar 2020-09-17 06:15:27 UTC
Can not reproduce with HCO-v2.5.0-181

Comment 7 errata-xmlrpc 2020-11-17 13:24:22 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (OpenShift Virtualization 2.5.0 Images), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHEA-2020:5127