[ovirt-users] Re: After minor upgrade oVirt Node to 4.2.3 can't start Virtual machine

7 Jun 2018

      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.

[ovirt-users] Re: After minor upgrade oVirt Node to 4.2.3 can't start Virtual machine

stefan.palecek＠x112.cz