Fedora Account System
Red Hat Associate
Red Hat Customer
Description of problem: Cannot start a VM with sidecar. Version-Release number of selected component (if applicable): cluster-network-addons-operator-container-v2.6.0-5 How reproducible: 100% Steps to Reproduce: 1. Create a VM with sidecar 2. Start the VM Actual results: VM fails to start: $ oc get vm,vmi,pod -n virt-general-custom-hooks-test-vm-with-sidecar NAME AGE VOLUME virtualmachine.kubevirt.io/vmi-with-sidecar-hook-1607011105-5713377 12s NAME AGE PHASE IP NODENAME virtualmachineinstance.kubevirt.io/vmi-with-sidecar-hook-1607011105-5713377 11s Scheduled 10.129.2.65 pytest-nightly-pscgr-worker-0-xj94k NAME READY STATUS RESTARTS AGE pod/virt-launcher-vmi-with-sidecar-hook-1607011105-5713377-x5dtv 3/3 Running 0 11s Expected results: VM should be running Additional info: $ oc describe vmi -n virt-general-custom-hooks-test-vm-with-sidecar Name: vmi-with-sidecar-hook-1607011105-5713377 Namespace: virt-general-custom-hooks-test-vm-with-sidecar Labels: kubevirt.io/domain=vmi-with-sidecar-hook-1607011105-5713377 kubevirt.io/nodeName=pytest-nightly-pscgr-worker-0-xj94k kubevirt.io/vm=vmi-with-sidecar-hook-1607011105-5713377 special=vmi-with-sidecar-hook-1607011105-5713377 Annotations: hooks.kubevirt.io/hookSidecars: [{"image": "kubevirt/example-hook-sidecar:v0.13.3"}] kubevirt.io/latest-observed-api-version: v1alpha3 kubevirt.io/storage-observed-api-version: v1alpha3 smbios.vm.kubevirt.io/baseBoardManufacturer: Radical Edward API Version: kubevirt.io/v1alpha3 Kind: VirtualMachineInstance Metadata: Creation Timestamp: 2020-12-03T15:58:26Z Finalizers: foregroundDeleteVirtualMachine Generation: 45 Managed Fields: API Version: kubevirt.io/v1alpha3 Fields Type: FieldsV1 fieldsV1: f:metadata: f:annotations: .: f:hooks.kubevirt.io/hookSidecars: f:kubevirt.io/latest-observed-api-version: f:kubevirt.io/storage-observed-api-version: f:smbios.vm.kubevirt.io/baseBoardManufacturer: f:labels: .: f:kubevirt.io/domain: f:kubevirt.io/nodeName: f:kubevirt.io/vm: f:special: f:ownerReferences: f:spec: .: f:domain: .: f:cpu: .: f:cores: f:devices: .: f:disks: f:interfaces: f:rng: f:firmware: .: f:uuid: f:machine: .: f:type: f:resources: .: f:requests: .: f:memory: f:networks: f:terminationGracePeriodSeconds: f:volumes: f:status: .: f:activePods: .: f:9561c2c0-a456-475d-ae98-e9805de639cf: f:guestOSInfo: f:nodeName: f:phase: f:qosClass: Manager: virt-controller Operation: Update Time: 2020-12-03T15:58:33Z API Version: kubevirt.io/v1alpha3 Fields Type: FieldsV1 fieldsV1: f:status: f:conditions: f:interfaces: f:migrationMethod: Manager: virt-handler Operation: Update Time: 2020-12-03T15:58:47Z Owner References: API Version: kubevirt.io/v1alpha3 Block Owner Deletion: true Controller: true Kind: VirtualMachine Name: vmi-with-sidecar-hook-1607011105-5713377 UID: af6beff7-034a-495b-a38f-3b8ecb7e5013 Resource Version: 2658807 Self Link: /apis/kubevirt.io/v1alpha3/namespaces/virt-general-custom-hooks-test-vm-with-sidecar/virtualmachineinstances/vmi-with-sidecar-hook-1607011105-5713377 UID: 880487bb-f7c1-4100-b014-821c8980239e Spec: Domain: Cpu: Cores: 1 Devices: Disks: Disk: Bus: virtio Name: containerdisk Disk: Bus: virtio Name: cloudinitdisk Interfaces: Mac Address: 02:d5:98:00:00:5a Masquerade: Name: default Rng: Features: Acpi: Enabled: true Firmware: Uuid: f0014236-4024-5d30-b1fa-8e185373cea6 Machine: Type: pc-q35-rhel8.2.0 Resources: Requests: Cpu: 100m Memory: 1Gi Networks: Name: default Pod: Termination Grace Period Seconds: 30 Volumes: Container Disk: Image: quay.io/openshift-cnv/qe-cnv-tests-fedora:33 Image Pull Policy: IfNotPresent Name: containerdisk Cloud Init No Cloud: User Data: #cloud-config chpasswd: { expire: False } password: fedora Name: cloudinitdisk Status: Active Pods: 9561c2c0-a456-475d-ae98-e9805de639cf: pytest-nightly-pscgr-worker-0-xj94k Conditions: Last Probe Time: <nil> Last Transition Time: <nil> Status: True Type: LiveMigratable Last Probe Time: <nil> Last Transition Time: 2020-12-03T15:58:36Z Message: server error. command SyncVMI failed: "LibvirtError(Code=38, Domain=0, Message='Cannot set interface MAC to fe:d5:98:00:00:5a on 'tap0': Operation not permitted')" Reason: Synchronizing with the Domain failed. Status: False Type: Synchronized Guest OS Info: Interfaces: Ip Address: 10.129.2.65 Ip Addresses: 10.129.2.65 Mac: 52:54:00:3a:fb:68 Name: default Migration Method: BlockMigration Node Name: pytest-nightly-pscgr-worker-0-xj94k Phase: Scheduled Qos Class: Burstable Events: Type Reason Age From Message ---- ------ ---- ---- ------- Normal SuccessfulCreate 21s virtualmachine-controller Created virtual machine pod virt-launcher-vmi-with-sidecar-hook-1607011105-5713377-x5dtv Warning SyncFailed 11s virt-handler server error. command SyncVMI failed: "LibvirtError(Code=38, Domain=0, Message='Cannot set interface MAC to fe:d5:98:00:00:5a on 'tap0': Operation not permitted')" Warning SyncFailed 11s virt-handler server error. command SyncVMI failed: "LibvirtError(Code=38, Domain=0, Message='Unable to create tap device vnet0: Operation not permitted')" Warning SyncFailed 11s virt-handler server error. command SyncVMI failed: "LibvirtError(Code=38, Domain=0, Message='Unable to create tap device vnet1: Operation not permitted')" Warning SyncFailed 11s virt-handler server error. command SyncVMI failed: "LibvirtError(Code=38, Domain=0, Message='Unable to create tap device vnet2: Operation not permitted')" Warning SyncFailed 11s virt-handler server error. command SyncVMI failed: "LibvirtError(Code=38, Domain=0, Message='Unable to create tap device vnet3: Operation not permitted')" Warning SyncFailed 10s virt-handler server error. command SyncVMI failed: "LibvirtError(Code=38, Domain=0, Message='Unable to create tap device vnet4: Operation not permitted')" Warning SyncFailed 10s virt-handler server error. command SyncVMI failed: "LibvirtError(Code=38, Domain=0, Message='Unable to create tap device vnet5: Operation not permitted')" Warning SyncFailed 10s virt-handler server error. command SyncVMI failed: "LibvirtError(Code=38, Domain=0, Message='Unable to create tap device vnet6: Operation not permitted')" Warning SyncFailed 10s virt-handler server error. command SyncVMI failed: "LibvirtError(Code=38, Domain=0, Message='Unable to create tap device vnet7: Operation not permitted')" Warning SyncFailed 7s (x16 over 10s) virt-handler (combined from similar events): server error. command SyncVMI failed: "LibvirtError(Code=38, Domain=0, Message='Unable to create tap device vnet23: Operation not permitted')" $ oc logs -n virt-general-custom-hooks-test-vm-with-sidecar virt-launcher-vmi-with-sidecar-hook-1607011105-5713377-x5dtv -c compute 2020/12/03 15:58:31 WARNING: proto: file "api.proto" is already registered A future release will panic on registration conflicts. See: https://developers.google.com/protocol-buffers/docs/reference/go/faq#namespace-conflict 2020/12/03 15:58:31 WARNING: proto: file "api.proto" is already registered A future release will panic on registration conflicts. See: https://developers.google.com/protocol-buffers/docs/reference/go/faq#namespace-conflict 2020/12/03 15:58:31 WARNING: proto: file "api.proto" is already registered A future release will panic on registration conflicts. See: https://developers.google.com/protocol-buffers/docs/reference/go/faq#namespace-conflict 2020/12/03 15:58:31 WARNING: proto: file "api.proto" is already registered A future release will panic on registration conflicts. See: https://developers.google.com/protocol-buffers/docs/reference/go/faq#namespace-conflict {"component":"virt-launcher","level":"info","msg":"Collected all requested hook sidecar sockets","pos":"manager.go:68","timestamp":"2020-12-03T15:58:33.742373Z"} {"component":"virt-launcher","level":"info","msg":"Sorted all collected sidecar sockets per hook point based on their priority and name: map[OnDefineDomain:[0xc0005269c0]]","pos":"manager.go:71","timestamp":"2020-12-03T15:58:33.742795Z"} {"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon: qemu:///system","pos":"libvirt.go:380","timestamp":"2020-12-03T15:58:33.754931Z"} {"component":"virt-launcher","level":"info","msg":"Connecting to libvirt daemon failed: virError(Code=38, Domain=7, Message='Failed to connect socket to '/var/run/libvirt/libvirt-sock': No such file or directory')","pos":"libvirt.go:388","timestamp":"2020-12-03T15:58:33.765362Z"} {"component":"virt-launcher","level":"info","msg":"libvirt version: 6.6.0, package: 7.module+el8.3.0+8424+5ea525c5 (Red Hat, Inc. \u003chttp://bugzilla.redhat.com/bugzilla\u003e, 2020-10-13-08:21:17, )","subcomponent":"libvirt","thread":"47","timestamp":"2020-12-03T15:58:33.807000Z"} {"component":"virt-launcher","level":"info","msg":"hostname: vmi-with-sidecar-hook-1607011105-5713377","subcomponent":"libvirt","thread":"47","timestamp":"2020-12-03T15:58:33.807000Z"} {"component":"virt-launcher","level":"error","msg":"internal error: Child process (dmidecode -q -t 0,1,2,3,4,11,17) unexpected exit status 1: /dev/mem: No such file or directory","pos":"virCommandWait:2744","subcomponent":"libvirt","thread":"47","timestamp":"2020-12-03T15:58:33.807000Z"} {"component":"virt-launcher","level":"info","msg":"Connected to libvirt daemon","pos":"libvirt.go:396","timestamp":"2020-12-03T15:58:34.269194Z"} {"component":"virt-launcher","level":"info","msg":"Registered libvirt event notify callback","pos":"client.go:394","timestamp":"2020-12-03T15:58:34.272735Z"} {"component":"virt-launcher","level":"info","msg":"Marked as ready","pos":"virt-launcher.go:71","timestamp":"2020-12-03T15:58:34.273014Z"} {"component":"virt-launcher","kind":"","level":"info","msg":"Executing PreStartHook on VMI pod environment","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"manager.go:994","timestamp":"2020-12-03T15:58:35.355097Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"} {"component":"virt-launcher","kind":"","level":"info","msg":"Starting PreCloudInitIso hook","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"manager.go:1003","timestamp":"2020-12-03T15:58:35.355195Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"} {"component":"virt-launcher","level":"info","msg":"Found nameservers in /etc/resolv.conf: \ufffd\u001e\u0000\n","pos":"converter.go:1808","timestamp":"2020-12-03T15:58:35.355925Z"} {"component":"virt-launcher","level":"info","msg":"Found search domains in /etc/resolv.conf: virt-general-custom-hooks-test-vm-with-sidecar.svc.cluster.local svc.cluster.local cluster.local pytest-nightly.cnv-qe.rhcloud.com","pos":"converter.go:1809","timestamp":"2020-12-03T15:58:35.355984Z"} {"component":"virt-launcher","level":"info","msg":"Starting SingleClientDHCPServer","pos":"dhcp.go:63","timestamp":"2020-12-03T15:58:35.356132Z"} {"component":"virt-launcher","level":"info","msg":"Driver cache mode for /var/run/kubevirt-ephemeral-disks/disk-data/containerdisk/disk.qcow2 set to none","pos":"converter.go:252","timestamp":"2020-12-03T15:58:35.379920Z"} {"component":"virt-launcher","level":"error","msg":"Error when closing file","pos":"os_helper.go:34","reason":"invalid argument","timestamp":"2020-12-03T15:58:35.390268Z"} {"component":"virt-launcher","level":"info","msg":"Driver cache mode for /var/run/kubevirt-ephemeral-disks/cloud-init-data/virt-general-custom-hooks-test-vm-with-sidecar/vmi-with-sidecar-hook-1607011105-5713377/noCloud.iso set to none","pos":"converter.go:252","timestamp":"2020-12-03T15:58:35.390360Z"} {"component":"virt-launcher","kind":"","level":"info","msg":"Domain XML generated. Base64 dump PGRvbWFpbiB0eXBlPSJrdm0iPjxuYW1lPnZpcnQtZ2VuZXJhbC1jdXN0b20taG9va3MtdGVzdC12bS13aXRoLXNpZGVjYXJfdm1pLXdpdGgtc2lkZWNhci1ob29rLTE2MDcwMTExMDUtNTcxMzM3NzwvbmFtZT48bWVtb3J5IHVuaXQ9ImIiPjEwNzM3NDE4MjQ8L21lbW9yeT48b3M+PHR5cGUgYXJjaD0ieDg2XzY0IiBtYWNoaW5lPSJwYy1xMzUtcmhlbDguMi4wIj5odm08L3R5cGU+PHNtYmlvcyBtb2RlPSJzeXNpbmZvIj48L3NtYmlvcz48L29zPjxzeXNpbmZvIHR5cGU9InNtYmlvcyI+PHN5c3RlbT48ZW50cnkgbmFtZT0idXVpZCI+ZjAwMTQyMzYtNDAyNC01ZDMwLWIxZmEtOGUxODUzNzNjZWE2PC9lbnRyeT48ZW50cnkgbmFtZT0ibWFudWZhY3R1cmVyIj5SZWQgSGF0PC9lbnRyeT48ZW50cnkgbmFtZT0iZmFtaWx5Ij5SZWQgSGF0PC9lbnRyeT48ZW50cnkgbmFtZT0icHJvZHVjdCI+Q29udGFpbmVyLW5hdGl2ZSB2aXJ0dWFsaXphdGlvbjwvZW50cnk+PGVudHJ5IG5hbWU9InNrdSI+Mi42LjA8L2VudHJ5PjxlbnRyeSBuYW1lPSJ2ZXJzaW9uIj4yLjYuMDwvZW50cnk+PC9zeXN0ZW0+PGJpb3M+PC9iaW9zPjxiYXNlQm9hcmQ+PGVudHJ5IG5hbWU9Im1hbnVmYWN0dXJlciI+UmFkaWNhbCBFZHdhcmQ8L2VudHJ5PjwvYmFzZUJvYXJkPjwvc3lzaW5mbz48ZGV2aWNlcz48aW50ZXJmYWNlIHR5cGU9ImV0aGVybmV0Ij48c291cmNlPjwvc291cmNlPjx0YXJnZXQgZGV2PSJ0YXAwIj48L3RhcmdldD48bW9kZWwgdHlwZT0idmlydGlvIj48L21vZGVsPjxtYWMgYWRkcmVzcz0iMDI6ZDU6OTg6MDA6MDA6NWEiPjwvbWFjPjxhbGlhcyBuYW1lPSJ1YS1kZWZhdWx0Ij48L2FsaWFzPjwvaW50ZXJmYWNlPjxjaGFubmVsIHR5cGU9InVuaXgiPjx0YXJnZXQgbmFtZT0ib3JnLnFlbXUuZ3Vlc3RfYWdlbnQuMCIgdHlwZT0idmlydGlvIj48L3RhcmdldD48L2NoYW5uZWw+PGNvbnRyb2xsZXIgdHlwZT0idXNiIiBpbmRleD0iMCIgbW9kZWw9Im5vbmUiPjwvY29udHJvbGxlcj48Y29udHJvbGxlciB0eXBlPSJ2aXJ0aW8tc2VyaWFsIiBpbmRleD0iMCI+PC9jb250cm9sbGVyPjx2aWRlbz48bW9kZWwgdHlwZT0idmdhIiBoZWFkcz0iMSIgdnJhbT0iMTYzODQiPjwvbW9kZWw+PC92aWRlbz48Z3JhcGhpY3MgdHlwZT0idm5jIj48bGlzdGVuIHR5cGU9InNvY2tldCIgc29ja2V0PSIvdmFyL3J1bi9rdWJldmlydC1wcml2YXRlLzg4MDQ4N2JiLWY3YzEtNDEwMC1iMDE0LTgyMWM4OTgwMjM5ZS92aXJ0LXZuYyI+PC9saXN0ZW4+PC9ncmFwaGljcz48bWVtYmFsbG9vbiBtb2RlbD0idmlydGlvIj48L21lbWJhbGxvb24+PGRpc2sgZGV2aWNlPSJkaXNrIiB0eXBlPSJmaWxlIj48c291cmNlIGZpbGU9Ii92YXIvcnVuL2t1YmV2aXJ0LWVwaGVtZXJhbC1kaXNrcy9kaXNrLWRhdGEvY29udGFpbmVyZGlzay9kaXNrLnFjb3cyIj48L3NvdXJjZT48dGFyZ2V0IGJ1cz0idmlydGlvIiBkZXY9InZkYSI+PC90YXJnZXQ+PGRyaXZlciBjYWNoZT0ibm9uZSIgbmFtZT0icWVtdSIgdHlwZT0icWNvdzIiPjwvZHJpdmVyPjxhbGlhcyBuYW1lPSJ1YS1jb250YWluZXJkaXNrIj48L2FsaWFzPjxiYWNraW5nU3RvcmUgdHlwZT0iZmlsZSI+PGZvcm1hdCB0eXBlPSJxY293MiI+PC9mb3JtYXQ+PHNvdXJjZSBmaWxlPSIvdmFyL3J1bi9rdWJldmlydC9jb250YWluZXItZGlza3MvZGlza18wLmltZyI+PC9zb3VyY2U+PC9iYWNraW5nU3RvcmU+PC9kaXNrPjxkaXNrIGRldmljZT0iZGlzayIgdHlwZT0iZmlsZSI+PHNvdXJjZSBmaWxlPSIvdmFyL3J1bi9rdWJldmlydC1lcGhlbWVyYWwtZGlza3MvY2xvdWQtaW5pdC1kYXRhL3ZpcnQtZ2VuZXJhbC1jdXN0b20taG9va3MtdGVzdC12bS13aXRoLXNpZGVjYXIvdm1pLXdpdGgtc2lkZWNhci1ob29rLTE2MDcwMTExMDUtNTcxMzM3Ny9ub0Nsb3VkLmlzbyI+PC9zb3VyY2U+PHRhcmdldCBidXM9InZpcnRpbyIgZGV2PSJ2ZGIiPjwvdGFyZ2V0Pjxkcml2ZXIgY2FjaGU9Im5vbmUiIG5hbWU9InFlbXUiIHR5cGU9InJhdyI+PC9kcml2ZXI+PGFsaWFzIG5hbWU9InVhLWNsb3VkaW5pdGRpc2siPjwvYWxpYXM+PC9kaXNrPjxzZXJpYWwgdHlwZT0idW5peCI+PHRhcmdldCBwb3J0PSIwIj48L3RhcmdldD48c291cmNlIG1vZGU9ImJpbmQiIHBhdGg9Ii92YXIvcnVuL2t1YmV2aXJ0LXByaXZhdGUvODgwNDg3YmItZjdjMS00MTAwLWIwMTQtODIxYzg5ODAyMzllL3ZpcnQtc2VyaWFsMCI+PC9zb3VyY2U+PC9zZXJpYWw+PGNvbnNvbGUgdHlwZT0icHR5Ij48dGFyZ2V0IHR5cGU9InNlcmlhbCIgcG9ydD0iMCI+PC90YXJnZXQ+PC9jb25zb2xlPjxybmcgbW9kZWw9InZpcnRpbyI+PGJhY2tlbmQgbW9kZWw9InJhbmRvbSI+L2Rldi91cmFuZG9tPC9iYWNrZW5kPjwvcm5nPjwvZGV2aWNlcz48bWV0YWRhdGE+PGt1YmV2aXJ0IHhtbG5zPSJodHRwOi8va3ViZXZpcnQuaW8iPjx1aWQ+ODgwNDg3YmItZjdjMS00MTAwLWIwMTQtODIxYzg5ODAyMzllPC91aWQ+PGdyYWNlcGVyaW9kPjxkZWxldGlvbkdyYWNlUGVyaW9kU2Vjb25kcz4zMDwvZGVsZXRpb25HcmFjZVBlcmlvZFNlY29uZHM+PC9ncmFjZXBlcmlvZD48L2t1YmV2aXJ0PjwvbWV0YWRhdGE+PGZlYXR1cmVzPjxhY3BpPjwvYWNwaT48L2ZlYXR1cmVzPjxjcHUgbW9kZT0iaG9zdC1tb2RlbCI+PHRvcG9sb2d5IHNvY2tldHM9IjEiIGNvcmVzPSIxIiB0aHJlYWRzPSIxIj48L3RvcG9sb2d5PjwvY3B1Pjx2Y3B1IHBsYWNlbWVudD0ic3RhdGljIj4xPC92Y3B1Pjxpb3RocmVhZHM+MTwvaW90aHJlYWRzPjwvZG9tYWluPg==","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"libvirt_helper.go:99","timestamp":"2020-12-03T15:58:35.410904Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"} {"component":"virt-launcher","kind":"","level":"info","msg":"Domain defined.","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"manager.go:1327","timestamp":"2020-12-03T15:58:36.325265Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"} {"component":"virt-launcher","level":"info","msg":"DomainLifecycle event 0 with reason 0 received","pos":"client.go:358","timestamp":"2020-12-03T15:58:36.325561Z"} {"component":"virt-launcher","level":"info","msg":"kubevirt domain status: Shutoff(5):Unknown(0)","pos":"client.go:241","timestamp":"2020-12-03T15:58:36.354207Z"} {"component":"virt-launcher","level":"info","msg":"generated nocloud iso file /var/run/kubevirt-ephemeral-disks/cloud-init-data/virt-general-custom-hooks-test-vm-with-sidecar/vmi-with-sidecar-hook-1607011105-5713377/noCloud.iso","pos":"cloud-init.go:579","timestamp":"2020-12-03T15:58:36.355370Z"} {"component":"virt-launcher","level":"info","msg":"Successfully connected to domain notify socket at /var/run/kubevirt/domain-notify-pipe.sock","pos":"client.go:136","timestamp":"2020-12-03T15:58:36.373368Z"} {"component":"virt-launcher","level":"error","msg":"Cannot set interface MAC to fe:d5:98:00:00:5a on 'tap0': Operation not permitted","pos":"virNetDevSetMACInternal:275","subcomponent":"libvirt","thread":"33","timestamp":"2020-12-03T15:58:36.375000Z"} {"component":"virt-launcher","level":"info","msg":"Detected domain with UUID f0014236-4024-5d30-b1fa-8e185373cea6","pos":"virt-launcher.go:217","timestamp":"2020-12-03T15:58:36.380127Z"} {"component":"virt-launcher","level":"info","msg":"Monitoring loop: rate 1s start timeout 5m0s","pos":"monitor.go:164","timestamp":"2020-12-03T15:58:36.380256Z"} {"component":"virt-launcher","level":"info","msg":"Domain name event: virt-general-custom-hooks-test-vm-with-sidecar_vmi-with-sidecar-hook-1607011105-5713377","pos":"client.go:334","timestamp":"2020-12-03T15:58:36.381767Z"} {"component":"virt-launcher","kind":"","level":"error","msg":"Starting the VirtualMachineInstance failed.","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"manager.go:1359","reason":"virError(Code=38, Domain=0, Message='Cannot set interface MAC to fe:d5:98:00:00:5a on 'tap0': Operation not permitted')","timestamp":"2020-12-03T15:58:36.432794Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"} {"component":"virt-launcher","kind":"","level":"error","msg":"Failed to sync vmi","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"server.go:161","reason":"virError(Code=38, Domain=0, Message='Cannot set interface MAC to fe:d5:98:00:00:5a on 'tap0': Operation not permitted')","timestamp":"2020-12-03T15:58:36.432986Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"} {"component":"virt-launcher","kind":"","level":"info","msg":"Domain XML generated. Base64 dump PGRvbWFpbiB0eXBlPSJrdm0iPjxuYW1lPnZpcnQtZ2VuZXJhbC1jdXN0b20taG9va3MtdGVzdC12bS13aXRoLXNpZGVjYXJfdm1pLXdpdGgtc2lkZWNhci1ob29rLTE2MDcwMTExMDUtNTcxMzM3NzwvbmFtZT48bWVtb3J5IHVuaXQ9ImIiPjEwNzM3NDE4MjQ8L21lbW9yeT48b3M+PHR5cGUgYXJjaD0ieDg2XzY0IiBtYWNoaW5lPSJwYy1xMzUtcmhlbDguMi4wIj5odm08L3R5cGU+PHNtYmlvcyBtb2RlPSJzeXNpbmZvIj48L3NtYmlvcz48L29zPjxzeXNpbmZvIHR5cGU9InNtYmlvcyI+PHN5c3RlbT48ZW50cnkgbmFtZT0idXVpZCI+ZjAwMTQyMzYtNDAyNC01ZDMwLWIxZmEtOGUxODUzNzNjZWE2PC9lbnRyeT48ZW50cnkgbmFtZT0ibWFudWZhY3R1cmVyIj5SZWQgSGF0PC9lbnRyeT48ZW50cnkgbmFtZT0iZmFtaWx5Ij5SZWQgSGF0PC9lbnRyeT48ZW50cnkgbmFtZT0icHJvZHVjdCI+Q29udGFpbmVyLW5hdGl2ZSB2aXJ0dWFsaXphdGlvbjwvZW50cnk+PGVudHJ5IG5hbWU9InNrdSI+Mi42LjA8L2VudHJ5PjxlbnRyeSBuYW1lPSJ2ZXJzaW9uIj4yLjYuMDwvZW50cnk+PC9zeXN0ZW0+PGJpb3M+PC9iaW9zPjxiYXNlQm9hcmQ+PGVudHJ5IG5hbWU9Im1hbnVmYWN0dXJlciI+UmFkaWNhbCBFZHdhcmQ8L2VudHJ5PjwvYmFzZUJvYXJkPjwvc3lzaW5mbz48ZGV2aWNlcz48aW50ZXJmYWNlIHR5cGU9ImV0aGVybmV0Ij48c291cmNlPjwvc291cmNlPjxtb2RlbCB0eXBlPSJ2aXJ0aW8iPjwvbW9kZWw+PGFsaWFzIG5hbWU9InVhLWRlZmF1bHQiPjwvYWxpYXM+PC9pbnRlcmZhY2U+PGNoYW5uZWwgdHlwZT0idW5peCI+PHRhcmdldCBuYW1lPSJvcmcucWVtdS5ndWVzdF9hZ2VudC4wIiB0eXBlPSJ2aXJ0aW8iPjwvdGFyZ2V0PjwvY2hhbm5lbD48Y29udHJvbGxlciB0eXBlPSJ1c2IiIGluZGV4PSIwIiBtb2RlbD0ibm9uZSI+PC9jb250cm9sbGVyPjxjb250cm9sbGVyIHR5cGU9InZpcnRpby1zZXJpYWwiIGluZGV4PSIwIj48L2NvbnRyb2xsZXI+PHZpZGVvPjxtb2RlbCB0eXBlPSJ2Z2EiIGhlYWRzPSIxIiB2cmFtPSIxNjM4NCI+PC9tb2RlbD48L3ZpZGVvPjxncmFwaGljcyB0eXBlPSJ2bmMiPjxsaXN0ZW4gdHlwZT0ic29ja2V0IiBzb2NrZXQ9Ii92YXIvcnVuL2t1YmV2aXJ0LXByaXZhdGUvODgwNDg3YmItZjdjMS00MTAwLWIwMTQtODIxYzg5ODAyMzllL3ZpcnQtdm5jIj48L2xpc3Rlbj48L2dyYXBoaWNzPjxtZW1iYWxsb29uIG1vZGVsPSJ2aXJ0aW8iPjwvbWVtYmFsbG9vbj48ZGlzayBkZXZpY2U9ImRpc2siIHR5cGU9ImZpbGUiPjxzb3VyY2UgZmlsZT0iL3Zhci9ydW4va3ViZXZpcnQtZXBoZW1lcmFsLWRpc2tzL2Rpc2stZGF0YS9jb250YWluZXJkaXNrL2Rpc2sucWNvdzIiPjwvc291cmNlPjx0YXJnZXQgYnVzPSJ2aXJ0aW8iIGRldj0idmRhIj48L3RhcmdldD48ZHJpdmVyIG5hbWU9InFlbXUiIHR5cGU9InFjb3cyIj48L2RyaXZlcj48YWxpYXMgbmFtZT0idWEtY29udGFpbmVyZGlzayI+PC9hbGlhcz48YmFja2luZ1N0b3JlIHR5cGU9ImZpbGUiPjxmb3JtYXQgdHlwZT0icWNvdzIiPjwvZm9ybWF0Pjxzb3VyY2UgZmlsZT0iL3Zhci9ydW4va3ViZXZpcnQvY29udGFpbmVyLWRpc2tzL2Rpc2tfMC5pbWciPjwvc291cmNlPjwvYmFja2luZ1N0b3JlPjwvZGlzaz48ZGlzayBkZXZpY2U9ImRpc2siIHR5cGU9ImZpbGUiPjxzb3VyY2UgZmlsZT0iL3Zhci9ydW4va3ViZXZpcnQtZXBoZW1lcmFsLWRpc2tzL2Nsb3VkLWluaXQtZGF0YS92aXJ0LWdlbmVyYWwtY3VzdG9tLWhvb2tzLXRlc3Qtdm0td2l0aC1zaWRlY2FyL3ZtaS13aXRoLXNpZGVjYXItaG9vay0xNjA3MDExMTA1LTU3MTMzNzcvbm9DbG91ZC5pc28iPjwvc291cmNlPjx0YXJnZXQgYnVzPSJ2aXJ0aW8iIGRldj0idmRiIj48L3RhcmdldD48ZHJpdmVyIG5hbWU9InFlbXUiIHR5cGU9InJhdyI+PC9kcml2ZXI+PGFsaWFzIG5hbWU9InVhLWNsb3VkaW5pdGRpc2siPjwvYWxpYXM+PC9kaXNrPjxzZXJpYWwgdHlwZT0idW5peCI+PHRhcmdldCBwb3J0PSIwIj48L3RhcmdldD48c291cmNlIG1vZGU9ImJpbmQiIHBhdGg9Ii92YXIvcnVuL2t1YmV2aXJ0LXByaXZhdGUvODgwNDg3YmItZjdjMS00MTAwLWIwMTQtODIxYzg5ODAyMzllL3ZpcnQtc2VyaWFsMCI+PC9zb3VyY2U+PC9zZXJpYWw+PGNvbnNvbGUgdHlwZT0icHR5Ij48dGFyZ2V0IHR5cGU9InNlcmlhbCIgcG9ydD0iMCI+PC90YXJnZXQ+PC9jb25zb2xlPjxybmcgbW9kZWw9InZpcnRpbyI+PGJhY2tlbmQgbW9kZWw9InJhbmRvbSI+L2Rldi91cmFuZG9tPC9iYWNrZW5kPjwvcm5nPjwvZGV2aWNlcz48bWV0YWRhdGE+PGt1YmV2aXJ0IHhtbG5zPSJodHRwOi8va3ViZXZpcnQuaW8iPjx1aWQ+ODgwNDg3YmItZjdjMS00MTAwLWIwMTQtODIxYzg5ODAyMzllPC91aWQ+PGdyYWNlcGVyaW9kPjxkZWxldGlvbkdyYWNlUGVyaW9kU2Vjb25kcz4zMDwvZGVsZXRpb25HcmFjZVBlcmlvZFNlY29uZHM+PC9ncmFjZXBlcmlvZD48L2t1YmV2aXJ0PjwvbWV0YWRhdGE+PGZlYXR1cmVzPjxhY3BpPjwvYWNwaT48L2ZlYXR1cmVzPjxjcHUgbW9kZT0iaG9zdC1tb2RlbCI+PHRvcG9sb2d5IHNvY2tldHM9IjEiIGNvcmVzPSIxIiB0aHJlYWRzPSIxIj48L3RvcG9sb2d5PjwvY3B1Pjx2Y3B1IHBsYWNlbWVudD0ic3RhdGljIj4xPC92Y3B1Pjxpb3RocmVhZHM+MTwvaW90aHJlYWRzPjwvZG9tYWluPg==","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"libvirt_helper.go:99","timestamp":"2020-12-03T15:58:36.517041Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"} {"component":"virt-launcher","level":"info","msg":"DomainLifecycle event 0 with reason 1 received","pos":"client.go:358","timestamp":"2020-12-03T15:58:36.526231Z"} {"component":"virt-launcher","level":"info","msg":"kubevirt domain status: Shutoff(5):Failed(6)","pos":"client.go:241","timestamp":"2020-12-03T15:58:36.528908Z"} {"component":"virt-launcher","level":"info","msg":"Domain name event: virt-general-custom-hooks-test-vm-with-sidecar_vmi-with-sidecar-hook-1607011105-5713377","pos":"client.go:334","timestamp":"2020-12-03T15:58:36.530965Z"} {"component":"virt-launcher","level":"info","msg":"generated nocloud iso file /var/run/kubevirt-ephemeral-disks/cloud-init-data/virt-general-custom-hooks-test-vm-with-sidecar/vmi-with-sidecar-hook-1607011105-5713377/noCloud.iso","pos":"cloud-init.go:579","timestamp":"2020-12-03T15:58:36.540335Z"} {"component":"virt-launcher","level":"error","msg":"Unable to create tap device vnet0: Operation not permitted","pos":"virNetDevTapCreate:382","subcomponent":"libvirt","thread":"32","timestamp":"2020-12-03T15:58:36.559000Z"} {"component":"virt-launcher","kind":"","level":"error","msg":"Starting the VirtualMachineInstance failed.","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"manager.go:1359","reason":"virError(Code=38, Domain=0, Message='Unable to create tap device vnet0: Operation not permitted')","timestamp":"2020-12-03T15:58:36.561739Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"} {"component":"virt-launcher","kind":"","level":"error","msg":"Failed to sync vmi","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"server.go:161","reason":"virError(Code=38, Domain=0, Message='Unable to create tap device vnet0: Operation not permitted')","timestamp":"2020-12-03T15:58:36.561880Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"} {"component":"virt-launcher","kind":"","level":"info","msg":"Domain XML generated. Base64 dump PGRvbWFpbiB0eXBlPSJrdm0iPjxuYW1lPnZpcnQtZ2VuZXJhbC1jdXN0b20taG9va3MtdGVzdC12bS13aXRoLXNpZGVjYXJfdm1pLXdpdGgtc2lkZWNhci1ob29rLTE2MDcwMTExMDUtNTcxMzM3NzwvbmFtZT48bWVtb3J5IHVuaXQ9ImIiPjEwNzM3NDE4MjQ8L21lbW9yeT48b3M+PHR5cGUgYXJjaD0ieDg2XzY0IiBtYWNoaW5lPSJwYy1xMzUtcmhlbDguMi4wIj5odm08L3R5cGU+PHNtYmlvcyBtb2RlPSJzeXNpbmZvIj48L3NtYmlvcz48L29zPjxzeXNpbmZvIHR5cGU9InNtYmlvcyI+PHN5c3RlbT48ZW50cnkgbmFtZT0idXVpZCI+ZjAwMTQyMzYtNDAyNC01ZDMwLWIxZmEtOGUxODUzNzNjZWE2PC9lbnRyeT48ZW50cnkgbmFtZT0ibWFudWZhY3R1cmVyIj5SZWQgSGF0PC9lbnRyeT48ZW50cnkgbmFtZT0iZmFtaWx5Ij5SZWQgSGF0PC9lbnRyeT48ZW50cnkgbmFtZT0icHJvZHVjdCI+Q29udGFpbmVyLW5hdGl2ZSB2aXJ0dWFsaXphdGlvbjwvZW50cnk+PGVudHJ5IG5hbWU9InNrdSI+Mi42LjA8L2VudHJ5PjxlbnRyeSBuYW1lPSJ2ZXJzaW9uIj4yLjYuMDwvZW50cnk+PC9zeXN0ZW0+PGJpb3M+PC9iaW9zPjxiYXNlQm9hcmQ+PGVudHJ5IG5hbWU9Im1hbnVmYWN0dXJlciI+UmFkaWNhbCBFZHdhcmQ8L2VudHJ5PjwvYmFzZUJvYXJkPjwvc3lzaW5mbz48ZGV2aWNlcz48aW50ZXJmYWNlIHR5cGU9ImV0aGVybmV0Ij48c291cmNlPjwvc291cmNlPjxtb2RlbCB0eXBlPSJ2aXJ0aW8iPjwvbW9kZWw+PGFsaWFzIG5hbWU9InVhLWRlZmF1bHQiPjwvYWxpYXM+PC9pbnRlcmZhY2U+PGNoYW5uZWwgdHlwZT0idW5peCI+PHRhcmdldCBuYW1lPSJvcmcucWVtdS5ndWVzdF9hZ2VudC4wIiB0eXBlPSJ2aXJ0aW8iPjwvdGFyZ2V0PjwvY2hhbm5lbD48Y29udHJvbGxlciB0eXBlPSJ1c2IiIGluZGV4PSIwIiBtb2RlbD0ibm9uZSI+PC9jb250cm9sbGVyPjxjb250cm9sbGVyIHR5cGU9InZpcnRpby1zZXJpYWwiIGluZGV4PSIwIj48L2NvbnRyb2xsZXI+PHZpZGVvPjxtb2RlbCB0eXBlPSJ2Z2EiIGhlYWRzPSIxIiB2cmFtPSIxNjM4NCI+PC9tb2RlbD48L3ZpZGVvPjxncmFwaGljcyB0eXBlPSJ2bmMiPjxsaXN0ZW4gdHlwZT0ic29ja2V0IiBzb2NrZXQ9Ii92YXIvcnVuL2t1YmV2aXJ0LXByaXZhdGUvODgwNDg3YmItZjdjMS00MTAwLWIwMTQtODIxYzg5ODAyMzllL3ZpcnQtdm5jIj48L2xpc3Rlbj48L2dyYXBoaWNzPjxtZW1iYWxsb29uIG1vZGVsPSJ2aXJ0aW8iPjwvbWVtYmFsbG9vbj48ZGlzayBkZXZpY2U9ImRpc2siIHR5cGU9ImZpbGUiPjxzb3VyY2UgZmlsZT0iL3Zhci9ydW4va3ViZXZpcnQtZXBoZW1lcmFsLWRpc2tzL2Rpc2stZGF0YS9jb250YWluZXJkaXNrL2Rpc2sucWNvdzIiPjwvc291cmNlPjx0YXJnZXQgYnVzPSJ2aXJ0aW8iIGRldj0idmRhIj48L3RhcmdldD48ZHJpdmVyIG5hbWU9InFlbXUiIHR5cGU9InFjb3cyIj48L2RyaXZlcj48YWxpYXMgbmFtZT0idWEtY29udGFpbmVyZGlzayI+PC9hbGlhcz48YmFja2luZ1N0b3JlIHR5cGU9ImZpbGUiPjxmb3JtYXQgdHlwZT0icWNvdzIiPjwvZm9ybWF0Pjxzb3VyY2UgZmlsZT0iL3Zhci9ydW4va3ViZXZpcnQvY29udGFpbmVyLWRpc2tzL2Rpc2tfMC5pbWciPjwvc291cmNlPjwvYmFja2luZ1N0b3JlPjwvZGlzaz48ZGlzayBkZXZpY2U9ImRpc2siIHR5cGU9ImZpbGUiPjxzb3VyY2UgZmlsZT0iL3Zhci9ydW4va3ViZXZpcnQtZXBoZW1lcmFsLWRpc2tzL2Nsb3VkLWluaXQtZGF0YS92aXJ0LWdlbmVyYWwtY3VzdG9tLWhvb2tzLXRlc3Qtdm0td2l0aC1zaWRlY2FyL3ZtaS13aXRoLXNpZGVjYXItaG9vay0xNjA3MDExMTA1LTU3MTMzNzcvbm9DbG91ZC5pc28iPjwvc291cmNlPjx0YXJnZXQgYnVzPSJ2aXJ0aW8iIGRldj0idmRiIj48L3RhcmdldD48ZHJpdmVyIG5hbWU9InFlbXUiIHR5cGU9InJhdyI+PC9kcml2ZXI+PGFsaWFzIG5hbWU9InVhLWNsb3VkaW5pdGRpc2siPjwvYWxpYXM+PC9kaXNrPjxzZXJpYWwgdHlwZT0idW5peCI+PHRhcmdldCBwb3J0PSIwIj48L3RhcmdldD48c291cmNlIG1vZGU9ImJpbmQiIHBhdGg9Ii92YXIvcnVuL2t1YmV2aXJ0LXByaXZhdGUvODgwNDg3YmItZjdjMS00MTAwLWIwMTQtODIxYzg5ODAyMzllL3ZpcnQtc2VyaWFsMCI+PC9zb3VyY2U+PC9zZXJpYWw+PGNvbnNvbGUgdHlwZT0icHR5Ij48dGFyZ2V0IHR5cGU9InNlcmlhbCIgcG9ydD0iMCI+PC90YXJnZXQ+PC9jb25zb2xlPjxybmcgbW9kZWw9InZpcnRpbyI+PGJhY2tlbmQgbW9kZWw9InJhbmRvbSI+L2Rldi91cmFuZG9tPC9iYWNrZW5kPjwvcm5nPjwvZGV2aWNlcz48bWV0YWRhdGE+PGt1YmV2aXJ0IHhtbG5zPSJodHRwOi8va3ViZXZpcnQuaW8iPjx1aWQ+ODgwNDg3YmItZjdjMS00MTAwLWIwMTQtODIxYzg5ODAyMzllPC91aWQ+PGdyYWNlcGVyaW9kPjxkZWxldGlvbkdyYWNlUGVyaW9kU2Vjb25kcz4zMDwvZGVsZXRpb25HcmFjZVBlcmlvZFNlY29uZHM+PC9ncmFjZXBlcmlvZD48L2t1YmV2aXJ0PjwvbWV0YWRhdGE+PGZlYXR1cmVzPjxhY3BpPjwvYWNwaT48L2ZlYXR1cmVzPjxjcHUgbW9kZT0iaG9zdC1tb2RlbCI+PHRvcG9sb2d5IHNvY2tldHM9IjEiIGNvcmVzPSIxIiB0aHJlYWRzPSIxIj48L3RvcG9sb2d5PjwvY3B1Pjx2Y3B1IHBsYWNlbWVudD0ic3RhdGljIj4xPC92Y3B1Pjxpb3RocmVhZHM+MTwvaW90aHJlYWRzPjwvZG9tYWluPg==","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"libvirt_helper.go:99","timestamp":"2020-12-03T15:58:36.630496Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"} {"component":"virt-launcher","level":"info","msg":"DomainLifecycle event 0 with reason 1 received","pos":"client.go:358","timestamp":"2020-12-03T15:58:36.664262Z"} {"component":"virt-launcher","level":"info","msg":"generated nocloud iso file /var/run/kubevirt-ephemeral-disks/cloud-init-data/virt-general-custom-hooks-test-vm-with-sidecar/vmi-with-sidecar-hook-1607011105-5713377/noCloud.iso","pos":"cloud-init.go:579","timestamp":"2020-12-03T15:58:36.682188Z"} {"component":"virt-launcher","level":"error","msg":"Unable to create tap device vnet1: Operation not permitted","pos":"virNetDevTapCreate:382","subcomponent":"libvirt","thread":"35","timestamp":"2020-12-03T15:58:36.709000Z"} {"component":"virt-launcher","kind":"","level":"error","msg":"Starting the VirtualMachineInstance failed.","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"manager.go:1359","reason":"virError(Code=38, Domain=0, Message='Unable to create tap device vnet1: Operation not permitted')","timestamp":"2020-12-03T15:58:36.717403Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"} {"component":"virt-launcher","level":"info","msg":"kubevirt domain status: Shutoff(5):Failed(6)","pos":"client.go:241","timestamp":"2020-12-03T15:58:36.717550Z"} {"component":"virt-launcher","kind":"","level":"error","msg":"Failed to sync vmi","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"server.go:161","reason":"virError(Code=38, Domain=0, Message='Unable to create tap device vnet1: Operation not permitted')","timestamp":"2020-12-03T15:58:36.717606Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"} {"component":"virt-launcher","level":"info","msg":"Domain name event: virt-general-custom-hooks-test-vm-with-sidecar_vmi-with-sidecar-hook-1607011105-5713377","pos":"client.go:334","timestamp":"2020-12-03T15:58:36.721110Z"} {"component":"virt-launcher","level":"info","msg":"2020-12-03 15:58:36.380+0000: shutting down, reason=failed","subcomponent":"qemu","timestamp":"2020-12-03T15:58:36.769364Z"} {"component":"virt-launcher","level":"info","msg":"2020-12-03 15:58:36.559+0000: shutting down, reason=failed","subcomponent":"qemu","timestamp":"2020-12-03T15:58:36.769456Z"} {"component":"virt-launcher","level":"info","msg":"2020-12-03 15:58:36.709+0000: shutting down, reason=failed","subcomponent":"qemu","timestamp":"2020-12-03T15:58:36.769482Z"} {"component":"virt-launcher","kind":"","level":"info","msg":"Domain XML generated. Base64 dump PGRvbWFpbiB0eXBlPSJrdm0iPjxuYW1lPnZpcnQtZ2VuZXJhbC1jdXN0b20taG9va3MtdGVzdC12bS13aXRoLXNpZGVjYXJfdm1pLXdpdGgtc2lkZWNhci1ob29rLTE2MDcwMTExMDUtNTcxMzM3NzwvbmFtZT48bWVtb3J5IHVuaXQ9ImIiPjEwNzM3NDE4MjQ8L21lbW9yeT48b3M+PHR5cGUgYXJjaD0ieDg2XzY0IiBtYWNoaW5lPSJwYy1xMzUtcmhlbDguMi4wIj5odm08L3R5cGU+PHNtYmlvcyBtb2RlPSJzeXNpbmZvIj48L3NtYmlvcz48L29zPjxzeXNpbmZvIHR5cGU9InNtYmlvcyI+PHN5c3RlbT48ZW50cnkgbmFtZT0idXVpZCI+ZjAwMTQyMzYtNDAyNC01ZDMwLWIxZmEtOGUxODUzNzNjZWE2PC9lbnRyeT48ZW50cnkgbmFtZT0ibWFudWZhY3R1cmVyIj5SZWQgSGF0PC9lbnRyeT48ZW50cnkgbmFtZT0iZmFtaWx5Ij5SZWQgSGF0PC9lbnRyeT48ZW50cnkgbmFtZT0icHJvZHVjdCI+Q29udGFpbmVyLW5hdGl2ZSB2aXJ0dWFsaXphdGlvbjwvZW50cnk+PGVudHJ5IG5hbWU9InNrdSI+Mi42LjA8L2VudHJ5PjxlbnRyeSBuYW1lPSJ2ZXJzaW9uIj4yLjYuMDwvZW50cnk+PC9zeXN0ZW0+PGJpb3M+PC9iaW9zPjxiYXNlQm9hcmQ+PGVudHJ5IG5hbWU9Im1hbnVmYWN0dXJlciI+UmFkaWNhbCBFZHdhcmQ8L2VudHJ5PjwvYmFzZUJvYXJkPjwvc3lzaW5mbz48ZGV2aWNlcz48aW50ZXJmYWNlIHR5cGU9ImV0aGVybmV0Ij48c291cmNlPjwvc291cmNlPjxtb2RlbCB0eXBlPSJ2aXJ0aW8iPjwvbW9kZWw+PGFsaWFzIG5hbWU9InVhLWRlZmF1bHQiPjwvYWxpYXM+PC9pbnRlcmZhY2U+PGNoYW5uZWwgdHlwZT0idW5peCI+PHRhcmdldCBuYW1lPSJvcmcucWVtdS5ndWVzdF9hZ2VudC4wIiB0eXBlPSJ2aXJ0aW8iPjwvdGFyZ2V0PjwvY2hhbm5lbD48Y29udHJvbGxlciB0eXBlPSJ1c2IiIGluZGV4PSIwIiBtb2RlbD0ibm9uZSI+PC9jb250cm9sbGVyPjxjb250cm9sbGVyIHR5cGU9InZpcnRpby1zZXJpYWwiIGluZGV4PSIwIj48L2NvbnRyb2xsZXI+PHZpZGVvPjxtb2RlbCB0eXBlPSJ2Z2EiIGhlYWRzPSIxIiB2cmFtPSIxNjM4NCI+PC9tb2RlbD48L3ZpZGVvPjxncmFwaGljcyB0eXBlPSJ2bmMiPjxsaXN0ZW4gdHlwZT0ic29ja2V0IiBzb2NrZXQ9Ii92YXIvcnVuL2t1YmV2aXJ0LXByaXZhdGUvODgwNDg3YmItZjdjMS00MTAwLWIwMTQtODIxYzg5ODAyMzllL3ZpcnQtdm5jIj48L2xpc3Rlbj48L2dyYXBoaWNzPjxtZW1iYWxsb29uIG1vZGVsPSJ2aXJ0aW8iPjwvbWVtYmFsbG9vbj48ZGlzayBkZXZpY2U9ImRpc2siIHR5cGU9ImZpbGUiPjxzb3VyY2UgZmlsZT0iL3Zhci9ydW4va3ViZXZpcnQtZXBoZW1lcmFsLWRpc2tzL2Rpc2stZGF0YS9jb250YWluZXJkaXNrL2Rpc2sucWNvdzIiPjwvc291cmNlPjx0YXJnZXQgYnVzPSJ2aXJ0aW8iIGRldj0idmRhIj48L3RhcmdldD48ZHJpdmVyIG5hbWU9InFlbXUiIHR5cGU9InFjb3cyIj48L2RyaXZlcj48YWxpYXMgbmFtZT0idWEtY29udGFpbmVyZGlzayI+PC9hbGlhcz48YmFja2luZ1N0b3JlIHR5cGU9ImZpbGUiPjxmb3JtYXQgdHlwZT0icWNvdzIiPjwvZm9ybWF0Pjxzb3VyY2UgZmlsZT0iL3Zhci9ydW4va3ViZXZpcnQvY29udGFpbmVyLWRpc2tzL2Rpc2tfMC5pbWciPjwvc291cmNlPjwvYmFja2luZ1N0b3JlPjwvZGlzaz48ZGlzayBkZXZpY2U9ImRpc2siIHR5cGU9ImZpbGUiPjxzb3VyY2UgZmlsZT0iL3Zhci9ydW4va3ViZXZpcnQtZXBoZW1lcmFsLWRpc2tzL2Nsb3VkLWluaXQtZGF0YS92aXJ0LWdlbmVyYWwtY3VzdG9tLWhvb2tzLXRlc3Qtdm0td2l0aC1zaWRlY2FyL3ZtaS13aXRoLXNpZGVjYXItaG9vay0xNjA3MDExMTA1LTU3MTMzNzcvbm9DbG91ZC5pc28iPjwvc291cmNlPjx0YXJnZXQgYnVzPSJ2aXJ0aW8iIGRldj0idmRiIj48L3RhcmdldD48ZHJpdmVyIG5hbWU9InFlbXUiIHR5cGU9InJhdyI+PC9kcml2ZXI+PGFsaWFzIG5hbWU9InVhLWNsb3VkaW5pdGRpc2siPjwvYWxpYXM+PC9kaXNrPjxzZXJpYWwgdHlwZT0idW5peCI+PHRhcmdldCBwb3J0PSIwIj48L3RhcmdldD48c291cmNlIG1vZGU9ImJpbmQiIHBhdGg9Ii92YXIvcnVuL2t1YmV2aXJ0LXByaXZhdGUvODgwNDg3YmItZjdjMS00MTAwLWIwMTQtODIxYzg5ODAyMzllL3ZpcnQtc2VyaWFsMCI+PC9zb3VyY2U+PC9zZXJpYWw+PGNvbnNvbGUgdHlwZT0icHR5Ij48dGFyZ2V0IHR5cGU9InNlcmlhbCIgcG9ydD0iMCI+PC90YXJnZXQ+PC9jb25zb2xlPjxybmcgbW9kZWw9InZpcnRpbyI+PGJhY2tlbmQgbW9kZWw9InJhbmRvbSI+L2Rldi91cmFuZG9tPC9iYWNrZW5kPjwvcm5nPjwvZGV2aWNlcz48bWV0YWRhdGE+PGt1YmV2aXJ0IHhtbG5zPSJodHRwOi8va3ViZXZpcnQuaW8iPjx1aWQ+ODgwNDg3YmItZjdjMS00MTAwLWIwMTQtODIxYzg5ODAyMzllPC91aWQ+PGdyYWNlcGVyaW9kPjxkZWxldGlvbkdyYWNlUGVyaW9kU2Vjb25kcz4zMDwvZGVsZXRpb25HcmFjZVBlcmlvZFNlY29uZHM+PC9ncmFjZXBlcmlvZD48L2t1YmV2aXJ0PjwvbWV0YWRhdGE+PGZlYXR1cmVzPjxhY3BpPjwvYWNwaT48L2ZlYXR1cmVzPjxjcHUgbW9kZT0iaG9zdC1tb2RlbCI+PHRvcG9sb2d5IHNvY2tldHM9IjEiIGNvcmVzPSIxIiB0aHJlYWRzPSIxIj48L3RvcG9sb2d5PjwvY3B1Pjx2Y3B1IHBsYWNlbWVudD0ic3RhdGljIj4xPC92Y3B1Pjxpb3RocmVhZHM+MTwvaW90aHJlYWRzPjwvZG9tYWluPg==","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"libvirt_helper.go:99","timestamp":"2020-12-03T15:58:36.803924Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"} {"component":"virt-launcher","level":"info","msg":"DomainLifecycle event 0 with reason 1 received","pos":"client.go:358","timestamp":"2020-12-03T15:58:36.815349Z"} {"component":"virt-launcher","level":"info","msg":"kubevirt domain status: Shutoff(5):Failed(6)","pos":"client.go:241","timestamp":"2020-12-03T15:58:36.821116Z"} {"component":"virt-launcher","level":"info","msg":"Domain name event: virt-general-custom-hooks-test-vm-with-sidecar_vmi-with-sidecar-hook-1607011105-5713377","pos":"client.go:334","timestamp":"2020-12-03T15:58:36.826423Z"} {"component":"virt-launcher","level":"info","msg":"generated nocloud iso file /var/run/kubevirt-ephemeral-disks/cloud-init-data/virt-general-custom-hooks-test-vm-with-sidecar/vmi-with-sidecar-hook-1607011105-5713377/noCloud.iso","pos":"cloud-init.go:579","timestamp":"2020-12-03T15:58:36.827892Z"} {"component":"virt-launcher","level":"error","msg":"Unable to create tap device vnet2: Operation not permitted","pos":"virNetDevTapCreate:382","subcomponent":"libvirt","thread":"35","timestamp":"2020-12-03T15:58:36.848000Z"} {"component":"virt-launcher","kind":"","level":"error","msg":"Starting the VirtualMachineInstance failed.","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"manager.go:1359","reason":"virError(Code=38, Domain=0, Message='Unable to create tap device vnet2: Operation not permitted')","timestamp":"2020-12-03T15:58:36.851193Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"} {"component":"virt-launcher","kind":"","level":"error","msg":"Failed to sync vmi","name":"vmi-with-sidecar-hook-1607011105-5713377","namespace":"virt-general-custom-hooks-test-vm-with-sidecar","pos":"server.go:161","reason":"virError(Code=38, Domain=0, Message='Unable to create tap device vnet2: Operation not permitted')","timestamp":"2020-12-03T15:58:36.851313Z","uid":"880487bb-f7c1-4100-b014-821c8980239e"}
sidecar log: $ oc logs -n virt-general-custom-hooks-test-vm-with-sidecar virt-launcher-vmi-with-sidecar-hook-1607011105-5713377-x5dtv -c hook-sidecar-0 {"component":"smbios-hook-sidecar","level":"info","msg":"Starting hook server exposing 'info' and 'v1alpha1' services on socket /var/run/kubevirt-hooks/smbios.sock","pos":"smbios.go:131","timestamp":"2020-12-03T15:58:32.332135Z"} {"component":"smbios-hook-sidecar","level":"info","msg":"Hook's Info method has been called","pos":"smbios.go:44","timestamp":"2020-12-03T15:58:32.740912Z"} {"component":"smbios-hook-sidecar","level":"info","msg":"Hook's OnDefineDomain callback method has been called","pos":"smbios.go:63","timestamp":"2020-12-03T15:58:35.403369Z"} {"component":"smbios-hook-sidecar","level":"info","msg":"Successfully updated original domain spec with requested SMBIOS attributes","pos":"smbios.go:109","timestamp":"2020-12-03T15:58:35.405379Z"} {"component":"smbios-hook-sidecar","level":"info","msg":"Hook's OnDefineDomain callback method has been called","pos":"smbios.go:63","timestamp":"2020-12-03T15:58:36.515619Z"} {"component":"smbios-hook-sidecar","level":"info","msg":"Successfully updated original domain spec with requested SMBIOS attributes","pos":"smbios.go:109","timestamp":"2020-12-03T15:58:36.516675Z"} {"component":"smbios-hook-sidecar","level":"info","msg":"Hook's OnDefineDomain callback method has been called","pos":"smbios.go:63","timestamp":"2020-12-03T15:58:36.629267Z"} {"component":"smbios-hook-sidecar","level":"info","msg":"Successfully updated original domain spec with requested SMBIOS attributes","pos":"smbios.go:109","timestamp":"2020-12-03T15:58:36.630166Z"} {"component":"smbios-hook-sidecar","level":"info","msg":"Hook's OnDefineDomain callback method has been called","pos":"smbios.go:63","timestamp":"2020-12-03T15:58:36.802337Z"} {"component":"smbios-hook-sidecar","level":"info","msg":"Successfully updated original domain spec with requested SMBIOS attributes","pos":"smbios.go:109","timestamp":"2020-12-03T15:58:36.803544Z"}
The adjusted domxml returned from the hook has the MAC in it: <interface type="ethernet"> <source/> <target dev="tap0"/> <model type="virtio"/> <mac address="02:d5:98:00:00:5a"/> <alias name="ua-default"/> </interface>
We brought back the NET_ADMIN capability due to https://bugzilla.redhat.com/show_bug.cgi?id=1905929. With this capability back in virt-launcher, this issue will not reproduce. I'm putting this therefore on hold until the linked BZ gets resolved, we drop the capability and get a chance to reproduce it.
(In reply to Petr Horáček from comment #2) > The adjusted domxml returned from the hook has the MAC in it: > > <interface type="ethernet"> > <source/> > <target dev="tap0"/> <target dev="tap0"/> I think the issue here is that managed="no" is missing- <target dev='tap0' managed='no'/> > <model type="virtio"/> > <mac address="02:d5:98:00:00:5a"/> > <alias name="ua-default"/> > </interface>
Looking at the logs of this bug I see another strange thing. The first domxml sent to libvirt is - <interface type="ethernet"> <source></source> <target dev="tap0"></target> <model type="virtio"></model> <mac address="02:d5:98:00:00:5a"></mac> <alias name="ua-default"></alias> </interface> While all the other attempts send the following - <interface type="ethernet"> <source></source> <model type="virtio"></model> <alias name="ua-default"></alias> </interface> Therefore, we see in the events that first libvirt tries to set mac on the predefined tap and then on the following attempts it tries to create new tap devices- "LibvirtError(Code=38, Domain=0, Message='Cannot set interface MAC to fe:d5:98:00:00:5a on 'tap0': Operation not permitted')" Warning SyncFailed 11s virt-handler server error. command SyncVMI failed: "LibvirtError(Code=38, Domain=0, Message='Unable to create tap device vnet0: Operation not permitted')" Warning SyncFailed 11s virt-handler server error. command SyncVMI failed: "LibvirtError(Code=38, Domain=0, Message='Unable to create tap device vnet1: Operation not permitted')" Warning SyncFailed 11s virt-handler server error. command SyncVMI failed: "LibvirtError(Code=38, Domain=0, Message='Unable to create tap device vnet2: Operation not permitted')" ... I suspect that if the creation of the vm fails on the libvirt side. We are not invoking podInterface.PlugPhase2 (https://github.com/kubevirt/kubevirt/blob/161b36a91c329007147c11b6683e397dfa0b4551/pkg/virt-launcher/virtwrap/network/podinterface.go#L798).
(In reply to Alona Kaplan from comment #4) > (In reply to Petr Horáček from comment #2) > > The adjusted domxml returned from the hook has the MAC in it: > > > > <interface type="ethernet"> > > <source/> > > <target dev="tap0"/> > > <target dev="tap0"/> > > I think the issue here is that managed="no" is missing- > <target dev='tap0' managed='no'/> Good catch. Without that attribute, libvirt will attempt to re-configure the existing tap device - in this case the MAC. > > > <model type="virtio"/> > > <mac address="02:d5:98:00:00:5a"/> > > <alias name="ua-default"/> > > </interface>
(In reply to Miguel Duarte Barroso from comment #6) > (In reply to Alona Kaplan from comment #4) > > (In reply to Petr Horáček from comment #2) > > > The adjusted domxml returned from the hook has the MAC in it: > > > > > > <interface type="ethernet"> > > > <source/> > > > <target dev="tap0"/> > > > > <target dev="tap0"/> > > > > I think the issue here is that managed="no" is missing- > > <target dev='tap0' managed='no'/> > > Good catch. Without that attribute, libvirt will attempt to re-configure the Ruth, is there a chance the image of "example-hook-sidecar" you are using is very old? The "managed" attribute was added to the "InterfaceTarget" domain schema about half a year ago (when the pre defined tap device was introduced). I suspect that the "example-hook-sidecar" is old and doesn't have this attribute, therefore, when unmarshalling the domxml the "InterfaceTarget.managed" attribute is dropped. > existing tap device - in this case the MAC. > > > > > > <model type="virtio"/> > > > <mac address="02:d5:98:00:00:5a"/> > > > <alias name="ua-default"/> > > > </interface>
(In reply to Alona Kaplan from comment #7) > (In reply to Miguel Duarte Barroso from comment #6) > > (In reply to Alona Kaplan from comment #4) > > > (In reply to Petr Horáček from comment #2) > > > > The adjusted domxml returned from the hook has the MAC in it: > > > > > > > > <interface type="ethernet"> > > > > <source/> > > > > <target dev="tap0"/> > > > > > > <target dev="tap0"/> > > > > > > I think the issue here is that managed="no" is missing- > > > <target dev='tap0' managed='no'/> > > > > Good catch. Without that attribute, libvirt will attempt to re-configure the > > > Ruth, is there a chance the image of "example-hook-sidecar" you are using is > very old? > The "managed" attribute was added to the "InterfaceTarget" domain schema > about half a year ago (when the pre defined tap device was introduced). The pre-defined tap device was introduced in v0.33.0: [0]. From the annotation on the pod's specification in the bug description, I get the feeling the sidecar container uses version v0.13.3 : - "hooks.kubevirt.io/hookSidecars: [{"image": "kubevirt/example-hook-sidecar:v0.13.3"}]" > I suspect that the "example-hook-sidecar" is old and doesn't have this > attribute, therefore, when unmarshalling the domxml the > "InterfaceTarget.managed" attribute is dropped. > > > existing tap device - in this case the MAC. > > > > > > > > > <model type="virtio"/> > > > > <mac address="02:d5:98:00:00:5a"/> > > > > <alias name="ua-default"/> > > > > </interface> Right now, it is not possible to reproduce this issue, since CAP_NET_ADMIN was re-introduced, but I've tried to reproduce this some days go (on a build where CAP_NET_ADMIN was *NOT* present) and was not able to reproduce it. [0] - https://github.com/kubevirt/kubevirt/releases/tag/v0.33.0
(In reply to Miguel Duarte Barroso from comment #8) > (In reply to Alona Kaplan from comment #7) > > (In reply to Miguel Duarte Barroso from comment #6) > > > (In reply to Alona Kaplan from comment #4) > > > > (In reply to Petr Horáček from comment #2) > > > > > The adjusted domxml returned from the hook has the MAC in it: > > > > > > > > > > <interface type="ethernet"> > > > > > <source/> > > > > > <target dev="tap0"/> > > > > > > > > <target dev="tap0"/> > > > > > > > > I think the issue here is that managed="no" is missing- > > > > <target dev='tap0' managed='no'/> > > > > > > Good catch. Without that attribute, libvirt will attempt to re-configure the > > > > > > Ruth, is there a chance the image of "example-hook-sidecar" you are using is > > very old? > > The "managed" attribute was added to the "InterfaceTarget" domain schema > > about half a year ago (when the pre defined tap device was introduced). > > The pre-defined tap device was introduced in v0.33.0: [0]. > > From the annotation on the pod's specification in the bug description, I get > the feeling the sidecar container uses version v0.13.3 : > - "hooks.kubevirt.io/hookSidecars: [{"image": > "kubevirt/example-hook-sidecar:v0.13.3"}]" > > > I suspect that the "example-hook-sidecar" is old and doesn't have this > > attribute, therefore, when unmarshalling the domxml the > > "InterfaceTarget.managed" attribute is dropped. > > > > > existing tap device - in this case the MAC. > > > > > > > > > > > > <model type="virtio"/> > > > > > <mac address="02:d5:98:00:00:5a"/> > > > > > <alias name="ua-default"/> > > > > > </interface> > > Right now, it is not possible to reproduce this issue, since CAP_NET_ADMIN > was re-introduced, but I've tried to reproduce this some days go (on a build > where CAP_NET_ADMIN was *NOT* present) and was not able to reproduce it. A way to verify it with the CAP_NET_ADMIN is to check whether the managed="no" is passed on the domxml. The domxml is printed to the log "Domain XML generated. Base64 dump, so it should be easy to find it. > > [0] - https://github.com/kubevirt/kubevirt/releases/tag/v0.33.0
Verified manually that adding Phase2 call at domain re-creation works fine and VM is created. Hacked kubevirt with the solution https://github.com/kubevirt/kubevirt/pull/4995.
Ruth, now when we dropped CAP_NET_ADMIN, this should be an issue again. Could you please try reproducing this with virt-handler-container-v4.8.0-40? Please make sure that the sidecar hook container image you use is updated to, i.e. it should be using kubevirt/example-hook-sidecar:v0.39 or newer. The old version that was originally used is the culprit here.
Waiting for a fix for bug 1958937, to verify with the latest sidecar hook container image
Works with virt-handler v4.8.0-47 and latest sidecar image (kubevirt/example-hook-sidecar:latest). Closing.