After minor upgrade oVirt Node to 4.2.3 can't start Virtual machine

Dear all, after upgrade oVirt Node to latest 4.2.3 I can't start any virtual machine with network interface. VM machine without network interface starts normally. Exactly the same situation is on freshly installed oVirt node machine with different hardware. I use openvswitch on both machines. After some searching I found out that there are the same version of openvswitch(2.9.0-3) on old and new version of oVirt node but different versions of libvirt(3.9.0-14 vs 3.2.0-14) Error message of libvirtd when the VM machine fail to start: VM OPNsense is down with error. Exit message: Unable to add bridge ovirtmgmt port vnet0: Operation not supported. Any suggestions? Thank you. Stefan

On 06/07/2018 11:55 AM, stefan.palecek@x112.cz wrote:
Dear all,
after upgrade oVirt Node to latest 4.2.3 I can't start any virtual machine with network interface. VM machine without network interface starts normally. Exactly the same situation is on freshly installed oVirt node machine with different hardware. I use openvswitch on both machines. After some searching I found out that there are the same version of openvswitch(2.9.0-3) on old and new version of oVirt node but different versions of libvirt(3.9.0-14 vs 3.2.0-14)
Error message of libvirtd when the VM machine fail to start: VM OPNsense is down with error. Exit message: Unable to add bridge ovirtmgmt port vnet0: Operation not supported.
Hi, could you please share the Vdsm and Engine logs? Thanks, -- Francesco Romani Senior SW Eng., Virtualization R&D Red Hat IRC: fromani github: @fromanirh

VDSM Log: 2018-06-07 12:26:14,101+0200 INFO (jsonrpc/2) [vdsm.api] START repoStats(domains=()) from=::ffff:89.185.232.132,47858, task_id=4d0c05a3-d2b8-4c86-a6ea-bd2d8b71d121 (api:46) 2018-06-07 12:26:14,101+0200 INFO (jsonrpc/2) [vdsm.api] FINISH repoStats return={u'3771a70e-696a-4be6-a724-d0021b1db790': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000226268', 'lastCheck': '4.7', 'valid': True}, u'e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0002538', 'lastCheck': '6.0', 'valid': True}} from=::ffff:89.185.232.132,47858, task_id=4d0c05a3-d2b8-4c86-a6ea-bd2d8b71d121 (api:52) 2018-06-07 12:26:14,101+0200 INFO (jsonrpc/2) [vdsm.api] START multipath_health() from=::ffff:89.185.232.132,47858, task_id=144ed2aa-7c0f-44b3-9a36-bd77105d3db1 (api:46) 2018-06-07 12:26:14,101+0200 INFO (jsonrpc/2) [vdsm.api] FINISH multipath_health return={} from=::ffff:89.185.232.132,47858, task_id=144ed2aa-7c0f-44b3-9a36-bd77105d3db1 (api:52) 2018-06-07 12:26:14,104+0200 INFO (jsonrpc/2) [api.host] FINISH getStats return={'status': {'message': 'Done', 'code': 0}, 'info': {'cpuStatistics': {'11': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '99.93'}, '10': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '13': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '12': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '15': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '14': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '1': {'cpuUser': '0.20', 'nodeIndex': 0, 'cpuSys': '0.27', 'cpuIdle': '99.53'}, '0': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.93'}, '3': {'cpuUser': '0.20', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.73'}, '2': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.93'}, '5': {'cpuUser': '0.00', 'nodeIndex' : 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '4': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.20', 'cpuIdle': '99.80'}, '7': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '6': {'cpuUser': '0.07', 'nodeIndex': 0, 'cpuSys': '0.07', 'cpuIdle': '99.86'}, '9': {'cpuUser': '0.00', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '100.00'}, '8': {'cpuUser': '0.13', 'nodeIndex': 0, 'cpuSys': '0.00', 'cpuIdle': '99.87'}}, 'numaNodeMemFree': {'0': {'memPercent': 5, 'memFree': '30661'}}, 'memShared': 0, 'thpState': 'always', 'ksmMergeAcrossNodes': True, 'vmCount': 0, 'memUsed': '3', 'storageDomains': {u'3771a70e-696a-4be6-a724-d0021b1db790': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000226268', 'lastCheck': '4.7', 'valid': True}, u'e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.0002538', 'lastCheck': '6.0', 'valid': True}}, 'incomingVmMigrations': 0, 'network': {'vdsmbr_ mpEeUYOE': {'txErrors': '0', 'state': 'down', 'sampleTime': 1528367172.682192, 'name': 'vdsmbr_mpEeUYOE', 'tx': '0', 'txDropped': '0', 'rx': '0', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '59407'}, 'LAN': {'txErrors': '0', 'state': 'up', 'sampleTime': 1528367172.682192, 'name': 'LAN', 'tx': '132', 'txDropped': '0', 'rx': '47079042', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '2271'}, 'ovirtmgmt': {'txErrors': '0', 'state': 'up', 'sampleTime': 1528367172.682192, 'name': 'ovirtmgmt', 'tx': '130928501', 'txDropped': '0', 'rx': '62952977', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '337'}, 'lo': {'txErrors': '0', 'state': 'up', 'sampleTime': 1528367172.682192, 'name': 'lo', 'tx': '19431142', 'txDropped': '0', 'rx': '19431142', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'enp4s0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1528367172.682192, 'name': 'enp4s0', 'tx': '138261664', 'txDropped': '0', 'rx': '72198192', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0 '}, 'enp6s0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1528367172.682192, 'name': 'enp6s0', 'tx': '818', 'txDropped': '0', 'rx': '63234467', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'vdsmbr_8dDLSL11': {'txErrors': '0', 'state': 'down', 'sampleTime': 1528367172.682192, 'name': 'vdsmbr_8dDLSL11', 'tx': '0', 'txDropped': '0', 'rx': '0', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '397854'}, ';vdsmdummy;': {'txErrors': '0', 'state': 'down', 'sampleTime': 1528367172.682192, 'name': ';vdsmdummy;', 'tx': '0', 'txDropped': '0', 'rx': '0', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'enp5s0': {'txErrors': '0', 'state': 'up', 'sampleTime': 1528367172.682192, 'name': 'enp5s0', 'tx': '1236', 'txDropped': '0', 'rx': '59627472', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '0'}, 'ovs-system': {'txErrors': '0', 'state': 'down', 'sampleTime': 1528367172.682192, 'name': 'ovs-system', 'tx': '0', 'txDropped': '0', 'rx': '0', 'rxErrors': '0', 'speed': '1000', 'rxDropped' : '0'}, 'PUBLIC': {'txErrors': '0', 'state': 'up', 'sampleTime': 1528367172.682192, 'name': 'PUBLIC', 'tx': '90', 'txDropped': '0', 'rx': '47078966', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '2272'}, 'vdsmbr_qFXYpGX6': {'txErrors': '0', 'state': 'down', 'sampleTime': 1528367172.682192, 'name': 'vdsmbr_qFXYpGX6', 'tx': '0', 'txDropped': '0', 'rx': '0', 'rxErrors': '0', 'speed': '1000', 'rxDropped': '397855'}}, 'txDropped': '0', 'anonHugePages': '162', 'ksmPages': 100, 'elapsedTime': '176590.56', 'cpuLoad': '0.01', 'cpuSys': '0.04', 'diskStats': {'/var/log': {'free': '45487'}, '/var/run/vdsm/': {'free': '16003'}, '/tmp': {'free': '905'}}, 'cpuUserVdsmd': '0.20', 'netConfigDirty': 'False', 'memCommitted': 0, 'ksmState': False, 'vmMigrating': 0, 'ksmCpu': 0, 'memAvailable': 31085, 'bootTime': '1528189684', 'haStats': {'active': False, 'configured': False, 'score': 0, 'localMaintenance': False, 'globalMaintenance': False}, 'momStatus': 'active', 'multipathHealth': {}, 'rxDropped': '859996', 'outgoingVmMigrations': 0, 'swapTotal': 4095, 'swapFree': 4095, 'hugepages': defaultdict(<type 'dict'>, {1048576: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}, 2048: {'resv_hugepages': 0, 'free_hugepages': 0, 'nr_overcommit_hugepages': 0, 'surplus_hugepages': 0, 'vm.free_hugepages': 0, 'nr_hugepages': 0, 'nr_hugepages_mempolicy': 0}}), 'dateTime': '2018-06-07T10:26:14 GMT', 'cpuUser': '0.04', 'memFree': 31341, 'cpuIdle': '99.92', 'vmActive': 0, 'v2vJobs': {}, 'cpuSysVdsmd': '0.13'}} from=::ffff:89.185.232.132,47858 (api:52) 2018-06-07 12:26:14,106+0200 INFO (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call Host.getStats succeeded in 0.00 seconds (__init__:573) 2018-06-07 12:26:18,693+0200 INFO (jsonrpc/4) [vdsm.api] START getSpmStatus(spUUID=u'8a0b21c0-3fe4-407a-a972-2e4ccf1e01bb', options=None) from=::ffff:89.185.232.132,47858, task_id=c5f35f1d-26e1-4abb-99b9-da654c335df2 (api:46) 2018-06-07 12:26:18,693+0200 INFO (jsonrpc/4) [vdsm.api] FINISH getSpmStatus return={'spm_st': {'spmId': 1, 'spmStatus': 'SPM', 'spmLver': -1}} from=::ffff:89.185.232.132,47858, task_id=c5f35f1d-26e1-4abb-99b9-da654c335df2 (api:52) 2018-06-07 12:26:18,693+0200 INFO (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call StoragePool.getSpmStatus succeeded in 0.00 seconds (__init__:573) 2018-06-07 12:26:18,709+0200 INFO (jsonrpc/6) [vdsm.api] START getStoragePoolInfo(spUUID=u'8a0b21c0-3fe4-407a-a972-2e4ccf1e01bb', options=None) from=::ffff:89.185.232.132,47860, task_id=aa6d3db9-e6ee-4e00-a2c6-16467d616cdf (api:46) 2018-06-07 12:26:18,710+0200 INFO (jsonrpc/6) [vdsm.api] FINISH getStoragePoolInfo return={'info': {'name': 'No Description', 'isoprefix': u'/rhev/data-center/mnt/_srv_md2_ISO/3771a70e-696a-4be6-a724-d0021b1db790/images/11111111-1111-1111-1111-111111111111', 'pool_status': 'connected', 'lver': -1, 'domains': u'3771a70e-696a-4be6-a724-d0021b1db790:Active,e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1:Active', 'master_uuid': u'e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1', 'version': '4', 'spm_id': 1, 'type': 'LOCALFS', 'master_ver': 4}, 'dominfo': {u'3771a70e-696a-4be6-a724-d0021b1db790': {'status': u'Active', 'diskfree': '1645759115264', 'isoprefix': u'/rhev/data-center/mnt/_srv_md2_ISO/3771a70e-696a-4be6-a724-d0021b1db790/images/11111111-1111-1111-1111-111111111111', 'alerts': [], 'disktotal': '1880404238336', 'version': 0}, u'e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1': {'status': u'Active', 'diskfree': '1645759115264', 'isoprefix': '', 'alerts': [], 'disktotal': '1880404238336', 'version': 4}}} from=::f fff:89.185.232.132,47860, task_id=aa6d3db9-e6ee-4e00-a2c6-16467d616cdf (api:52) 2018-06-07 12:26:18,710+0200 INFO (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call StoragePool.getInfo succeeded in 0.00 seconds (__init__:573) 2018-06-07 12:26:22,883+0200 INFO (jsonrpc/5) [api.host] START getAllVmStats() from=::ffff:89.185.232.132,47858 (api:46) 2018-06-07 12:26:22,883+0200 INFO (jsonrpc/5) [api.host] FINISH getAllVmStats return={'status': {'message': 'Done', 'code': 0}, 'statsList': (suppressed)} from=::ffff:89.185.232.132,47858 (api:52) 2018-06-07 12:26:22,883+0200 INFO (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call Host.getAllVmStats succeeded in 0.00 seconds (__init__:573) 2018-06-07 12:26:26,770+0200 INFO (jsonrpc/1) [api.virt] START create(vmParams={u'xml': u'<?xml version="1.0" encoding="UTF-8"?><domain type="kvm" xmlns:ovirt-tune="http://ovirt.org/vm/tune/1.0" xmlns:ovirt-vm="http://ovirt.org/vm/1.0"><name>OPNsense</name><uuid>614c6984-5fdf-48cd-a36e-de1d6224f271</uuid><memory>8388608</memory><currentMemory>8388608</currentMemory><iothreads>1</iothreads><maxMemory slots="16">16777216</maxMemory><vcpu current="8">128</vcpu><sysinfo type="smbios"><system><entry name="manufacturer">oVirt</entry><entry name="product">OS-NAME:</entry><entry name="version">OS-VERSION:</entry><entry name="serial">HOST-SERIAL:</entry><entry name="uuid">614c6984-5fdf-48cd-a36e-de1d6224f271</entry></system></sysinfo><clock offset="variable" adjustment="0"><timer name="rtc" tickpolicy="catchup"></timer><timer name="pit" tickpolicy="delay"></timer><timer name="hpet" present="no"></timer></clock><features><acpi></acpi></features><cpu match="exact"><model>Opteron_G3</model><top ology cores="8" threads="1" sockets="16"></topology><numa><cell id="0" cpus="0,1,2,3,4,5,6,7" memory="8388608"></cell></numa></cpu><cputune></cputune><devices><input type="mouse" bus="ps2"></input><channel type="unix"><target type="virtio" name="ovirt-guest-agent.0"></target><source mode="bind" path="/var/lib/libvirt/qemu/channels/614c6984-5fdf-48cd-a36e-de1d6224f271.ovirt-guest-agent.0"></source></channel><channel type="unix"><target type="virtio" name="org.qemu.guest_agent.0"></target><source mode="bind" path="/var/lib/libvirt/qemu/channels/614c6984-5fdf-48cd-a36e-de1d6224f271.org.qemu.guest_agent.0"></source></channel><graphics type="spice" port="-1" autoport="yes" passwd="*****" passwdValidTo="1970-01-01T00:00:01" tlsPort="-1"><channel name="main" mode="secure"></channel><channel name="inputs" mode="secure"></channel><channel name="cursor" mode="secure"></channel><channel name="playback" mode="secure"></channel><channel name="record" mode="secure"></channel><channel name="displa y" mode="secure"></channel><channel name="smartcard" mode="secure"></channel><channel name="usbredir" mode="secure"></channel><listen type="network" network="vdsm-ovirtmgmt"></listen></graphics><video><model type="qxl" vram="8192" heads="1" ram="65536" vgamem="16384"></model><alias name="ua-7cf9477b-43f4-4b93-8fb9-a0a9d5bb920e"></alias></video><memballoon model="none"></memballoon><channel type="spicevmc"><target type="virtio" name="com.redhat.spice.0"></target></channel><interface type="bridge"><model type="virtio"></model><link state="up"></link><source bridge="ovirtmgmt"></source><alias name="ua-5b3d6e4e-b3e9-49ca-927b-7ba16a37b4d8"></alias><mac address="00:1a:4a:16:01:02"></mac><filterref filter="vdsm-no-mac-spoofing"></filterref><bandwidth></bandwidth></interface><interface type="bridge"><model type="virtio"></model><link state="up"></link><source bridge="LAN"></source><alias name="ua-dedaa712-37ee-4925-99e6-d4ac82458759"></alias><mac address="00:1a:4a:16:01:03"></mac><filterre f filter="vdsm-no-mac-spoofing"></filterref><bandwidth></bandwidth></interface><disk type="file" device="cdrom" snapshot="no"><driver name="qemu" type="raw" error_policy="report"></driver><source file="" startupPolicy="optional"></source><target dev="hdc" bus="ide"></target><readonly></readonly><alias name="ua-d8b91f6b-7db3-4304-b9b8-10f5512860b8"></alias></disk><disk snapshot="no" type="file" device="disk"><target dev="vda" bus="virtio"></target><source file="/rhev/data-center/8a0b21c0-3fe4-407a-a972-2e4ccf1e01bb/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1/images/9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5/8e4eecca-f140-4072-9539-ec16b9198543"></source><driver name="qemu" iothread="1" io="threads" type="raw" error_policy="stop" cache="none"></driver><alias name="ua-9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5"></alias><boot order="1"></boot><serial>9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5</serial></disk></devices><pm><suspend-to-disk enabled="no"></suspend-to-disk><suspend-to-mem enabled="no"></suspend-to-m em></pm><os><type arch="x86_64" machine="pc-i440fx-rhel7.3.0">hvm</type><smbios mode="sysinfo"></smbios></os><metadata><ovirt-tune:qos></ovirt-tune:qos><ovirt-vm:vm><minGuaranteedMemoryMb type="int">8192</minGuaranteedMemoryMb><clusterVersion>4.2</clusterVersion><ovirt-vm:custom></ovirt-vm:custom><ovirt-vm:device mac_address="00:1a:4a:16:01:02"><ovirt-vm:custom></ovirt-vm:custom></ovirt-vm:device><ovirt-vm:device mac_address="00:1a:4a:16:01:03"><ovirt-vm:custom></ovirt-vm:custom></ovirt-vm:device><ovirt-vm:device devtype="disk" name="vda"><ovirt-vm:poolID>8a0b21c0-3fe4-407a-a972-2e4ccf1e01bb</ovirt-vm:poolID><ovirt-vm:volumeID>8e4eecca-f140-4072-9539-ec16b9198543</ovirt-vm:volumeID><ovirt-vm:imageID>9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5</ovirt-vm:imageID><ovirt-vm:domainID>e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1</ovirt-vm:domainID></ovirt-vm:device><launchPaused>false</launchPaused><resumeBehavior>auto_resume</resumeBehavior></ovirt-vm:vm></metadata></domain>'}) from=::ffff:89.185.232.1 32,47858, flow_id=a06f2f4a-fcbe-472b-a282-d35e93585cc5, vmId= (api:46) 2018-06-07 12:26:26,780+0200 INFO (jsonrpc/1) [api.virt] FINISH create return={'status': {'message': 'Done', 'code': 0}, 'vmList': {'status': 'WaitForLaunch', 'maxMemSize': 16384, 'acpiEnable': 'true', 'emulatedMachine': 'pc-i440fx-rhel7.3.0', 'numOfIoThreads': '1', 'vmId': '614c6984-5fdf-48cd-a36e-de1d6224f271', 'memGuaranteedSize': 8192, 'timeOffset': '0', 'smpThreadsPerCore': '1', 'cpuType': 'Opteron_G3', 'guestDiskMapping': {}, 'arch': 'x86_64', 'smp': '8', 'guestNumaNodes': [{'nodeIndex': 0, 'cpus': '0,1,2,3,4,5,6,7', 'memory': '8192'}], u'xml': u'<?xml version="1.0" encoding="UTF-8"?><domain type="kvm" xmlns:ovirt-tune="http://ovirt.org/vm/tune/1.0" xmlns:ovirt-vm="http://ovirt.org/vm/1.0"><name>OPNsense</name><uuid>614c6984-5fdf-48cd-a36e-de1d6224f271</uuid><memory>8388608</memory><currentMemory>8388608</currentMemory><iothreads>1</iothreads><maxMemory slots="16">16777216</maxMemory><vcpu current="8">128</vcpu><sysinfo type="smbios"><system><entry name="manufacturer">oVirt</e ntry><entry name="product">OS-NAME:</entry><entry name="version">OS-VERSION:</entry><entry name="serial">HOST-SERIAL:</entry><entry name="uuid">614c6984-5fdf-48cd-a36e-de1d6224f271</entry></system></sysinfo><clock offset="variable" adjustment="0"><timer name="rtc" tickpolicy="catchup"></timer><timer name="pit" tickpolicy="delay"></timer><timer name="hpet" present="no"></timer></clock><features><acpi></acpi></features><cpu match="exact"><model>Opteron_G3</model><topology cores="8" threads="1" sockets="16"></topology><numa><cell id="0" cpus="0,1,2,3,4,5,6,7" memory="8388608"></cell></numa></cpu><cputune></cputune><devices><input type="mouse" bus="ps2"></input><channel type="unix"><target type="virtio" name="ovirt-guest-agent.0"></target><source mode="bind" path="/var/lib/libvirt/qemu/channels/614c6984-5fdf-48cd-a36e-de1d6224f271.ovirt-guest-agent.0"></source></channel><channel type="unix"><target type="virtio" name="org.qemu.guest_agent.0"></target><source mode="bind" path="/var/lib/l ibvirt/qemu/channels/614c6984-5fdf-48cd-a36e-de1d6224f271.org.qemu.guest_agent.0"></source></channel><graphics type="spice" port="-1" autoport="yes" passwd="*****" passwdValidTo="1970-01-01T00:00:01" tlsPort="-1"><channel name="main" mode="secure"></channel><channel name="inputs" mode="secure"></channel><channel name="cursor" mode="secure"></channel><channel name="playback" mode="secure"></channel><channel name="record" mode="secure"></channel><channel name="display" mode="secure"></channel><channel name="smartcard" mode="secure"></channel><channel name="usbredir" mode="secure"></channel><listen type="network" network="vdsm-ovirtmgmt"></listen></graphics><video><model type="qxl" vram="8192" heads="1" ram="65536" vgamem="16384"></model><alias name="ua-7cf9477b-43f4-4b93-8fb9-a0a9d5bb920e"></alias></video><memballoon model="none"></memballoon><channel type="spicevmc"><target type="virtio" name="com.redhat.spice.0"></target></channel><interface type="bridge"><model type="virtio"></mode l><link state="up"></link><source bridge="ovirtmgmt"></source><alias name="ua-5b3d6e4e-b3e9-49ca-927b-7ba16a37b4d8"></alias><mac address="00:1a:4a:16:01:02"></mac><filterref filter="vdsm-no-mac-spoofing"></filterref><bandwidth></bandwidth></interface><interface type="bridge"><model type="virtio"></model><link state="up"></link><source bridge="LAN"></source><alias name="ua-dedaa712-37ee-4925-99e6-d4ac82458759"></alias><mac address="00:1a:4a:16:01:03"></mac><filterref filter="vdsm-no-mac-spoofing"></filterref><bandwidth></bandwidth></interface><disk type="file" device="cdrom" snapshot="no"><driver name="qemu" type="raw" error_policy="report"></driver><source file="" startupPolicy="optional"></source><target dev="hdc" bus="ide"></target><readonly></readonly><alias name="ua-d8b91f6b-7db3-4304-b9b8-10f5512860b8"></alias></disk><disk snapshot="no" type="file" device="disk"><target dev="vda" bus="virtio"></target><source file="/rhev/data-center/8a0b21c0-3fe4-407a-a972-2e4ccf1e01bb/e27667f9 -cf5c-49d2-a4e6-7d4ea83b7fd1/images/9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5/8e4eecca-f140-4072-9539-ec16b9198543"></source><driver name="qemu" iothread="1" io="threads" type="raw" error_policy="stop" cache="none"></driver><alias name="ua-9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5"></alias><boot order="1"></boot><serial>9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5</serial></disk></devices><pm><suspend-to-disk enabled="no"></suspend-to-disk><suspend-to-mem enabled="no"></suspend-to-mem></pm><os><type arch="x86_64" machine="pc-i440fx-rhel7.3.0">hvm</type><smbios mode="sysinfo"></smbios></os><metadata><ovirt-tune:qos></ovirt-tune:qos><ovirt-vm:vm><minGuaranteedMemoryMb type="int">8192</minGuaranteedMemoryMb><clusterVersion>4.2</clusterVersion><ovirt-vm:custom></ovirt-vm:custom><ovirt-vm:device mac_address="00:1a:4a:16:01:02"><ovirt-vm:custom></ovirt-vm:custom></ovirt-vm:device><ovirt-vm:device mac_address="00:1a:4a:16:01:03"><ovirt-vm:custom></ovirt-vm:custom></ovirt-vm:device><ovirt-vm:device devtype=" disk" name="vda"><ovirt-vm:poolID>8a0b21c0-3fe4-407a-a972-2e4ccf1e01bb</ovirt-vm:poolID><ovirt-vm:volumeID>8e4eecca-f140-4072-9539-ec16b9198543</ovirt-vm:volumeID><ovirt-vm:imageID>9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5</ovirt-vm:imageID><ovirt-vm:domainID>e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1</ovirt-vm:domainID></ovirt-vm:device><launchPaused>false</launchPaused><resumeBehavior>auto_resume</resumeBehavior></ovirt-vm:vm></metadata></domain>', 'smpCoresPerSocket': '8', 'kvmEnable': 'true', 'bootMenuEnable': 'false', 'devices': [], 'custom': {}, 'maxVCpus': '128', 'clientIp': '', 'statusTime': '4472169670', 'vmName': 'OPNsense', 'maxMemSlots': 16}} from=::ffff:89.185.232.132,47858, flow_id=a06f2f4a-fcbe-472b-a282-d35e93585cc5, vmId= (api:52) 2018-06-07 12:26:26,780+0200 INFO (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call VM.create succeeded in 0.01 seconds (__init__:573) 2018-06-07 12:26:26,781+0200 INFO (vm/614c6984) [virt.vm] (vmId='614c6984-5fdf-48cd-a36e-de1d6224f271') VM wrapper has started (vm:2764) 2018-06-07 12:26:26,804+0200 INFO (vm/614c6984) [vdsm.api] START getVolumeSize(sdUUID='e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1', spUUID='8a0b21c0-3fe4-407a-a972-2e4ccf1e01bb', imgUUID='9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5', volUUID='8e4eecca-f140-4072-9539-ec16b9198543', options=None) from=internal, task_id=138c0753-1b18-4ddd-8051-c5f52c15617e (api:46) 2018-06-07 12:26:26,806+0200 INFO (vm/614c6984) [vdsm.api] FINISH getVolumeSize return={'truesize': '137439154176', 'apparentsize': '137438953472'} from=internal, task_id=138c0753-1b18-4ddd-8051-c5f52c15617e (api:52) 2018-06-07 12:26:26,806+0200 INFO (vm/614c6984) [vds] prepared volume path: (clientIF:497) 2018-06-07 12:26:26,806+0200 INFO (vm/614c6984) [vdsm.api] START prepareImage(sdUUID='e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1', spUUID='8a0b21c0-3fe4-407a-a972-2e4ccf1e01bb', imgUUID='9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5', leafUUID='8e4eecca-f140-4072-9539-ec16b9198543', allowIllegal=False) from=internal, task_id=9808893e-9a32-4292-8882-599001998207 (api:46) 2018-06-07 12:26:26,808+0200 INFO (vm/614c6984) [storage.StorageDomain] Fixing permissions on /rhev/data-center/mnt/_srv_md2_VMStore/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1/images/9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5/8e4eecca-f140-4072-9539-ec16b9198543 (fileSD:622) 2018-06-07 12:26:26,809+0200 INFO (vm/614c6984) [storage.StorageDomain] Creating domain run directory u'/var/run/vdsm/storage/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1' (fileSD:576) 2018-06-07 12:26:26,809+0200 INFO (vm/614c6984) [storage.fileUtils] Creating directory: /var/run/vdsm/storage/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1 mode: None (fileUtils:197) 2018-06-07 12:26:26,809+0200 INFO (vm/614c6984) [storage.StorageDomain] Creating symlink from /rhev/data-center/mnt/_srv_md2_VMStore/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1/images/9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5 to /var/run/vdsm/storage/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1/9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5 (fileSD:579) 2018-06-07 12:26:26,811+0200 INFO (vm/614c6984) [vdsm.api] FINISH prepareImage return={'info': {'path': u'/rhev/data-center/mnt/_srv_md2_VMStore/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1/images/9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5/8e4eecca-f140-4072-9539-ec16b9198543', 'type': 'file'}, 'path': u'/rhev/data-center/mnt/_srv_md2_VMStore/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1/images/9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5/8e4eecca-f140-4072-9539-ec16b9198543', 'imgVolumesInfo': [{'path': u'/rhev/data-center/mnt/_srv_md2_VMStore/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1/images/9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5/8e4eecca-f140-4072-9539-ec16b9198543', 'domainID': 'e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1', 'volumeID': u'8e4eecca-f140-4072-9539-ec16b9198543', 'imageID': '9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5'}]} from=internal, task_id=9808893e-9a32-4292-8882-599001998207 (api:52) 2018-06-07 12:26:26,811+0200 INFO (vm/614c6984) [vds] prepared volume path: /rhev/data-center/mnt/_srv_md2_VMStore/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1/images/9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5/8e4eecca-f140-4072-9539-ec16b9198543 (clientIF:497) 2018-06-07 12:26:26,811+0200 INFO (vm/614c6984) [virt.vm] (vmId='614c6984-5fdf-48cd-a36e-de1d6224f271') Enabling drive monitoring (drivemonitor:54) 2018-06-07 12:26:26,888+0200 INFO (vm/614c6984) [virt.vm] (vmId='614c6984-5fdf-48cd-a36e-de1d6224f271') drive 'hdc' path: 'file=' -> '*file=' (storagexml:323) 2018-06-07 12:26:26,888+0200 INFO (vm/614c6984) [virt.vm] (vmId='614c6984-5fdf-48cd-a36e-de1d6224f271') drive 'vda' path: 'file=/rhev/data-center/8a0b21c0-3fe4-407a-a972-2e4ccf1e01bb/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1/images/9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5/8e4eecca-f140-4072-9539-ec16b9198543' -> u'*file=/rhev/data-center/mnt/_srv_md2_VMStore/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1/images/9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5/8e4eecca-f140-4072-9539-ec16b9198543' (storagexml:323) 2018-06-07 12:26:27,056+0200 INFO (vm/614c6984) [root] /usr/libexec/vdsm/hooks/before_device_create/50_openstacknet: rc=0 err= (hooks:110) 2018-06-07 12:26:27,155+0200 INFO (vm/614c6984) [root] /usr/libexec/vdsm/hooks/before_device_create/50_vmfex: rc=0 err= (hooks:110) 2018-06-07 12:26:27,317+0200 INFO (vm/614c6984) [root] /usr/libexec/vdsm/hooks/before_device_create/openstacknet_utils.py: rc=0 err= (hooks:110) 2018-06-07 12:26:27,412+0200 INFO (vm/614c6984) [root] /usr/libexec/vdsm/hooks/before_device_create/ovirt_provider_ovn_hook: rc=0 err= (hooks:110) 2018-06-07 12:26:27,577+0200 INFO (vm/614c6984) [root] /usr/libexec/vdsm/hooks/before_device_create/50_openstacknet: rc=0 err= (hooks:110) 2018-06-07 12:26:27,676+0200 INFO (vm/614c6984) [root] /usr/libexec/vdsm/hooks/before_device_create/50_vmfex: rc=0 err= (hooks:110) 2018-06-07 12:26:27,710+0200 INFO (periodic/3) [vdsm.api] START repoStats(domains=()) from=internal, task_id=e0713d7b-0622-4d1c-8ac1-29716b60ce79 (api:46) 2018-06-07 12:26:27,710+0200 INFO (periodic/3) [vdsm.api] FINISH repoStats return={u'3771a70e-696a-4be6-a724-d0021b1db790': {'code': 0, 'actual': True, 'version': 0, 'acquired': True, 'delay': '0.000256275', 'lastCheck': '8.4', 'valid': True}, u'e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000225878', 'lastCheck': '2.6', 'valid': True}} from=internal, task_id=e0713d7b-0622-4d1c-8ac1-29716b60ce79 (api:52) 2018-06-07 12:26:27,710+0200 INFO (periodic/3) [vdsm.api] START multipath_health() from=internal, task_id=8f35aaea-cb43-42fc-ab76-7a0b4c6b56c1 (api:46) 2018-06-07 12:26:27,710+0200 INFO (periodic/3) [vdsm.api] FINISH multipath_health return={} from=internal, task_id=8f35aaea-cb43-42fc-ab76-7a0b4c6b56c1 (api:52) 2018-06-07 12:26:27,838+0200 INFO (vm/614c6984) [root] /usr/libexec/vdsm/hooks/before_device_create/openstacknet_utils.py: rc=0 err= (hooks:110) 2018-06-07 12:26:27,933+0200 INFO (vm/614c6984) [root] /usr/libexec/vdsm/hooks/before_device_create/ovirt_provider_ovn_hook: rc=0 err= (hooks:110) 2018-06-07 12:26:28,043+0200 INFO (vm/614c6984) [root] /usr/libexec/vdsm/hooks/before_vm_start/50_hostedengine: rc=0 err= (hooks:110) 2018-06-07 12:26:28,152+0200 INFO (vm/614c6984) [root] /usr/libexec/vdsm/hooks/before_vm_start/50_vfio_mdev: rc=0 err= (hooks:110) 2018-06-07 12:26:28,247+0200 INFO (vm/614c6984) [root] /usr/libexec/vdsm/hooks/before_vm_start/50_vhostmd: rc=0 err= (hooks:110) 2018-06-07 12:26:28,248+0200 INFO (vm/614c6984) [virt.vm] (vmId='614c6984-5fdf-48cd-a36e-de1d6224f271') <?xml version='1.0' encoding='utf-8'?> <domain xmlns:ns0="http://ovirt.org/vm/tune/1.0" xmlns:ovirt-vm="http://ovirt.org/vm/1.0" type="kvm"> <name>OPNsense</name> <uuid>614c6984-5fdf-48cd-a36e-de1d6224f271</uuid> <memory>8388608</memory> <currentMemory>8388608</currentMemory> <iothreads>1</iothreads> <maxMemory slots="16">16777216</maxMemory> <vcpu current="8">128</vcpu> <sysinfo type="smbios"> <system> <entry name="manufacturer">oVirt</entry> <entry name="product">oVirt Node</entry> <entry name="version">7-5.1804.el7.centos.2</entry> <entry name="serial">03D502E0-045E-052C-4806-1E0700080009</entry> <entry name="uuid">614c6984-5fdf-48cd-a36e-de1d6224f271</entry> </system> </sysinfo> <clock adjustment="0" offset="variable"> <timer name="rtc" tickpolicy="catchup" /> <timer name="pit" tickpolicy="delay" /> <timer name="hpet" present="no" /> </clock> <features> <acpi /> </features> <cpu match="exact"> <model>Opteron_G3</model> <topology cores="8" sockets="16" threads="1" /> <numa> <cell cpus="0,1,2,3,4,5,6,7" id="0" memory="8388608" /> </numa> </cpu> <cputune /> <devices> <input bus="ps2" type="mouse" /> <channel type="unix"> <target name="ovirt-guest-agent.0" type="virtio" /> <source mode="bind" path="/var/lib/libvirt/qemu/channels/614c6984-5fdf-48cd-a36e-de1d6224f271.ovirt-guest-agent.0" /> </channel> <channel type="unix"> <target name="org.qemu.guest_agent.0" type="virtio" /> <source mode="bind" path="/var/lib/libvirt/qemu/channels/614c6984-5fdf-48cd-a36e-de1d6224f271.org.qemu.guest_agent.0" /> </channel> <graphics autoport="yes" passwd="*****" passwdValidTo="1970-01-01T00:00:01" port="-1" tlsPort="-1" type="spice"> <channel mode="secure" name="main" /> <channel mode="secure" name="inputs" /> <channel mode="secure" name="cursor" /> <channel mode="secure" name="playback" /> <channel mode="secure" name="record" /> <channel mode="secure" name="display" /> <channel mode="secure" name="smartcard" /> <channel mode="secure" name="usbredir" /> <listen network="vdsm-ovirtmgmt" type="network" /> </graphics> <video> <model heads="1" ram="65536" type="qxl" vgamem="16384" vram="8192" /> <alias name="ua-7cf9477b-43f4-4b93-8fb9-a0a9d5bb920e" /> </video> <memballoon model="none" /> <channel type="spicevmc"> <target name="com.redhat.spice.0" type="virtio" /> </channel> <disk device="cdrom" snapshot="no" type="file"> <driver error_policy="report" name="qemu" type="raw" /> <source file="" startupPolicy="optional" /> <target bus="ide" dev="hdc" /> <readonly /> <alias name="ua-d8b91f6b-7db3-4304-b9b8-10f5512860b8" /> </disk> <disk device="disk" snapshot="no" type="file"> <target bus="virtio" dev="vda" /> <source file="/rhev/data-center/mnt/_srv_md2_VMStore/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1/images/9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5/8e4eecca-f140-4072-9539-ec16b9198543" /> <driver cache="none" error_policy="stop" io="threads" iothread="1" name="qemu" type="raw" /> <alias name="ua-9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5" /> <boot order="1" /> <serial>9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5</serial> </disk> <interface type="bridge"> <model type="virtio" /> <link state="up" /> <source bridge="ovirtmgmt" /> <alias name="ua-5b3d6e4e-b3e9-49ca-927b-7ba16a37b4d8" /> <mac address="00:1a:4a:16:01:02" /> <filterref filter="vdsm-no-mac-spoofing" /> <bandwidth /> </interface> <interface type="bridge"> <model type="virtio" /> <link state="up" /> <source bridge="LAN" /> <alias name="ua-dedaa712-37ee-4925-99e6-d4ac82458759" /> <mac address="00:1a:4a:16:01:03" /> <filterref filter="vdsm-no-mac-spoofing" /> <bandwidth /> </interface> </devices> <pm> <suspend-to-disk enabled="no" /> <suspend-to-mem enabled="no" /> </pm> <os> <type arch="x86_64" machine="pc-i440fx-rhel7.3.0">hvm</type> <smbios mode="sysinfo" /> </os> <metadata> <ns0:qos /> <ovirt-vm:vm> <minGuaranteedMemoryMb type="int">8192</minGuaranteedMemoryMb> <clusterVersion>4.2</clusterVersion> <ovirt-vm:custom /> <ovirt-vm:device mac_address="00:1a:4a:16:01:02"> <ovirt-vm:custom /> </ovirt-vm:device> <ovirt-vm:device mac_address="00:1a:4a:16:01:03"> <ovirt-vm:custom /> </ovirt-vm:device> <ovirt-vm:device devtype="disk" name="vda"> <ovirt-vm:poolID>8a0b21c0-3fe4-407a-a972-2e4ccf1e01bb</ovirt-vm:poolID> <ovirt-vm:volumeID>8e4eecca-f140-4072-9539-ec16b9198543</ovirt-vm:volumeID> <ovirt-vm:imageID>9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5</ovirt-vm:imageID> <ovirt-vm:domainID>e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1</ovirt-vm:domainID> </ovirt-vm:device> <launchPaused>false</launchPaused> <resumeBehavior>auto_resume</resumeBehavior> </ovirt-vm:vm> </metadata> </domain> (vm:2867) 2018-06-07 12:26:28,321+0200 ERROR (vm/614c6984) [virt.vm] (vmId='614c6984-5fdf-48cd-a36e-de1d6224f271') The vm start process failed (vm:943) Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 872, in _startUnderlyingVm self._run() File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 2872, in _run dom.createWithFlags(flags) File "/usr/lib/python2.7/site-packages/vdsm/common/libvirtconnection.py", line 130, in wrapper ret = f(*args, **kwargs) File "/usr/lib/python2.7/site-packages/vdsm/common/function.py", line 92, in wrapper return func(inst, *args, **kwargs) File "/usr/lib64/python2.7/site-packages/libvirt.py", line 1099, in createWithFlags if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self) libvirtError: Unable to add bridge ovirtmgmt port vnet0: Operation not supported 2018-06-07 12:26:28,322+0200 INFO (vm/614c6984) [virt.vm] (vmId='614c6984-5fdf-48cd-a36e-de1d6224f271') Changed state to Down: Unable to add bridge ovirtmgmt port vnet0: Operation not supported (code=1) (vm:1683) 2018-06-07 12:26:28,327+0200 INFO (vm/614c6984) [virt.vm] (vmId='614c6984-5fdf-48cd-a36e-de1d6224f271') Stopping connection (guestagent:438) 2018-06-07 12:26:28,343+0200 INFO (jsonrpc/7) [api.virt] START destroy(gracefulAttempts=1) from=::ffff:89.185.232.132,47858, vmId=614c6984-5fdf-48cd-a36e-de1d6224f271 (api:46) 2018-06-07 12:26:28,343+0200 INFO (jsonrpc/7) [virt.vm] (vmId='614c6984-5fdf-48cd-a36e-de1d6224f271') Release VM resources (vm:5184) 2018-06-07 12:26:28,343+0200 WARN (jsonrpc/7) [virt.vm] (vmId='614c6984-5fdf-48cd-a36e-de1d6224f271') trying to set state to Powering down when already Down (vm:605) 2018-06-07 12:26:28,343+0200 INFO (jsonrpc/7) [virt.vm] (vmId='614c6984-5fdf-48cd-a36e-de1d6224f271') Stopping connection (guestagent:438) 2018-06-07 12:26:28,344+0200 INFO (jsonrpc/7) [vdsm.api] START teardownImage(sdUUID='e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1', spUUID='8a0b21c0-3fe4-407a-a972-2e4ccf1e01bb', imgUUID='9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5', volUUID=None) from=::ffff:89.185.232.132,47858, task_id=3a18b19c-5a79-4533-ab94-99a5c3765e14 (api:46) 2018-06-07 12:26:28,344+0200 INFO (jsonrpc/7) [storage.StorageDomain] Removing image rundir link u'/var/run/vdsm/storage/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1/9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5' (fileSD:599) 2018-06-07 12:26:28,344+0200 INFO (jsonrpc/7) [vdsm.api] FINISH teardownImage return=None from=::ffff:89.185.232.132,47858, task_id=3a18b19c-5a79-4533-ab94-99a5c3765e14 (api:52) 2018-06-07 12:26:28,344+0200 INFO (jsonrpc/7) [virt.vm] (vmId='614c6984-5fdf-48cd-a36e-de1d6224f271') Stopping connection (guestagent:438) Engine Log 2018-06-07 12:26:26,612+02 INFO [org.ovirt.engine.core.bll.RunVmCommand] (default task-32) [a06f2f4a-fcbe-472b-a282-d35e93585cc5] Lock Acquired to object 'EngineLock:{exclusiveLocks='[614c6984-5fdf-48cd-a36e-de1d6224f271=VM]', sharedLocks=''}' 2018-06-07 12:26:26,625+02 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (default task-32) [a06f2f4a-fcbe-472b-a282-d35e93585cc5] START, IsVmDuringInitiatingVDSCommand( IsVmDuringInitiatingVDSCommandParameters:{vmId='614c6984-5fdf-48cd-a36e-de1d6224f271'}), log id: 649a863a 2018-06-07 12:26:26,625+02 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (default task-32) [a06f2f4a-fcbe-472b-a282-d35e93585cc5] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 649a863a 2018-06-07 12:26:26,688+02 INFO [org.ovirt.engine.core.bll.RunVmCommand] (EE-ManagedThreadFactory-engine-Thread-56509) [a06f2f4a-fcbe-472b-a282-d35e93585cc5] Running command: RunVmCommand internal: false. Entities affected : ID: 614c6984-5fdf-48cd-a36e-de1d6224f271 Type: VMAction group RUN_VM with role type USER 2018-06-07 12:26:26,719+02 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (EE-ManagedThreadFactory-engine-Thread-56509) [a06f2f4a-fcbe-472b-a282-d35e93585cc5] START, UpdateVmDynamicDataVDSCommand( UpdateVmDynamicDataVDSCommandParameters:{hostId='null', vmId='614c6984-5fdf-48cd-a36e-de1d6224f271', vmDynamic='org.ovirt.engine.core.common.businessentities.VmDynamic@2c7fbf50'}), log id: 23a50120 2018-06-07 12:26:26,729+02 INFO [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (EE-ManagedThreadFactory-engine-Thread-56509) [a06f2f4a-fcbe-472b-a282-d35e93585cc5] FINISH, UpdateVmDynamicDataVDSCommand, log id: 23a50120 2018-06-07 12:26:26,733+02 INFO [org.ovirt.engine.core.vdsbroker.CreateVDSCommand] (EE-ManagedThreadFactory-engine-Thread-56509) [a06f2f4a-fcbe-472b-a282-d35e93585cc5] START, CreateVDSCommand( CreateVDSCommandParameters:{hostId='d6fe9190-7c90-48de-a673-641bf9343b68', vmId='614c6984-5fdf-48cd-a36e-de1d6224f271', vm='VM [OPNsense]'}), log id: 1fdd70d2 2018-06-07 12:26:26,733+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (EE-ManagedThreadFactory-engine-Thread-56509) [a06f2f4a-fcbe-472b-a282-d35e93585cc5] START, CreateBrokerVDSCommand(HostName = bija02.adastsystems.cz, CreateVDSCommandParameters:{hostId='d6fe9190-7c90-48de-a673-641bf9343b68', vmId='614c6984-5fdf-48cd-a36e-de1d6224f271', vm='VM [OPNsense]'}), log id: 7e5021d6 2018-06-07 12:26:26,748+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (EE-ManagedThreadFactory-engine-Thread-56509) [a06f2f4a-fcbe-472b-a282-d35e93585cc5] VM <?xml version="1.0" encoding="UTF-8"?><domain type="kvm" xmlns:ovirt-tune="http://ovirt.org/vm/tune/1.0" xmlns:ovirt-vm="http://ovirt.org/vm/1.0"> <name>OPNsense</name> <uuid>614c6984-5fdf-48cd-a36e-de1d6224f271</uuid> <memory>8388608</memory> <currentMemory>8388608</currentMemory> <iothreads>1</iothreads> <maxMemory slots="16">16777216</maxMemory> <vcpu current="8">128</vcpu> <sysinfo type="smbios"> <system> <entry name="manufacturer">oVirt</entry> <entry name="product">OS-NAME:</entry> <entry name="version">OS-VERSION:</entry> <entry name="serial">HOST-SERIAL:</entry> <entry name="uuid">614c6984-5fdf-48cd-a36e-de1d6224f271</entry> </system> </sysinfo> <clock offset="variable" adjustment="0"> <timer name="rtc" tickpolicy="catchup"/> <timer name="pit" tickpolicy="delay"/> <timer name="hpet" present="no"/> </clock> <features> <acpi/> </features> <cpu match="exact"> <model>Opteron_G3</model> <topology cores="8" threads="1" sockets="16"/> <numa> <cell id="0" cpus="0,1,2,3,4,5,6,7" memory="8388608"/> </numa> </cpu> <cputune/> <devices> <input type="mouse" bus="ps2"/> <channel type="unix"> <target type="virtio" name="ovirt-guest-agent.0"/> <source mode="bind" path="/var/lib/libvirt/qemu/channels/614c6984-5fdf-48cd-a36e-de1d6224f271.ovirt-guest-agent.0"/> </channel> <channel type="unix"> <target type="virtio" name="org.qemu.guest_agent.0"/> <source mode="bind" path="/var/lib/libvirt/qemu/channels/614c6984-5fdf-48cd-a36e-de1d6224f271.org.qemu.guest_agent.0"/> </channel> <graphics type="spice" port="-1" autoport="yes" passwd="*****" passwdValidTo="1970-01-01T00:00:01" tlsPort="-1"> <channel name="main" mode="secure"/> <channel name="inputs" mode="secure"/> <channel name="cursor" mode="secure"/> <channel name="playback" mode="secure"/> <channel name="record" mode="secure"/> <channel name="display" mode="secure"/> <channel name="smartcard" mode="secure"/> <channel name="usbredir" mode="secure"/> <listen type="network" network="vdsm-ovirtmgmt"/> </graphics> <video> <model type="qxl" vram="8192" heads="1" ram="65536" vgamem="16384"/> <alias name="ua-7cf9477b-43f4-4b93-8fb9-a0a9d5bb920e"/> </video> <memballoon model="none"/> <channel type="spicevmc"> <target type="virtio" name="com.redhat.spice.0"/> </channel> <interface type="bridge"> <model type="virtio"/> <link state="up"/> <source bridge="ovirtmgmt"/> <alias name="ua-5b3d6e4e-b3e9-49ca-927b-7ba16a37b4d8"/> <mac address="00:1a:4a:16:01:02"/> <filterref filter="vdsm-no-mac-spoofing"/> <bandwidth/> </interface> <interface type="bridge"> <model type="virtio"/> <link state="up"/> <source bridge="LAN"/> <alias name="ua-dedaa712-37ee-4925-99e6-d4ac82458759"/> <mac address="00:1a:4a:16:01:03"/> <filterref filter="vdsm-no-mac-spoofing"/> <bandwidth/> </interface> <disk type="file" device="cdrom" snapshot="no"> <driver name="qemu" type="raw" error_policy="report"/> <source file="" startupPolicy="optional"/> <target dev="hdc" bus="ide"/> <readonly/> <alias name="ua-d8b91f6b-7db3-4304-b9b8-10f5512860b8"/> </disk> <disk snapshot="no" type="file" device="disk"> <target dev="vda" bus="virtio"/> <source file="/rhev/data-center/8a0b21c0-3fe4-407a-a972-2e4ccf1e01bb/e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1/images/9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5/8e4eecca-f140-4072-9539-ec16b9198543"/> <driver name="qemu" iothread="1" io="threads" type="raw" error_policy="stop" cache="none"/> <alias name="ua-9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5"/> <boot order="1"/> <serial>9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5</serial> </disk> </devices> <pm> <suspend-to-disk enabled="no"/> <suspend-to-mem enabled="no"/> </pm> <os> <type arch="x86_64" machine="pc-i440fx-rhel7.3.0">hvm</type> <smbios mode="sysinfo"/> </os> <metadata> <ovirt-tune:qos/> <ovirt-vm:vm> <minGuaranteedMemoryMb type="int">8192</minGuaranteedMemoryMb> <clusterVersion>4.2</clusterVersion> <ovirt-vm:custom/> <ovirt-vm:device mac_address="00:1a:4a:16:01:02"> <ovirt-vm:custom/> </ovirt-vm:device> <ovirt-vm:device mac_address="00:1a:4a:16:01:03"> <ovirt-vm:custom/> </ovirt-vm:device> <ovirt-vm:device devtype="disk" name="vda"> <ovirt-vm:poolID>8a0b21c0-3fe4-407a-a972-2e4ccf1e01bb</ovirt-vm:poolID> <ovirt-vm:volumeID>8e4eecca-f140-4072-9539-ec16b9198543</ovirt-vm:volumeID> <ovirt-vm:imageID>9c7168c6-fc3b-45c3-9a75-1f9c4c7129d5</ovirt-vm:imageID> <ovirt-vm:domainID>e27667f9-cf5c-49d2-a4e6-7d4ea83b7fd1</ovirt-vm:domainID> </ovirt-vm:device> <launchPaused>false</launchPaused> <resumeBehavior>auto_resume</resumeBehavior> </ovirt-vm:vm> </metadata> </domain> 2018-06-07 12:26:26,799+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateBrokerVDSCommand] (EE-ManagedThreadFactory-engine-Thread-56509) [a06f2f4a-fcbe-472b-a282-d35e93585cc5] FINISH, CreateBrokerVDSCommand, log id: 7e5021d6 2018-06-07 12:26:26,809+02 INFO [org.ovirt.engine.core.vdsbroker.CreateVDSCommand] (EE-ManagedThreadFactory-engine-Thread-56509) [a06f2f4a-fcbe-472b-a282-d35e93585cc5] FINISH, CreateVDSCommand, return: WaitForLaunch, log id: 1fdd70d2 2018-06-07 12:26:26,809+02 INFO [org.ovirt.engine.core.bll.RunVmCommand] (EE-ManagedThreadFactory-engine-Thread-56509) [a06f2f4a-fcbe-472b-a282-d35e93585cc5] Lock freed to object 'EngineLock:{exclusiveLocks='[614c6984-5fdf-48cd-a36e-de1d6224f271=VM]', sharedLocks=''}' 2018-06-07 12:26:26,821+02 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-56509) [a06f2f4a-fcbe-472b-a282-d35e93585cc5] EVENT_ID: USER_STARTED_VM(153), VM OPNsense was started by admin@internal-authz (Host: bija02.adastsystems.cz). 2018-06-07 12:26:28,335+02 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (ForkJoinPool-1-worker-2) [] VM '614c6984-5fdf-48cd-a36e-de1d6224f271' was reported as Down on VDS 'd6fe9190-7c90-48de-a673-641bf9343b68'(bija02.adastsystems.cz) 2018-06-07 12:26:28,336+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-2) [] START, DestroyVDSCommand(HostName = bija02.adastsystems.cz, DestroyVmVDSCommandParameters:{hostId='d6fe9190-7c90-48de-a673-641bf9343b68', vmId='614c6984-5fdf-48cd-a36e-de1d6224f271', secondsToWait='0', gracefully='false', reason='', ignoreNoVm='true'}), log id: 143e9a69 2018-06-07 12:26:28,900+02 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-2) [] FINISH, DestroyVDSCommand, log id: 143e9a69 2018-06-07 12:26:28,900+02 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (ForkJoinPool-1-worker-2) [] VM '614c6984-5fdf-48cd-a36e-de1d6224f271'(OPNsense) moved from 'WaitForLaunch' --> 'Down' 2018-06-07 12:26:28,968+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ForkJoinPool-1-worker-2) [] EVENT_ID: VM_DOWN_ERROR(119), VM OPNsense is down with error. Exit message: Unable to add bridge ovirtmgmt port vnet0: Operation not supported. 2018-06-07 12:26:28,969+02 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (ForkJoinPool-1-worker-2) [] add VM '614c6984-5fdf-48cd-a36e-de1d6224f271'(OPNsense) to rerun treatment 2018-06-07 12:26:28,993+02 ERROR [org.ovirt.engine.core.vdsbroker.monitoring.VmsMonitoring] (ForkJoinPool-1-worker-2) [] Rerun VM '614c6984-5fdf-48cd-a36e-de1d6224f271'. Called from VDS 'bija02.adastsystems.cz' 2018-06-07 12:26:29,018+02 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-56510) [] EVENT_ID: USER_INITIATED_RUN_VM_FAILED(151), Failed to run VM OPNsense on Host bija02.adastsystems.cz. 2018-06-07 12:26:29,037+02 INFO [org.ovirt.engine.core.bll.RunVmCommand] (EE-ManagedThreadFactory-engine-Thread-56510) [] Lock Acquired to object 'EngineLock:{exclusiveLocks='[614c6984-5fdf-48cd-a36e-de1d6224f271=VM]', sharedLocks=''}' 2018-06-07 12:26:29,062+02 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (EE-ManagedThreadFactory-engine-Thread-56510) [] START, IsVmDuringInitiatingVDSCommand( IsVmDuringInitiatingVDSCommandParameters:{vmId='614c6984-5fdf-48cd-a36e-de1d6224f271'}), log id: 5f03d52c 2018-06-07 12:26:29,062+02 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (EE-ManagedThreadFactory-engine-Thread-56510) [] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 5f03d52c 2018-06-07 12:26:29,071+02 WARN [org.ovirt.engine.core.bll.RunVmCommand] (EE-ManagedThreadFactory-engine-Thread-56510) [] Validation of action 'RunVm' failed for user admin@internal-authz. Reasons: VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,VAR__ACTION__RUN,VAR__TYPE__VM,SCHEDULING_NO_HOSTS 2018-06-07 12:26:29,072+02 INFO [org.ovirt.engine.core.bll.RunVmCommand] (EE-ManagedThreadFactory-engine-Thread-56510) [] Lock freed to object 'EngineLock:{exclusiveLocks='[614c6984-5fdf-48cd-a36e-de1d6224f271=VM]', sharedLocks=''}' 2018-06-07 12:26:29,147+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-56510) [] EVENT_ID: USER_FAILED_RUN_VM(54), Failed to run VM OPNsense (User: admin@internal-authz). 2018-06-07 12:26:29,186+02 INFO [org.ovirt.engine.core.bll.ProcessDownVmCommand] (EE-ManagedThreadFactory-engine-Thread-56511) [20bb07df] Running command: ProcessDownVmCommand internal: true.

Hi, I have a new info. Update to latest libvirtd(4.3) didn't help. štefan

Are you on OVS or legacy bridge networks for oVirt? If OVS, you need to move to OVN to continue to use OVS, else regress back to legacy.
participants (4)
-
Francesco Romani
-
stefan.palecek@x112.cz
-
tadavis@lbl.gov
-
Štefan Paleček