Attachment 924862 Details for Bug 1126349 – engine log

engine log

engine.log (text/x-log), 10.18 KB, created by Lukas Svaty on 2014-08-07 10:20:10 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Lukas Svaty

Created: 2014-08-07 10:20:10 UTC

Size: 10.18 KB

patch

obsolete

>2014-08-07 12:13:38,620 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-2) [79654e39] Lock Acquired to object EngineLock [exclusiveLocks= key: 96990259-9061-4f77-9783-b004220b6dc2 value: VM
>, sharedLocks= ]
>2014-08-07 12:13:38,653 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-2) [79654e39] START, IsVmDuringInitiatingVDSCommand( vmId = 96990259-9061-4f77-9783-b004220b6dc2), log id: 7dee2cd9
>2014-08-07 12:13:38,654 INFO  [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-2) [79654e39] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 7dee2cd9
>2014-08-07 12:13:38,736 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-40) [79654e39] Running command: RunVmCommand internal: false. Entities affected :  ID: 96990259-9061-4f77-9783-b004220b6dc2 Type: VM
>2014-08-07 12:13:38,815 INFO  [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-40) [79654e39] START, UpdateVmDynamicDataVDSCommand(HostName = blue, HostId = 448a3383-4a01-4a20-af86-5ccc31dc7732, vmDynamic=org.ovirt.engine.core.common.businessentities.VmDynamic@c5d10996), log id: 645d0e9b
>2014-08-07 12:13:38,828 INFO  [org.ovirt.engine.core.vdsbroker.UpdateVmDynamicDataVDSCommand] (org.ovirt.thread.pool-8-thread-40) [79654e39] FINISH, UpdateVmDynamicDataVDSCommand, log id: 645d0e9b
>2014-08-07 12:13:38,847 INFO  [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-40) [79654e39] START, CreateVmVDSCommand(HostName = blue, HostId = 448a3383-4a01-4a20-af86-5ccc31dc7732, vmId=96990259-9061-4f77-9783-b004220b6dc2, vm=VM [test01]), log id: 7dd450ae
>2014-08-07 12:13:38,961 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVmFromCloudInitVDSCommand] (org.ovirt.thread.pool-8-thread-40) [79654e39] START, CreateVmFromCloudInitVDSCommand(HostName = blue, HostId = 448a3383-4a01-4a20-af86-5ccc31dc7732, vmId=96990259-9061-4f77-9783-b004220b6dc2, vm=VM [test01]), log id: 42d314e0
>2014-08-07 12:13:39,056 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (org.ovirt.thread.pool-8-thread-40) [79654e39] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVmFromCloudInitVDSCommand kvmEnable=true,keyboardLayout=en-us,nice=0,displayNetwork=ovirtmgmt,copyPasteEnable=true,timeOffset=0,transparentHugePages=true,vmId=96990259-9061-4f77-9783-b004220b6dc2,acpiEnable=true,custom={},spiceSslCipherSuite=DEFAULT,memSize=1024,smp=1,emulatedMachine=rhel6.4.0,vmType=kvm,memGuaranteedSize=1024,display=qxl,smartcardEnable=false,bootMenuEnable=false,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,smpCoresPerSocket=1,numaTune={mode=preferred},maxVCpus=160,devices=[{shared=false, iface=ide, index=3, specParams={vmPayload={file={openstack/latest/meta_data.json=ewogICJsYXVuY2hfaW5kZXgiIDogIjAiLAogICJhdmFpbGFiaWxpdHlfem9uZSIgOiAibm92YSIs
>CiAgIm5ldHdvcmstaW50ZXJmYWNlcyIgOiAiYXV0b1xuIiwKICAibmV0d29ya19jb25maWciIDog
>ewogICAgImNvbnRlbnRfcGF0aCIgOiAiL2NvbnRlbnQvMDAwMCIsCiAgICAicGF0aCIgOiAiL2V0
>Yy9uZXR3b3JrL2ludGVyZmFjZXMiCiAgfSwKICAidXVpZCIgOiAiNTU0YmYzNWMtODhkYS00M2Mz
>LTk4Y2EtMjUwMzQ0ZWI3NWZiIiwKICAibWV0YSIgOiB7CiAgICAiZXNzZW50aWFsIiA6ICJmYWxz
>ZSIsCiAgICAicm9sZSIgOiAic2VydmVyIiwKICAgICJkc21vZGUiIDogImxvY2FsIgogIH0KfQ==
>, openstack/latest/user_data=I2Nsb3VkLWNvbmZpZwpzc2hfcHdhdXRoOiB0cnVlCmRpc2FibGVfcm9vdDogMApvdXRwdXQ6CiAg
>YWxsOiAnPj4gL3Zhci9sb2cvY2xvdWQtaW5pdC1vdXRwdXQubG9nJwpjaHBhc3N3ZDoKICBleHBp
>cmU6IGZhbHNlCnJ1bmNtZDoKLSAnc2VkIC1pICcnL15kYXRhc291cmNlX2xpc3Q6IC9kJycgL2V0
>Yy9jbG91ZC9jbG91ZC5jZmc7IGVjaG8gJydkYXRhc291cmNlX2xpc3Q6CiAgWyJOb0Nsb3VkIiwg
>IkNvbmZpZ0RyaXZlIl0nJyA+PiAvZXRjL2Nsb3VkL2Nsb3VkLmNmZycK
>, openstack/content/0000=YXV0bwo=
>}, volId=config-2}}, path=, device=cdrom, type=disk, readonly=true, deviceId=1680c7f1-a63a-4247-a1cd-fed0a531a37a}, {specParams={vram=32768, heads=1}, device=qxl, type=video, deviceId=bd37a789-ea6c-4dc8-818c-5c92901a2c82}, {shared=false, iface=ide, index=2, specParams={path=}, path=, device=cdrom, type=disk, readonly=true, deviceId=ed82340e-e0cd-460b-a9de-1f686bd96102}, {shared=false, volumeID=82fb74f2-d8b3-45aa-8bfd-712828ddd064, index=0, iface=virtio, imageID=3b0383dd-1f26-40e0-875f-d96044f2b58d, domainID=ec7410f6-6cf2-42e1-bc69-6df4053e57c6, specParams={}, optional=false, propagateErrors=off, device=disk, poolID=00000002-0002-0002-0002-0000000003a6, format=raw, type=disk, readonly=false, deviceId=3b0383dd-1f26-40e0-875f-d96044f2b58d}, {nicModel=pv, specParams={outbound={}, inbound={}}, macAddr=00:1a:4a:4f:3f:08, device=bridge, linkActive=true, type=interface, filter=vdsm-no-mac-spoofing, network=ovirtmgmt, deviceId=0615a54f-f099-4d7b-81f5-7d121a021e87}, {index=0, model=virtio-scsi, specParams={}, device=scsi, type=controller, deviceId=22e387ce-4dbb-48ea-a230-603a02204e22}],vmName=test01,cpuType=SandyBridge,fileTransferEnable=true
>2014-08-07 12:13:39,104 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVmFromCloudInitVDSCommand] (org.ovirt.thread.pool-8-thread-40) [79654e39] FINISH, CreateVmFromCloudInitVDSCommand, log id: 42d314e0
>2014-08-07 12:13:39,118 INFO  [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (org.ovirt.thread.pool-8-thread-40) [79654e39] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 7dd450ae
>2014-08-07 12:13:39,119 INFO  [org.ovirt.engine.core.bll.RunVmCommand] (org.ovirt.thread.pool-8-thread-40) [79654e39] Lock freed to object EngineLock [exclusiveLocks= key: 96990259-9061-4f77-9783-b004220b6dc2 value: VM
>, sharedLocks= ]
>2014-08-07 12:13:39,132 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-8-thread-40) [79654e39] Correlation ID: 79654e39, Job ID: 6840648e-8bb1-4429-8ea3-6ac2c296acee, Call Stack: null, Custom Event ID: -1, Message: VM test01 was started by admin (Host: blue).
>2014-08-07 12:13:42,200 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-91) VM test01 96990259-9061-4f77-9783-b004220b6dc2 moved from WaitForLaunch --> PoweringUp
>2014-08-07 12:13:42,203 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-91) START, FullListVdsCommand(HostName = blue, HostId = 448a3383-4a01-4a20-af86-5ccc31dc7732, vds=Host[blue,448a3383-4a01-4a20-af86-5ccc31dc7732], vmIds=[96990259-9061-4f77-9783-b004220b6dc2]), log id: 217e9b53
>2014-08-07 12:13:42,219 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVdsCommand] (DefaultQuartzScheduler_Worker-91) FINISH, FullListVdsCommand, return: [{displaySecurePort=5901, kvmEnable=true, nicModel=rtl8139,pv, keyboardLayout=en-us, displayIp=10.34.62.204, pauseCode=NOERR, nice=0, displayNetwork=ovirtmgmt, copyPasteEnable=true, timeOffset=0, transparentHugePages=true, vmId=96990259-9061-4f77-9783-b004220b6dc2, acpiEnable=true, custom={}, spiceSslCipherSuite=DEFAULT, memSize=1024, smp=1, displayPort=5900, emulatedMachine=rhel6.4.0, vmType=kvm, status=Up, memGuaranteedSize=1024, display=qxl, pid=2259, smartcardEnable=false, bootMenuEnable=false, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, numaTune={mode=preferred}, smpCoresPerSocket=1, maxVCpus=160, clientIp=, devices=[Ljava.lang.Object;@7f077752, vmName=test01, fileTransferEnable=true, cpuType=SandyBridge}], log id: 217e9b53
>2014-08-07 12:13:42,229 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-91) Received a memballoon Device without an address when processing VM 96990259-9061-4f77-9783-b004220b6dc2 devices, skipping device: {alias=balloon0, specParams={model=none}, device=memballoon, type=balloon}
>2014-08-07 12:13:42,232 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-91) Received a spice Device without an address when processing VM 96990259-9061-4f77-9783-b004220b6dc2 devices, skipping device: {port=5900, specParams={spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard, keyMap=en-us, displayNetwork=ovirtmgmt, copyPasteEnable=true, displayIp=10.34.62.204}, device=spice, tlsPort=5901, type=graphics}
>2014-08-07 12:13:44,833 INFO  [org.ovirt.engine.core.bll.SetVmTicketCommand] (ajp--127.0.0.1-8702-4) [415ebf1e] Running command: SetVmTicketCommand internal: false. Entities affected :  ID: 96990259-9061-4f77-9783-b004220b6dc2 Type: VM
>2014-08-07 12:13:44,848 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (ajp--127.0.0.1-8702-4) [415ebf1e] START, SetVmTicketVDSCommand(HostName = blue, HostId = 448a3383-4a01-4a20-af86-5ccc31dc7732, vmId=96990259-9061-4f77-9783-b004220b6dc2, ticket=FRMzv14GgZsi, validTime=120,m userName=admin, userId=fdfc627c-d875-11e0-90f0-83df133b58cc), log id: 4665d1dc
>2014-08-07 12:13:44,917 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.SetVmTicketVDSCommand] (ajp--127.0.0.1-8702-4) [415ebf1e] FINISH, SetVmTicketVDSCommand, log id: 4665d1dc
>2014-08-07 12:13:44,933 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (ajp--127.0.0.1-8702-4) [415ebf1e] Correlation ID: 415ebf1e, Call Stack: null, Custom Event ID: -1, Message: user admin initiated console session for VM test01
>2014-08-07 12:13:51,591 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-13) Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: User admin is connected to VM test01.
>2014-08-07 12:14:40,359 INFO  [org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo] (DefaultQuartzScheduler_Worker-39) VM test01 96990259-9061-4f77-9783-b004220b6dc2 moved from PoweringUp --> Up
>2014-08-07 12:14:40,393 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler_Worker-39) Correlation ID: 79654e39, Job ID: 6840648e-8bb1-4429-8ea3-6ac2c296acee, Call Stack: null, Custom Event ID: -1, Message: VM test01 started on Host blue
>2014-08-07 12:14:40,411 WARN  [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-8-thread-25) Executing a command: java.util.concurrent.FutureTask , but note that there are 0 tasks in the queue.
>2014-08-07 12:15:07,751 WARN  [org.ovirt.engine.core.utils.threadpool.ThreadPoolUtil] (org.ovirt.thread.pool-8-thread-4) Executing a command: java.util.concurrent.FutureTask , but note that there are 1 tasks in the queue.

Actions: View

Attachments on bug 1126349: 924862 | 924863 | 924864 | 924865