less engine.log | egrep '715d7551-4ad6-4377-8773-84da59373dfd|CF-CM-OPS-LONG-RUN-58017' --color

engine.log

2017-08-03 04:23:43,315 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (ajp-/127.0.0.1:8702-13) [468f0ec5] 
Lock Acquired to object EngineLock [exclusiveLocks= key: 715d7551-4ad6-4377-8773-84da59373dfd value: VM

2017-08-03 04:23:43,400 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp-/127.0.0.1:8702-13) 
[468f0ec5] START, IsVmDuringInitiatingVDSCommand( vmId = 715d7551-4ad6-4377-8773-84da59373dfd), log id: 416ba226

2017-08-03 04:23:43,502 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-7-thread-31) [468f0ec5] 
Running command: RunVmCommand internal: false. Entities affected :  ID: 715d7551-4ad6-4377-8773-84da59373dfd 
Type: VMAction group VM_BASIC_OPERATIONS with role type USER

2017-08-03 04:23:43,678 INFO  [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-7-thread-31) 
[468f0ec5] START, CreateVmVDSCommand(HostName = morstan, HostId = 42b8b533-f36b-47c6-b4c0-1aa7d5fcf888, 
vmId=715d7551-4ad6-4377-8773-84da59373dfd, vm=VM [CF-CM-OPS-LONG-RUN-58017]), log id: 2eec6677

2017-08-03 04:23:43,693 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-7-thread-31) 
[468f0ec5] START, CreateVDSCommand(HostName = morstan, HostId = 42b8b533-f36b-47c6-b4c0-1aa7d5fcf888, vmId=715d7551-4ad6-4377-8773-84da59373dfd, 
vm=VM [CF-CM-OPS-LONG-RUN-58017]), log id: 6fcc9584

2017-08-03 04:23:43,717 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-7-thread-31) 
[468f0ec5] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand kvmEnable=true,keyboardLayout=en-us,nice=0,
pitReinjection=false,displayNetwork=rhevm,copyPasteEnable=true,timeOffset=0,transparentHugePages=true,vmId=715d7551-4ad6-4377-8773-84da59373dfd,
acpiEnable=true,custom={device_947a0509-81b1-48d3-9658-68ed4d238aa3device_e332f309-bdb9-47f4-ba0c-5e51f978075ddevice_a6fe0375-4ff2-40eb-941f-6ef82e95f5e0device_f7232599-7142-4dc9-8fa2-03261389ede5=VmDevice 
{vmId=715d7551-4ad6-4377-8773-84da59373dfd, deviceId=f7232599-7142-4dc9-8fa2-03261389ede5, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=3}, 
managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null, logicalName=null}, device_947a0509-81b1-48d3-9658-68ed4d238aa3device_e332f309-bdb9-47f4-ba0c-5e51f978075ddevice_a6fe0375-4ff2-40eb-941f-6ef82e95f5e0=VmDevice 
{vmId=715d7551-4ad6-4377-8773-84da59373dfd, deviceId=a6fe0375-4ff2-40eb-941f-6ef82e95f5e0, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=2}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, 
customProperties={}, snapshotId=null, logicalName=null}, device_947a0509-81b1-48d3-9658-68ed4d238aa3device_e332f309-bdb9-47f4-ba0c-5e51f978075d=VmDevice {vmId=715d7551-4ad6-4377-8773-84da59373dfd, deviceId=e332f309-bdb9-47f4-ba0c-5e51f978075d, device=unix, type=CHANNEL, 
bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=1}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null, logicalName=null}, device_947a0509-81b1-48d3-9658-68ed4d238aa3=VmDevice 
{vmId=715d7551-4ad6-4377-8773-84da59373dfd, deviceId=947a0509-81b1-48d3-9658-68ed4d238aa3, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={slot=0x01, bus=0x00, domain=0x0000, type=pci, function=0x1}, managed=false, plugged=true, readOnly=false, 
deviceAlias=ide, customProperties={}, snapshotId=null, logicalName=null}},spiceSslCipherSuite=DEFAULT,memSize=20480,smp=8,emulatedMachine=rhel6.5.0,vmType=kvm,memGuaranteedSize=20480,display=qxl,smartcardEnable=false,bootMenuEnable=false,
spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,smpCoresPerSocket=4,maxVCpus=64,devices=[{address={bus=0x00, domain=0x0000, type=pci, slot=0x02, function=0x0}, specParams={ram=65536, vram=32768, heads=1}, 
device=qxl, type=video, deviceId=dd92cdc4-9202-4e73-a22f-578d0e3d8143}, {shared=false, iface=ide, index=2, address={unit=0, bus=1, target=0, controller=0, type=drive}, specParams={path=}, path=, device=cdrom, type=disk, readonly=true, deviceId=61d9fb50-0e75-4a01-b402-768b77217f1b}, 
{shared=false, index=0, volumeID=e014f02f-cf0c-4f88-a59e-fec7f50db23c, propagateErrors=off, format=cow, type=disk, iface=virtio, bootOrder=1, address={bus=0x00, domain=0x0000, type=pci, slot=0x05, function=0x0}, domainID=b1042c8c-7005-4301-a8c7-62f2a814b021, imageID=c5a7f69e-d861-4150-affb-afce27cc05fd, 
specParams={}, optional=false, device=disk, poolID=00000002-0002-0002-0002-00000000026e, readonly=false, deviceId=c5a7f69e-d861-4150-affb-afce27cc05fd}, {shared=false, volumeID=7c895296-1afe-424b-9d29-01d519fff06d, iface=virtio, imageID=33d5eed5-4212-4d37-a02d-2d6f0cbe2496, domainID=b1042c8c-7005-4301-a8c7-62f2a814b021, 
address={bus=0x00, domain=0x0000, type=pci, slot=0x06, function=0x0}, specParams={}, optional=false, propagateErrors=off, device=disk, poolID=00000002-0002-0002-0002-00000000026e, format=cow, type=disk, readonly=false, deviceId=33d5eed5-4212-4d37-a02d-2d6f0cbe2496}, {nicModel=pv, bootOrder=2, 
address={bus=0x00, domain=0x0000, type=pci, slot=0x03, function=0x0}, specParams={outbound={}, inbound={}}, macAddr=00:1a:4a:22:39:11, device=bridge, linkActive=true, type=interface, filter=vdsm-no-mac-spoofing, network=rhevm, deviceId=7c74769a-c74c-413a-92c0-c09b1a27e683}, {address={bus=0x00, domain=0x0000,
type=pci, slot=0x04, function=0x0}, specParams={}, device=virtio-serial, type=controller, deviceId=a8ae3bb2-a141-4fec-957b-b91c5a24f7b6}],vmName=CF-CM-OPS-LONG-RUN-58017,cpuType=SandyBridge,fileTransferEnable=true

2017-08-03 04:23:44,730 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-7-thread-31) [468f0ec5] Lock freed to object EngineLock [exclusiveLocks= key: 715d7551-4ad6-4377-8773-84da59373dfd value: VM

2017-08-03 04:23:44,732 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-7-thread-31) [468f0ec5] Correlation ID: 468f0ec5, Job ID: ab0899f5-3cab-4a18-8a29-c22d2404bf54, 
Call Stack: null, Custom Event ID: -1, Message: VM CF-CM-OPS-LONG-RUN-58017 was started by admin@internal (Host: morstan).

2017-08-03 04:23:45,289 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-99) [7c19c40] VM CF-CM-OPS-LONG-RUN-58017 715d7551-4ad6-4377-8773-84da59373dfd moved from WaitForLaunch --> PoweringUp

2017-08-03 04:23:49,797 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-26) [16adbf0] START, FullListVdsCommand(HostName = morstan, HostId = 42b8b533-f36b-47c6-b4c0-1aa7d5fcf888, vds=Host[morstan,42b8b533-f36b-47c6-b4c0-1aa7d5fcf888], vmIds=[715d7551-4ad6-4377-8773-84da59373dfd]), log id: 13b20a3c

2017-08-03 04:23:50,767 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-26) [16adbf0] FINISH, FullListVdsCommand, return: [{acpiEnable=true, emulatedMachine=rhel6.5.0, vmId=715d7551-4ad6-4377-8773-84da59373dfd, memGuaranteedSize=20480, transparentHugePages=true, displaySecurePort=5900, spiceSslCipherSuite=DEFAULT, cpuType=SandyBridge, smp=8, pauseCode=NOERR, smartcardEnable=false, custom={device_947a0509-81b1-48d3-9658-68ed4d238aa3device_e332f309-bdb9-47f4-ba0c-5e51f978075d=VmDevice {vmId=715d7551-4ad6-4377-8773-84da59373dfd, deviceId=e332f309-bdb9-47f4-ba0c-5e51f978075d, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=1}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null, logicalName=null}, device_947a0509-81b1-48d3-9658-68ed4d238aa3device_e332f309-bdb9-47f4-ba0c-5e51f978075ddevice_a6fe0375-4ff2-40eb-941f-6ef82e95f5e0device_f7232599-7142-4dc9-8fa2-03261389ede5=VmDevice {vmId=715d7551-4ad6-4377-8773-84da59373dfd, deviceId=f7232599-7142-4dc9-8fa2-03261389ede5, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=3}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null, logicalName=null}, device_947a0509-81b1-48d3-9658-68ed4d238aa3device_e332f309-bdb9-47f4-ba0c-5e51f978075ddevice_a6fe0375-4ff2-40eb-941f-6ef82e95f5e0=VmDevice {vmId=715d7551-4ad6-4377-8773-84da59373dfd, deviceId=a6fe0375-4ff2-40eb-941f-6ef82e95f5e0, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=2}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null, logicalName=null}, device_947a0509-81b1-48d3-9658-68ed4d238aa3=VmDevice {vmId=715d7551-4ad6-4377-8773-84da59373dfd, deviceId=947a0509-81b1-48d3-9658-68ed4d238aa3, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={slot=0x01, bus=0x00, domain=0x0000, type=pci, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide, customProperties={}, snapshotId=null, logicalName=null}}, vmType=kvm, memSize=20480, smpCoresPerSocket=4, vmName=CF-CM-OPS-LONG-RUN-58017, nice=0, status=Up, bootMenuEnable=false, pid=15705, copyPasteEnable=true, displayIp=10.12.20.255, displayPort=-1, guestDiskMapping={}, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, fileTransferEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, kvmEnable=true, pitReinjection=false, displayNetwork=rhevm, devices=[Ljava.lang.Object;@494635e9, timeOffset=0, maxVCpus=64, clientIp=, statusTime=8146645320, display=qxl}], log id: 13b20a3c

2017-08-03 04:23:50,768 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-26) [16adbf0] Received a memballoon Device without an address when processing VM 715d7551-4ad6-4377-8773-84da59373dfd devices, skipping device: {device=memballoon, specParams={model=none}, deviceType=balloon, type=balloon, alias=balloon0}

2017-08-03 04:23:50,768 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-26) [16adbf0] Received a spice Device without an address when processing VM 715d7551-4ad6-4377-8773-84da59373dfd devices, skipping device: {device=spice, specParams={fileTransferEnable=true, displayNetwork=rhevm, displayIp=10.12.20.255, keyMap=en-us, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, copyPasteEnable=true}, deviceType=graphics, type=graphics, tlsPort=5900}

2017-08-03 04:24:01,456 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-60) [5cfba53f] START, FullListVdsCommand(HostName = morstan, HostId = 42b8b533-f36b-47c6-b4c0-1aa7d5fcf888, vds=Host[morstan,42b8b533-f36b-47c6-b4c0-1aa7d5fcf888], vmIds=[715d7551-4ad6-4377-8773-84da59373dfd]), log id: 4d7d02ec

2017-08-03 04:24:01,492 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-60) [5cfba53f] FINISH, FullListVdsCommand, return: [{acpiEnable=true, emulatedMachine=rhel6.5.0, vmId=715d7551-4ad6-4377-8773-84da59373dfd, memGuaranteedSize=20480, transparentHugePages=true, displaySecurePort=5900, spiceSslCipherSuite=DEFAULT, cpuType=SandyBridge, smp=8, pauseCode=NOERR, smartcardEnable=false, custom={device_947a0509-81b1-48d3-9658-68ed4d238aa3device_e332f309-bdb9-47f4-ba0c-5e51f978075d=VmDevice {vmId=715d7551-4ad6-4377-8773-84da59373dfd, deviceId=e332f309-bdb9-47f4-ba0c-5e51f978075d, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=1}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}, snapshotId=null, logicalName=null}, device_947a0509-81b1-48d3-9658-68ed4d238aa3device_e332f309-bdb9-47f4-ba0c-5e51f978075ddevice_a6fe0375-4ff2-40eb-941f-6ef82e95f5e0device_f7232599-7142-4dc9-8fa2-03261389ede5=VmDevice {vmId=715d7551-4ad6-4377-8773-84da59373dfd, deviceId=f7232599-7142-4dc9-8fa2-03261389ede5, device=spicevmc, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=3}, managed=false, plugged=true, readOnly=false, deviceAlias=channel2, customProperties={}, snapshotId=null, logicalName=null}, device_947a0509-81b1-48d3-9658-68ed4d238aa3device_e332f309-bdb9-47f4-ba0c-5e51f978075ddevice_a6fe0375-4ff2-40eb-941f-6ef82e95f5e0=VmDevice {vmId=715d7551-4ad6-4377-8773-84da59373dfd, deviceId=a6fe0375-4ff2-40eb-941f-6ef82e95f5e0, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={bus=0, controller=0, type=virtio-serial, port=2}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}, snapshotId=null, logicalName=null}, device_947a0509-81b1-48d3-9658-68ed4d238aa3=VmDevice {vmId=715d7551-4ad6-4377-8773-84da59373dfd, deviceId=947a0509-81b1-48d3-9658-68ed4d238aa3, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={slot=0x01, bus=0x00, domain=0x0000, type=pci, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide, customProperties={}, snapshotId=null, logicalName=null}}, vmType=kvm, memSize=20480, smpCoresPerSocket=4, vmName=CF-CM-OPS-LONG-RUN-58017, nice=0, status=Up, bootMenuEnable=false, pid=15705, copyPasteEnable=true, displayIp=10.12.20.255, displayPort=-1, guestDiskMapping={c5a7f69e-d861-4150-a={name=/dev/vda}, QEMU_DVD-ROM_QM00003={name=/dev/sr0}, 33d5eed5-4212-4d37-a={name=/dev/vdb}}, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, fileTransferEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, kvmEnable=true, pitReinjection=false, displayNetwork=rhevm, devices=[Ljava.lang.Object;@45f5651b, timeOffset=0, maxVCpus=64, clientIp=, statusTime=8146656980, display=qxl}], log id: 4d7d02ec

2017-08-03 04:24:01,494 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-60) [5cfba53f] Received a memballoon Device without an address when processing VM 715d7551-4ad6-4377-8773-84da59373dfd devices, skipping device: {device=memballoon, specParams={model=none}, deviceType=balloon, type=balloon, alias=balloon0}

2017-08-03 04:24:01,494 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-60) [5cfba53f] Received a spice Device without an address when processing VM 715d7551-4ad6-4377-8773-84da59373dfd devices, skipping device: {device=spice, specParams={fileTransferEnable=true, displayNetwork=rhevm, displayIp=10.12.20.255, keyMap=en-us, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, copyPasteEnable=true}, deviceType=graphics, type=graphics, tlsPort=5900}

2017-08-03 04:24:04,623 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-34) [4141b385] VM CF-CM-OPS-LONG-RUN-58017 715d7551-4ad6-4377-8773-84da59373dfd moved from PoweringUp --> Up

2017-08-03 04:24:04,691 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-34) [4141b385] Correlation ID: 468f0ec5, Job ID: ab0899f5-3cab-4a18-8a29-c22d2404bf54, Call Stack: null, Custom Event ID: -1, Message: VM CF-CM-OPS-LONG-RUN-58017 started on Host morstan