Users
Threads by month
- ----- 2025 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2024 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2023 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2022 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2021 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2020 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2019 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2018 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2017 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2016 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2015 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2014 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2013 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2012 -----
- December
- November
- October
- September
- August
- July
- June
- May
- April
- March
- February
- January
- ----- 2011 -----
- December
- November
- October
- 13 participants
- 19161 discussions
Both ovirt engine & host run F19.
oVirt Engine Version: 3.3.1-2.fc19
I get an "unexpected connection termination" when trying to install host
(see attached log).
Can someone help ?
Thanks in advance
*Pascal *
2
3
Hi Sandro
These are the PPC features and its status:
Target Status Description
3.4 - Under review - Architecture support when importing/exporting VM and Templates
3.4 - Under review - Ability to specify architecture in the OSInfo file
3.4 - Under review - Ability to specify supported video cards and display protocols in the OSInfo file
3.4 - Under review - Ability to specify watch dog in the OSInfo file
3.4 - Done - Ability to specify hotplug of nic and disk in the OSInfo file
3.4 - Under review - Ability to search by architecture
3.4 - Under review - Create Cluster, VM and Templates for PPC64
3.4 - Under review - Add PPC64 Hosts
3.4 - Under review - Support for sPAPR VLAN and sPAPR VSCSI
3.4 - Under review - Run fake power hosts
3.4 - Under review - Obtain capabilities of PPC64 hosts
3.4 - Under review - Obtain the CPU topology of PPC64 hosts
3.4 - Under review - Ability to run power machines on x86 hosts
Some basic patches for PPC support were merged but not enough to enable any PPC feature.
We are focused on the patches 18938, 19010 and 18220 (see below), since they are the base for all PPC features.
Engine
18938 (Initial support for alternative architectures)
|_19010 (Architecture parameter on search backend)
|_18220 (New OS for IBM POWER support)
|_21503 (Architecture dependent commands)
|_21522 (Avoid migration in ppc64)
20294 (Architecture dependent commands)
|_18622 (sPAPR SCSI on PPC64 VMs)
|_20630 (Limit the number of SCSI and VirtIO blk devices)
|_17972 (Show only compatible OSes)
|_18347 (OS type validation)
|_20667 (Fix VM creation with blank template)
|_18702 (Fill and check arch when importing VM and Template)
|_19012 (OVF import for multiple architectures)
|_18226 (Cluster and arch related changes)
|_19132 (Prevent arch mismatches in the FE)
|_18227 (Added arch support for VM and Template)
|_19487 (Selection of incompatible templates)
VDSM
19395 (Hardware information about POWER hosts)
|_17437 (Adding ppc64 handling to getVdsCaps)
|_19396 (Report fake capabilities)
|_18718 (Create VMs for the POWER architecture)
|_19875 (Handling topology for ppc64)
Regards
Leonardo Bianconi
Date: Wed, 27 Nov 2013 17:14:37 +0100
From: Sandro Bonazzola <sbonazzo(a)redhat.com>
To: "Users(a)ovirt.org" <Users(a)ovirt.org>, engine-devel
<engine-devel(a)ovirt.org>
Subject: [Engine-devel] oVirt PPC status update
Message-ID: <52961A6D.4090208(a)redhat.com>
Content-Type: text/plain; charset=ISO-8859-15
Hi,
anybody can report about PPC status for 3.3.2 and 3.4.0 target releases?
It would be nice having someone for PPC at ovirt-sync meeting from next week on, so please join :-)
Thanks,
--
Sandro Bonazzola
Better technology. Faster innovation. Powered by community collaboration.
See how it works at redhat.com
1
0
--========GMXBoundary101141385639387905866
Content-Type: text/plain; charset="utf-8"
Content-Transfer-Encoding: 8bit
Hello,
thank you.
It solved my problem.
Hans-Joachim
----- Original Message -----
From: Gilad Chaplik
Sent: 11/27/13 05:46 PM
To: Hans-Joachim
Subject: Re: [Users] Problem starting VM in oVirt 3.3.1-2
----- Original Message ----- > From: "Hans-Joachim" <rni(a)chef.net> > To: users(a)ovirt.org > Sent: Wednesday, November 27, 2013 4:47:11 PM > Subject: [Users] Problem starting VM in oVirt 3.3.1-2 > > Hello, > > I'm running in troubles..... > After migrating the storage of an powered off VM to a different iSCSI > storage, my CentOS 4 VM does not start any more (well, it's not the reality, > but for the system the VM stays in Wait for launch for hours). In reality, > the VM starts on the node. Hi, we've already solve this issue and it probably be included in the next release. a simple workaround: either disable ballooning in the cluster (edit cluster -> Optimization -> uncheck Enable balloon) or enable ballooning for the vm (edit vm -> Resource Allocation -> check Memory Balloon Device Enabled) Thanks, Gilad.
--========GMXBoundary101141385639387905866
Content-Type: text/html; charset="utf-8"
Content-Transfer-Encoding: quoted-printable
<span style=3D'font-family:Verdana'><span style=3D'font-size:12px'>Hello,<b=
r /><br />thank you.<br /><br />It solved my problem.<br /><br />Hans-Joach=
im<p style=3D"margin:0px; padding:0px;" >=C2=A0</p><blockquote style=3D"bor=
der-left: 1px solid #CCC; padding-left: 5px; margin-left: 5px; margin-botto=
m: 0px; margin-top: 0px; margin-right: 0px;" type=3D"cite"><p style=3D"marg=
in:0px; padding:0px;" ><span style=3D"font-family:Verdana"><span style=3D"f=
ont-size:12px">----- Original Message -----</span></span></p><p style=3D"ma=
rgin:0px; padding:0px;" ><span style=3D"font-family:Verdana"><span style=3D=
"font-size:12px">From: Gilad Chaplik</span></span></p><p style=3D"margin:0p=
x; padding:0px;" ><span style=3D"font-family:Verdana"><span style=3D"font-s=
ize:12px">Sent: 11/27/13 05:46 PM</span></span></p><p style=3D"margin:0px; =
padding:0px;" ><span style=3D"font-family:Verdana"><span style=3D"font-size=
:12px">To: Hans-Joachim</span></span></p><p style=3D"margin:0px; padding:0p=
x;" ><span style=3D"font-family:Verdana"><span style=3D"font-size:12px">Sub=
ject: Re: [Users] Problem starting VM in oVirt 3.3.1-2</span></span></p>=C2=
=A0<div><div><pre style=3D"white-space: pre-wrap; word-wrap: break-word; fo=
nt-size:11;pre">----- Original Message -----=20
> From: "Hans-Joachim" <rni(a)chef.net>=20
> To: users(a)ovirt.org=20
> Sent: Wednesday, November 27, 2013 4:47:11 PM=20
> Subject: [Users] Problem starting VM in oVirt 3.3.1-2=20
>=20
> Hello,=20
>=20
> I'm running in troubles.....=20
> After migrating the storage of an powered off VM to a different iSCSI=
=20
> storage, my CentOS 4 VM does not start any more (well, it's not the re=
ality,=20
> but for the system the VM stays in Wait for launch for hours). In real=
ity,=20
> the VM starts on the node.=20
Hi,=20
we've already solve this issue and it probably be included in the next rele=
ase.=20
a simple workaround:=20
either disable ballooning in the cluster (edit cluster -> Optimization -=
> uncheck Enable balloon)=20
or enable ballooning for the vm (edit vm -> Resource Allocation -> ch=
eck Memory Balloon Device Enabled)=20
Thanks, Gilad.=20
</pre></div></div></blockquote></span></span>
--========GMXBoundary101141385639387905866--
1
0
Hi,
we're going to branch and build oVirt 3.3.2 beta TODAY.
A bug tracker is available at [1] and it shows only 3 bugs still blocking the release:
Whiteboard Bug ID Summary
storage 1022961 Running a VM from a gluster domain uses mount instead of gluster URI
virt 1025829 sysprep floppy is not attached to Windows 2008 R2 machine - even when specifically checked in Run Once
virt 1029885 cloud-init testcase does not work in engine 3.3.1
Please provide an ETA for the above bugs.
The following is a list of the non-blocking bugs still open with target 3.3.2:
Whiteboard Bug ID Summary
infra 1017267 Plaintext user passwords in async_tasks database
infra 987982 When adding a host through the REST API, the error message says that "rootPassword" is required,...
infra 1020344 Power Managent with cisco_ucs problem
integration 1022440 AIO - configure the AIO host to be a gluster cluster/host
integration 902979 ovirt-live - firefox doesn't trust the installed engine
integration 1021805 oVirt Live - use motd to show the admin password
integration 1026930 Package virtio-win and put it in ovirt repositories
integration 1026933 pre-populate ISO domain with virtio-win ISO
network 1019818 Support OpenStack Havana layer 2 agent integration
network 987999 [oVirt] [provider] Add button shouldn't appear on specific provider
network 987916 [oVirt] [provider] Dialog doesn't update unless focus lost
network 906313 [oVirt-webadmin] [setupNetworks] "No valid Operation for <network_name> and Unassigned Logical Networks panel"
network 1023722 [oVirt-webadmin][network] Network roles in cluster management should be radio buttons
network 997197 Some AppErrors messages are grammatically incorrect (singular vs plural)
storage 1029069 Live storage migration snapshot removal fails, probably due to unexpected qemu-img output
storage 987917 [oVirt] [glance] API version not specified in provider dialog
storage 1016118 async between masterVersion : can't connect to StoragePool
ux 906394 [oVirt-webadmin] [network] Loading animation in network main tab 'hosts' and 'vms' subtab is stuck on first view...
virt 1007940 Cannot clone from snapshot while using GlusterFS as POSIX Storage Domain
Please add the bugs to the tracker if you think that 3.3.2 should not be released without them fixed.
For those who want to help testing the bugs, I suggest to add yourself as QA contact for the bug and add yourself to the testing page [2].
Maintainers are welcomed to start filling release notes, the page has been created here [3]
[1] https://bugzilla.redhat.com/1027349
[2] http://www.ovirt.org/Testing/Ovirt_3.3.2_testing
[3] http://www.ovirt.org/OVirt_3.3.2_release_notes
Thanks,
--
Sandro Bonazzola
Better technology. Faster innovation. Powered by community collaboration.
See how it works at redhat.com
4
5
Dear,
We have updated our oVirt installation to 3.3.1 and now we have the
following problem:
When we boot a VM:
He doesn't automatically chooses a hypervisor, he always takes the same
But a larger issue is this one:
2013-11-27 12:37:14,528 WARN [org.ovirt.engine.core.vdsbroker.VdsManager]
(DefaultQuartzScheduler_Worker-1) Failed to refresh VDS , vds =
2a8b1829-2235-44db-be12-ac71dc6777f8 : Vostok, error =
java.lang.NullPointerException, continuing.: java.lang.NullPointerException
Vostok is the server where we try to boot the VM, sometimes the VM comes
up, but most of the time they don't... And if I would say to boot the VM on
a specific other Hypervisor, he will ga ve the same error, only with the
other host(hypervisor) in the error log.
Any Idea's?
Kind regards,
Koen
7
11
Sander Grendelman schreef op 27-11-2013 16:56:
> On Wed, Nov 27, 2013 at 3:51 PM, Ernest Beinrohr
> <Ernest.Beinrohr(a)axonpro.sk> wrote:
>> Just curious, where/how you run the engine. I run it in libvirt/kvm on one
>> of my storage domains.
>
> I run it on our esx cluster (seriously).
Yep, me too...
Highly interested in running it alongside VDSM on one of the hosts,
though...
Cheers,
Martijn.
2
1
Hi I was having odd issues with my IPA domain so rather than
troubleshoot it properly I thought it would be a good idea to remove it
and then add it again.
I removed it with
engine-manage-domains -action=delete -domain=clarkconnect.lan
and when I try to add it with
engine-manage-domains -action=add -domain=clarkconnect.lan -user=admin
-provider=IPA -interactive
which worked fine the first time I get
General error has occurednull
java.lang.NegativeArraySizeException
at
sun.security.jgss.krb5.CipherHelper.aes256Encrypt(CipherHelper.java:1367)
at
sun.security.jgss.krb5.CipherHelper.encryptData(CipherHelper.java:722)
at sun.security.jgss.krb5.WrapToken_v2.<init>(WrapToken_v2.java:200)
at sun.security.jgss.krb5.Krb5Context.wrap(Krb5Context.java:861)
at sun.security.jgss.GSSContextImpl.wrap(GSSContextImpl.java:385)
at com.sun.security.sasl.gsskerb.GssKrb5Base.wrap(GssKrb5Base.java:104)
at
com.sun.jndi.ldap.sasl.SaslOutputStream.write(SaslOutputStream.java:89)
at com.sun.jndi.ldap.Connection.writeRequest(Connection.java:430)
at com.sun.jndi.ldap.LdapClient.search(LdapClient.java:555)
at com.sun.jndi.ldap.LdapCtx.doSearch(LdapCtx.java:1985)
at com.sun.jndi.ldap.LdapCtx.searchAux(LdapCtx.java:1847)
at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1772)
at
com.sun.jndi.toolkit.ctx.ComponentDirContext.p_search(ComponentDirContext.java:386)
at
com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:356)
at
com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:339)
at
javax.naming.directory.InitialDirContext.search(InitialDirContext.java:267)
at org.ovirt.engine.core.ldap.RootDSEData.<init>(RootDSEData.java:52)
at
org.ovirt.engine.core.utils.kerberos.JndiAction.getDomainDN(JndiAction.java:257)
at
org.ovirt.engine.core.utils.kerberos.JndiAction.run(JndiAction.java:87)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:356)
at
org.ovirt.engine.core.utils.kerberos.KerberosConfigCheck.promptSuccessfulAuthentication(KerberosConfigCheck.java:174)
at
org.ovirt.engine.core.utils.kerberos.KerberosConfigCheck.validateKerberosInstallation(KerberosConfigCheck.java:150)
at
org.ovirt.engine.core.utils.kerberos.KerberosConfigCheck.checkInstallation(KerberosConfigCheck.java:135)
at
org.ovirt.engine.core.domains.ManageDomains.checkKerberosConfiguration(ManageDomains.java:746)
at
org.ovirt.engine.core.domains.ManageDomains.testConfiguration(ManageDomains.java:917)
at
org.ovirt.engine.core.domains.ManageDomains.addDomain(ManageDomains.java:539)
at
org.ovirt.engine.core.domains.ManageDomains.runCommand(ManageDomains.java:311)
at
org.ovirt.engine.core.domains.ManageDomains.main(ManageDomains.java:206)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.jboss.modules.Module.run(Module.java:260)
at org.jboss.modules.Main.main(Main.java:291)
Failure while testing domain %1$s. Details: %2$s: One of the parameters
for this error is null and no default message to show
in the engine-manage-domains.log I get
2013-11-13 20:53:41,318 INFO
[org.ovirt.engine.core.domains.ManageDomains] Creating kerberos
configuration for domain(s): clarkconnect.lan
2013-11-13 20:53:41,525 INFO
[org.ovirt.engine.core.domains.ManageDomains] Successfully created
kerberos configuration for domain(s): clarkconnect.lan
2013-11-13 20:53:41,526 INFO
[org.ovirt.engine.core.domains.ManageDomains] Testing kerberos
configuration for domain: clarkconnect.lan
2013-11-13 20:53:48,718 ERROR
[org.ovirt.engine.core.domains.ManageDomains] Failure while testing
domain %1$s. Details: %2$s: One of the parameters for this error is null
and no default message to show
any ideas?
Junk
4
4
--========GMXBoundary242171385563631782200
Content-Type: text/plain; charset="utf-8"
Content-Transfer-Encoding: 8bit
Hello,
I'm running in troubles.....
After migrating the storage of an powered off VM to a different iSCSI storage, my CentOS 4 VM does not start any more (well, it's not the reality, but for the system the VM stays in Wait for launch for hours). In reality, the VM starts on the node.
Any hints?
My Config:
CentOS 6.4
oVirt 3.3.1-2
VDSM 4.12.1-4
engine.log
2013-11-26 14:58:50,171 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-46) Setting new tasks map. The map contains now 0 tasks
2013-11-26 14:58:50,172 INFO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzScheduler_Worker-46) Cleared all tasks of pool 5849b030-626e-47cb-ad90-3ce782d831b3.
2013-11-26 14:58:52,106 INFO [org.ovirt.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-2) [574ec4d2] Lock Acquired to object EngineLock [exclusiveLocks= key: 8798d0da-a82c-4bcf-b41a-7e3fe1c613ef value: VM
, sharedLocks= ]
2013-11-26 14:58:52,124 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-2) [574ec4d2] START, IsVmDuringInitiatingVDSCommand( vmId = 8798d0da-a82c-4bcf-b41a-7e3fe1c613ef), log id: 13e7aadf
2013-11-26 14:58:52,125 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand] (ajp--127.0.0.1-8702-2) [574ec4d2] FINISH, IsVmDuringInitiatingVDSCommand, return: false, log id: 13e7aadf
2013-11-26 14:58:52,251 INFO [org.ovirt.engine.core.bll.RunVmCommand] (pool-6-thread-50) [574ec4d2] Running command: RunVmCommand internal: false. Entities affected : ID: 8798d0da-a82c-4bcf-b41a-7e3fe1c613ef Type: VM
2013-11-26 14:58:52,406 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (pool-6-thread-50) [574ec4d2] START, IsoPrefixVDSCommand(HostName = HOST01, HostId = b34d1e33-bdda-4ba8-9c23-0d136f372ad8, storagePoolId=5849b030-626e-47cb-ad90-3ce782d831b3), log id: 1a6a3b22
2013-11-26 14:58:52,408 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPrefixVDSCommand] (pool-6-thread-50) [574ec4d2] FINISH, IsoPrefixVDSCommand, return: /rhev/data-center/mnt/engine.private.com:_var_lib_exports_iso/53a22027-fd2d-451b-8cd7-0e604fb8e460/images/11111111-1111-1111-1111-111111111111, log id: 1a6a3b22
2013-11-26 14:58:52,441 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-6-thread-50) [574ec4d2] START, CreateVmVDSCommand(HostName = HOST01, HostId = b34d1e33-bdda-4ba8-9c23-0d136f372ad8, vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, vm=VM [vm01]), log id: 2da012df
2013-11-26 14:58:52,476 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-6-thread-50) [574ec4d2] START, CreateVDSCommand(HostName = HOST01, HostId = b34d1e33-bdda-4ba8-9c23-0d136f372ad8, vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, vm=VM [vm01]), log id: 727a7bf7
2013-11-26 14:58:52,539 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-6-thread-50) [574ec4d2] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand spiceSslCipherSuite=DEFAULT,memSize=1024,kvmEnable=true,smp=1,vmType=kvm,emulatedMachine=rhel6.4.0,keyboardLayout=de,memGuaranteedSize=512,pitReinjection=false,nice=0,display=vnc,smartcardEnable=false,tabletEnable=true,smpCoresPerSocket=1,spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard,timeOffset=1,transparentHugePages=true,vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef,devices=[Ljava.util.HashMap;@1030ba06,acpiEnable=true,vmName=vm01,cpuType=Nehalem,custom={device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813=VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=5b94ca77-fab8-41b4-b286-311dee724813, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}}, device_99b583e9-9030-40af-bb41-55d62a4a6b6a=VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=99b583e9-9030-40af-bb41-55d62a4a6b6a, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}}, device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813device_c3d8dcbf-d977-4d4d-8240-35b973ee00b9device_839371b0-1967-4435-910e-0d8e1c980850=VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=839371b0-1967-4435-910e-0d8e1c980850, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}}, device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813device_c3d8dcbf-d977-4d4d-8240-35b973ee00b9=VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=c3d8dcbf-d977-4d4d-8240-35b973ee00b9, device=scsi, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x04, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=scsi0, customProperties={}}, device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813device_c3d8dcbf-d977-4d4d-8240-35b973ee00b9device_839371b0-1967-4435-910e-0d8e1c980850device_920282ca-79c2-4abf-b1f2-7425f16f7820=VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=920282ca-79c2-4abf-b1f2-7425f16f7820, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x06, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}}}
2013-11-26 14:58:52,552 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-6-thread-50) [574ec4d2] FINISH, CreateVDSCommand, log id: 727a7bf7
2013-11-26 14:58:52,567 INFO [org.ovirt.engine.core.vdsbroker.CreateVmVDSCommand] (pool-6-thread-50) [574ec4d2] FINISH, CreateVmVDSCommand, return: WaitForLaunch, log id: 2da012df
2013-11-26 14:58:52,568 INFO [org.ovirt.engine.core.bll.RunVmCommand] (pool-6-thread-50) [574ec4d2] Lock freed to object EngineLock [exclusiveLocks= key: 8798d0da-a82c-4bcf-b41a-7e3fe1c613ef value: VM
, sharedLocks= ]
2013-11-26 14:58:52,576 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (pool-6-thread-50) [574ec4d2] Correlation ID: 574ec4d2, Job ID: d3d270e1-607b-4599-983a-1ef884e81a43, Call Stack: null, Custom Event ID: -1, Message: VM vm01 was started by User01 (Host: HOST01).
2013-11-26 14:58:55,177 WARN [org.ovirt.engine.core.vdsbroker.VdsManager] (DefaultQuartzScheduler_Worker-33) Failed to refresh VDS , vds = b34d1e33-bdda-4ba8-9c23-0d136f372ad8 : HOST01, error = java.lang.NullPointerException, continuing.: java.lang.NullPointerException
at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.proceedBalloonCheck(VdsUpdateRunTimeInfo.java:1312) [vdsbroker.jar:]
at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.refreshVmStats(VdsUpdateRunTimeInfo.java:926) [vdsbroker.jar:]
at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.refreshVdsRunTimeInfo(VdsUpdateRunTimeInfo.java:502) [vdsbroker.jar:]
at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.Refresh(VdsUpdateRunTimeInfo.java:343) [vdsbroker.jar:]
at org.ovirt.engine.core.vdsbroker.VdsManager.OnTimer(VdsManager.java:237) [vdsbroker.jar:]
at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source) [:1.7.0_45]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_45]
at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_45]
at org.ovirt.engine.core.utils.timer.JobWrapper.execute(JobWrapper.java:60) [scheduler.jar:]
at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [quartz.jar:]
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) [quartz.jar:]
vdsm.log
Thread-867485::DEBUG::2013-11-26 14:58:52,504::BindingXMLRPC::979::vds::(wrapper) client [192.168.1.29]::call vmCreate with ({'acpiEnable': 'true', 'emulatedMachine': 'rhel6.4.0', 'tabletEnable': 'true', 'vmId': '8798d0da-a82c-4bcf-b41a-7e3fe1c613ef', 'memGuaranteedSize': 512, 'spiceSslCipherSuite': 'DEFAULT', 'timeOffset': '1', 'cpuType': 'Nehalem', 'custom': {'device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813device_c3d8dcbf-d977-4d4d-8240-35b973ee00b9': 'VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=c3d8dcbf-d977-4d4d-8240-35b973ee00b9, device=scsi, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x04, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=scsi0, customProperties={}}', 'device_99b583e9-9030-40af-bb41-55d62a4a6b6a': 'VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=99b583e9-9030-40af-bb41-55d62a4a6b6a, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}}', 'device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813device_c3d8dcbf-d977-4d4d-8240-35b973ee00b9device_839371b0-1967-4435-910e-0d8e1c980850device_920282ca-79c2-4abf-b1f2-7425f16f7820': 'VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=920282ca-79c2-4abf-b1f2-7425f16f7820, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x06, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}}', 'device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813device_c3d8dcbf-d977-4d4d-8240-35b973ee00b9device_839371b0-1967-4435-910e-0d8e1c980850': 'VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=839371b0-1967-4435-910e-0d8e1c980850, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}}', 'device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813': 'VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=5b94ca77-fab8-41b4-b286-311dee724813, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}}'}, 'smp': '1', 'vmType': 'kvm', 'memSize': 1024, 'smpCoresPerSocket': '1', 'vmName':
'vm01', 'nice': '0', 'smartcardEnable': 'false', 'keyboardLayout': 'de', 'kvmEnable': 'true', 'pitReinjection': 'false', 'transparentHugePages': 'true', 'devices': [{'device': 'cirrus', 'specParams': {'vram': '65536'}, 'type': 'video', 'deviceId': 'bf71f555-dc86-417b-9649-b06083b863b8', 'address': {'bus': '0x00', ' slot': '0x02', ' domain': '0x0000', ' type': 'pci', ' function': '0x0'}}, {'index': '2', 'iface': 'ide', 'address': {' controller': '0', ' target': '0', 'unit': '0', ' bus': '1', ' type': 'drive'}, 'specParams': {'path': ''}, 'readonly': 'true', 'deviceId': '865f42a1-f64a-49cd-a706-76bc1bea8517', 'path': '', 'device': 'cdrom', 'shared': 'false', 'type': 'disk'}, {'index': 0, 'iface': 'virtio', 'format': 'raw', 'bootOrder': '1', 'poolID': '5849b030-626e-47cb-ad90-3ce782d831b3', 'volumeID': 'd3011aef-3297-401c-88d7-65079e05dd4d', 'imageID': '272b7bb5-38e6-41b3-9da4-4cc278873fbf', 'specParams': {}, 'readonly': 'false', 'domainID': '8c8ad4f8-f187-410c-82a7-2beb79a51a30', 'optional': 'false', 'deviceId': '272b7bb5-38e6-41b3-9da4-4cc278873fbf', 'address': {'bus': '0x00', ' slot': '0x05', ' domain': '0x0000', ' type': 'pci', ' function': '0x0'}, 'device': 'disk', 'shared': 'false', 'propagateErrors': 'off', 'type': 'disk'}, {'nicModel': 'pv', 'macAddr': '52:54:00:6d:ce:c8', 'linkActive': 'true', 'network': 'VM', 'custom': {}, 'filter': 'vdsm-no-mac-spoofing', 'specParams': {}, 'deviceId': '78c714a7-9bc5-464b-85ae-328d29ba0b50', 'address': {'bus': '0x00', ' slot': '0x03', ' domain': '0x0000', ' type': 'pci', ' function': '0x0'}, 'device': 'bridge', 'type': 'interface'}], 'spiceSecureChannels': 'smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard', 'display': 'vnc'},) {} flowID [574ec4d2]
Thread-867485::INFO::2013-11-26 14:58:52,509::API::641::vds::(_getNetworkIp) network None: using 0
Thread-867485::INFO::2013-11-26 14:58:52,509::clientIF::366::vds::(createVm) vmContainerLock acquired by vm 8798d0da-a82c-4bcf-b41a-7e3fe1c613ef
Thread-867485::DEBUG::2013-11-26 14:58:52,515::clientIF::380::vds::(createVm) Total desktops after creation of 8798d0da-a82c-4bcf-b41a-7e3fe1c613ef is 5
Thread-867486::DEBUG::2013-11-26 14:58:52,516::vm::2015::vm.Vm::(_startUnderlyingVm) vmId=`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::Start
Thread-867485::DEBUG::2013-11-26 14:58:52,516::BindingXMLRPC::986::vds::(wrapper) return vmCreate with {'status': {'message': 'Done', 'code': 0}, 'vmList': {'status': 'WaitForLaunch', 'acpiEnable': 'true', 'emulatedMachine': 'rhel6.4.0', 'tabletEnable': 'true', 'pid': '0', 'memGuaranteedSize': 512, 'timeOffset': '1', 'keyboardLayout': 'de', 'displayPort': '-1', 'displaySecurePort': '-1', 'spiceSslCipherSuite': 'DEFAULT', 'cpuType': 'Nehalem', 'smp': '1', 'clientIp': '', 'nicModel': 'rtl8139,pv', 'smartcardEnable': 'false', 'kvmEnable': 'true', 'pitReinjection': 'false', 'vmId': '8798d0da-a82c-4bcf-b41a-7e3fe1c613ef', 'transparentHugePages': 'true', 'devices': [{'device': 'cirrus', 'specParams': {'vram': '65536'}, 'type': 'video', 'deviceId': 'bf71f555-dc86-417b-9649-b06083b863b8', 'address': {'bus': '0x00', ' slot': '0x02', ' domain': '0x0000', ' type': 'pci', ' function': '0x0'}}, {'index': '2', 'iface': 'ide', 'address': {' controller': '0', ' target': '0', 'unit': '0', ' bus': '1', ' type': 'drive'}, 'specParams': {'path': ''}, 'readonly': 'true', 'deviceId': '865f42a1-f64a-49cd-a706-76bc1bea8517', 'path': '', 'device': 'cdrom', 'shared': 'false', 'type': 'disk'}, {'index': 0, 'iface': 'virtio', 'format': 'raw', 'bootOrder': '1', 'poolID': '5849b030-626e-47cb-ad90-3ce782d831b3', 'volumeID': 'd3011aef-3297-401c-88d7-65079e05dd4d', 'imageID': '272b7bb5-38e6-41b3-9da4-4cc278873fbf', 'specParams': {}, 'readonly': 'false', 'domainID': '8c8ad4f8-f187-410c-82a7-2beb79a51a30', 'optional': 'false', 'deviceId': '272b7bb5-38e6-41b3-9da4-4cc278873fbf', 'address': {'bus': '0x00', ' slot': '0x05', ' domain': '0x0000', ' type': 'pci', ' function': '0x0'}, 'device': 'disk', 'shared': 'false', 'propagateErrors': 'off', 'type': 'disk'}, {'nicModel': 'pv', 'macAddr': '52:54:00:6d:ce:c8', 'linkActive': 'true', 'network': 'VM', 'custom': {}, 'filter': 'vdsm-no-mac-spoofing', 'specParams': {}, 'deviceId': '78c714a7-9bc5-464b-85ae-328d29ba0b50', 'address': {'bus': '0x00', ' slot': '0x03', ' domain': '0x0000', ' type': 'pci', ' function': '0x0'}, 'device': 'bridge', 'type': 'interface'}], 'custom': {'device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813device_c3d8dcbf-d977-4d4d-8240-35b973ee00b9': 'VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=c3d8dcbf-d977-4d4d-8240-35b973ee00b9, device=scsi, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x04, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=scsi0, customProperties={}}', 'device_99b583e9-9030-40af-bb41-55d62a4a6b6a': 'VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=99b583e9-9030-40af-bb41-55d62a4a6b6a, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=1, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel0, customProperties={}}', 'device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813device_c3d8dcbf-d977-4d4d-8240-35b973ee00b9device_839371b0-1967-4435-910e-0d8e1c980850device_920282ca-79c2-4abf-b1f2-7425f16f7820': 'VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=920282ca-79c2-4abf-b1f2-7425f16f7820, device=virtio-serial, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x06, function=0x0}, managed=false, plugged=true, readOnly=false, deviceAlias=virtio-serial0, customProperties={}}', 'device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813device_c3d8dcbf-d977-4d4d-8240-35b973ee00b9device_839371b0-1967-4435-910e-0d8e1c980850': 'VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=839371b0-1967-4435-910e-0d8e1c980850, device=ide, type=CONTROLLER, bootOrder=0, specParams={}, address={bus=0x00, domain=0x0000, type=pci, slot=0x01, function=0x1}, managed=false, plugged=true, readOnly=false, deviceAlias=ide0, customProperties={}}', 'device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813': 'VmDevice {vmId=8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=5b94ca77-fab8-41b4-b286-311dee724813, device=unix, type=CHANNEL, bootOrder=0, specParams={}, address={port=2, bus=0, controller=0, type=virtio-serial}, managed=false, plugged=true, readOnly=false, deviceAlias=channel1, customProperties={}}'}, 'vmType': 'kvm', 'memSize': 1024, 'displayIp': '0', 'spiceSecureChannels': 'smain,sinputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard', 'smpCoresPerSocket': '1', 'vmName':
'vm01', 'display': 'vnc', 'nice': '0'}}
Thread-867486::DEBUG::2013-11-26 14:58:52,519::vm::2019::vm.Vm::(_startUnderlyingVm) vmId=`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::_ongoingCreations acquired
Thread-867486::INFO::2013-11-26 14:58:52,522::vm::2815::vm.Vm::(_run) vmId=`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::VM wrapper has started
Thread-867486::DEBUG::2013-11-26 14:58:52,527::task::579::TaskManager.Task::(_updateState) Task=`e64eb271-e389-4057-81f7-1148059464d7`::moving from state init -> state preparing
Thread-867486::INFO::2013-11-26 14:58:52,530::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='8c8ad4f8-f187-410c-82a7-2beb79a51a30', spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', imgUUID='272b7bb5-38e6-41b3-9da4-4cc278873fbf', volUUID='d3011aef-3297-401c-88d7-65079e05dd4d', options=None)
Thread-867486::DEBUG::2013-11-26 14:58:52,534::lvm::415::OperationMutex::(_reloadlvs) Operation 'lvm reload operation' got the operation mutex
Thread-867486::DEBUG::2013-11-26 14:58:52,539::lvm::311::Storage.Misc.excCmd::(cmd) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \'a|/dev/mapper/360014051fd69751de087d46f1da5aadb|/dev/mapper/360014056ce3d140de6a5d4fffd9218da|/dev/mapper/360014056db0fc0fdcda7d4a27da043d5|/dev/mapper/36001405917dfc0dd0809d41cfd86c9d4|/dev/mapper/3600508b1001cd6f84303d050b8fb5a80|\', \'r|.*|\' ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags 8c8ad4f8-f187-410c-82a7-2beb79a51a30' (cwd None)
Thread-867486::DEBUG::2013-11-26 14:58:52,588::lvm::311::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ''; <rc> = 0
Thread-867486::DEBUG::2013-11-26 14:58:52,623::lvm::448::OperationMutex::(_reloadlvs) Operation 'lvm reload operation' released the operation mutex
Thread-867486::INFO::2013-11-26 14:58:52,623::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '42949672960', 'apparentsize': '42949672960'}
Thread-867486::DEBUG::2013-11-26 14:58:52,624::task::1168::TaskManager.Task::(prepare) Task=`e64eb271-e389-4057-81f7-1148059464d7`::finished: {'truesize': '42949672960', 'apparentsize': '42949672960'}
Thread-867486::DEBUG::2013-11-26 14:58:52,624::task::579::TaskManager.Task::(_updateState) Task=`e64eb271-e389-4057-81f7-1148059464d7`::moving from state preparing -> state finished
Thread-867486::DEBUG::2013-11-26 14:58:52,624::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-867486::DEBUG::2013-11-26 14:58:52,625::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-867486::DEBUG::2013-11-26 14:58:52,625::task::974::TaskManager.Task::(_decref) Task=`e64eb271-e389-4057-81f7-1148059464d7`::ref 0 aborting False
Thread-867486::INFO::2013-11-26 14:58:52,625::clientIF::325::vds::(prepareVolumePath) prepared volume path:
Thread-867486::DEBUG::2013-11-26 14:58:52,626::task::579::TaskManager.Task::(_updateState) Task=`e0d9071f-a343-400e-865d-81656dd8862b`::moving from state init -> state preparing
Thread-867486::INFO::2013-11-26 14:58:52,626::logUtils::44::dispatcher::(wrapper) Run and protect: prepareImage(sdUUID='8c8ad4f8-f187-410c-82a7-2beb79a51a30', spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', imgUUID='272b7bb5-38e6-41b3-9da4-4cc278873fbf', volUUID='d3011aef-3297-401c-88d7-65079e05dd4d')
Thread-867486::DEBUG::2013-11-26 14:58:52,627::resourceManager::197::ResourceManager.Request::(__init__) ResName=`Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30`ReqID=`664dc122-58c1-49d1-a03e-faa2182f42da`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '3240' at 'prepareImage'
Thread-867486::DEBUG::2013-11-26 14:58:52,627::resourceManager::541::ResourceManager::(registerResource) Trying to register resource 'Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30' for lock type 'shared'
Thread-867486::DEBUG::2013-11-26 14:58:52,628::resourceManager::600::ResourceManager::(registerResource) Resource 'Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30' is free. Now locking as 'shared' (1 active user)
Thread-867486::DEBUG::2013-11-26 14:58:52,628::resourceManager::237::ResourceManager.Request::(grant) ResName=`Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30`ReqID=`664dc122-58c1-49d1-a03e-faa2182f42da`::Granted request
Thread-867486::DEBUG::2013-11-26 14:58:52,629::task::811::TaskManager.Task::(resourceAcquired) Task=`e0d9071f-a343-400e-865d-81656dd8862b`::_resourcesAcquired: Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30 (shared)
Thread-867486::DEBUG::2013-11-26 14:58:52,629::task::974::TaskManager.Task::(_decref) Task=`e0d9071f-a343-400e-865d-81656dd8862b`::ref 1 aborting False
Thread-867486::DEBUG::2013-11-26 14:58:52,635::blockVolume::588::Storage.Misc.excCmd::(getMetadata) '/bin/dd iflag=direct skip=23 bs=512 if=/dev/8c8ad4f8-f187-410c-82a7-2beb79a51a30/metadata count=1' (cwd None)
Thread-867486::DEBUG::2013-11-26 14:58:52,644::blockVolume::588::Storage.Misc.excCmd::(getMetadata) SUCCESS: <err> = '1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.000281928 s, 1.8 MB/s\n'; <rc> = 0
Thread-867486::DEBUG::2013-11-26 14:58:52,644::misc::288::Storage.Misc::(validateDDBytes) err: ['1+0 records in', '1+0 records out', '512 bytes (512 B) copied, 0.000281928 s, 1.8 MB/s'], size: 512
Thread-867486::INFO::2013-11-26 14:58:52,645::image::215::Storage.Image::(getChain) sdUUID=8c8ad4f8-f187-410c-82a7-2beb79a51a30 imgUUID=272b7bb5-38e6-41b3-9da4-4cc278873fbf chain=[<storage.blockVolume.BlockVolume object at 0x14f6ad0>]
Thread-867486::DEBUG::2013-11-26 14:58:52,646::lvm::311::Storage.Misc.excCmd::(cmd) '/usr/bin/sudo -n /sbin/lvm lvchange --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \'a|/dev/mapper/360014051fd69751de087d46f1da5aadb|/dev/mapper/360014056ce3d140de6a5d4fffd9218da|/dev/mapper/360014056db0fc0fdcda7d4a27da043d5|/dev/mapper/36001405917dfc0dd0809d41cfd86c9d4|/dev/mapper/3600508b1001cd6f84303d050b8fb5a80|\', \'r|.*|\' ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --autobackup n --available y 8c8ad4f8-f187-410c-82a7-2beb79a51a30/d3011aef-3297-401c-88d7-65079e05dd4d' (cwd None)
Thread-867486::DEBUG::2013-11-26 14:58:52,942::lvm::311::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ''; <rc> = 0
Thread-867486::DEBUG::2013-11-26 14:58:52,943::lvm::499::OperationMutex::(_invalidatelvs) Operation 'lvm invalidate operation' got the operation mutex
Thread-867486::DEBUG::2013-11-26 14:58:52,943::lvm::511::OperationMutex::(_invalidatelvs) Operation 'lvm invalidate operation' released the operation mutex
Thread-867486::DEBUG::2013-11-26 14:58:52,943::lvm::415::OperationMutex::(_reloadlvs) Operation 'lvm reload operation' got the operation mutex
Thread-867486::DEBUG::2013-11-26 14:58:52,944::lvm::311::Storage.Misc.excCmd::(cmd) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_names = [\\"^/dev/mapper/\\"] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ \'a|/dev/mapper/360014051fd69751de087d46f1da5aadb|/dev/mapper/360014056ce3d140de6a5d4fffd9218da|/dev/mapper/360014056db0fc0fdcda7d4a27da043d5|/dev/mapper/36001405917dfc0dd0809d41cfd86c9d4|/dev/mapper/3600508b1001cd6f84303d050b8fb5a80|\', \'r|.*|\' ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } " --noheadings --units b --nosuffix --separator | -o uuid,name,vg_name,attr,size,seg_start_pe,devices,tags 8c8ad4f8-f187-410c-82a7-2beb79a51a30' (cwd None)
Thread-867486::DEBUG::2013-11-26 14:58:53,242::lvm::311::Storage.Misc.excCmd::(cmd) SUCCESS: <err> = ''; <rc> = 0
Thread-867486::DEBUG::2013-11-26 14:58:53,277::lvm::448::OperationMutex::(_reloadlvs) Operation 'lvm reload operation' released the operation mutex
Thread-867486::DEBUG::2013-11-26 14:58:53,283::blockVolume::588::Storage.Misc.excCmd::(getMetadata) '/bin/dd iflag=direct skip=23 bs=512 if=/dev/8c8ad4f8-f187-410c-82a7-2beb79a51a30/metadata count=1' (cwd None)
Thread-867486::DEBUG::2013-11-26 14:58:53,292::blockVolume::588::Storage.Misc.excCmd::(getMetadata) SUCCESS: <err> = '1+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.000298328 s, 1.7 MB/s\n'; <rc> = 0
Thread-867486::DEBUG::2013-11-26 14:58:53,292::misc::288::Storage.Misc::(validateDDBytes) err: ['1+0 records in', '1+0 records out', '512 bytes (512 B) copied, 0.000298328 s, 1.7 MB/s'], size: 512
Thread-867486::INFO::2013-11-26 14:58:53,293::logUtils::47::dispatcher::(wrapper) Run and protect: prepareImage, Return response: {'info': {'path': '/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65079e05dd4d', 'volType': 'path'}, 'path': '/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65079e05dd4d', 'chain': [{'path': '/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65079e05dd4d', 'domainID': '8c8ad4f8-f187-410c-82a7-2beb79a51a30', 'vmVolInfo': {'path': '/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65079e05dd4d', 'volType': 'path'}, 'volumeID': 'd3011aef-3297-401c-88d7-65079e05dd4d', 'imageID': '272b7bb5-38e6-41b3-9da4-4cc278873fbf'}]}
Thread-867486::DEBUG::2013-11-26 14:58:53,293::task::1168::TaskManager.Task::(prepare) Task=`e0d9071f-a343-400e-865d-81656dd8862b`::finished: {'info': {'path': '/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65079e05dd4d', 'volType': 'path'}, 'path': '/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65079e05dd4d', 'chain': [{'path': '/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65079e05dd4d', 'domainID': '8c8ad4f8-f187-410c-82a7-2beb79a51a30', 'vmVolInfo': {'path': '/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65079e05dd4d', 'volType': 'path'}, 'volumeID': 'd3011aef-3297-401c-88d7-65079e05dd4d', 'imageID': '272b7bb5-38e6-41b3-9da4-4cc278873fbf'}]}
Thread-867486::DEBUG::2013-11-26 14:58:53,293::task::579::TaskManager.Task::(_updateState) Task=`e0d9071f-a343-400e-865d-81656dd8862b`::moving from state preparing -> state finished
Thread-867486::DEBUG::2013-11-26 14:58:53,294::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30': < ResourceRef 'Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30', isValid: 'True' obj: 'None'>}
Thread-867486::DEBUG::2013-11-26 14:58:53,294::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-867486::DEBUG::2013-11-26 14:58:53,294::resourceManager::615::ResourceManager::(releaseResource) Trying to release resource 'Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30'
Thread-867486::DEBUG::2013-11-26 14:58:53,295::resourceManager::634::ResourceManager::(releaseResource) Released resource 'Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30' (0 active users)
Thread-867486::DEBUG::2013-11-26 14:58:53,295::resourceManager::640::ResourceManager::(releaseResource) Resource 'Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30' is free, finding out if anyone is waiting for it.
Thread-867486::DEBUG::2013-11-26 14:58:53,295::resourceManager::648::ResourceManager::(releaseResource) No one is waiting for resource 'Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30', Clearing records.
Thread-867486::DEBUG::2013-11-26 14:58:53,296::task::974::TaskManager.Task::(_decref) Task=`e0d9071f-a343-400e-865d-81656dd8862b`::ref 0 aborting False
Thread-867486::INFO::2013-11-26 14:58:53,296::clientIF::325::vds::(prepareVolumePath) prepared volume path: /rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65079e05dd4d
Thread-867486::DEBUG::2013-11-26 14:58:53,318::utils::486::root::(execCmd) '/usr/libexec/vdsm/hooks/before_vm_start/50_smbios' (cwd None)
Thread-867486::DEBUG::2013-11-26 14:58:53,400::utils::505::root::(execCmd) SUCCESS: <err> = ''; <rc> = 0
Thread-867486::INFO::2013-11-26 14:58:53,401::hooks::88::root::(_runHooksDir)
Thread-867486::DEBUG::2013-11-26 14:58:53,401::vm::2872::vm.Vm::(_run) vmId=`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::<?xml version="1.0" encoding="utf-8"?>
<domain type="kvm">
<name>vm01</name>
<uuid>8798d0da-a82c-4bcf-b41a-7e3fe1c613ef</uuid>
<memory>1048576</memory>
<currentMemory>1048576</currentMemory>
<vcpu>1</vcpu>
<memtune>
<min_guarantee>524288</min_guarantee>
</memtune>
<devices>
<channel type="unix">
<target name="com.redhat.rhevm.vdsm" type="virtio"/>
<source mode="bind" path="/var/lib/libvirt/qemu/channels/8798d0da-a82c-4bcf-b41a-7e3fe1c613ef.com.redhat.rhevm.vdsm"/>
</channel>
<channel type="unix">
<target name="org.qemu.guest_agent.0" type="virtio"/>
<source mode="bind" path="/var/lib/libvirt/qemu/channels/8798d0da-a82c-4bcf-b41a-7e3fe1c613ef.org.qemu.guest_agent.0"/>
</channel>
<input bus="usb" type="tablet"/>
<graphics autoport="yes" keymap="de" listen="0" passwd="*****" passwdValidTo="1970-01-01T00:00:01" port="-1" type="vnc"/>
<video>
<address bus="0x00" domain="0x0000" function="0x0" slot="0x02" type="pci"/>
<model heads="1" type="cirrus" vram="65536"/>
</video>
<interface type="bridge">
<address bus="0x00" domain="0x0000" function="0x0" slot="0x03" type="pci"/>
<mac address="52:54:00:6d:ce:c8"/>
<model type="virtio"/>
<source bridge="VM"/>
<filterref filter="vdsm-no-mac-spoofing"/>
<link state="up"/>
</interface>
<disk device="cdrom" snapshot="no" type="file">
<address bus="1" controller="0" target="0" type="drive" unit="0"/>
<source file="" startupPolicy="optional"/>
<target bus="ide" dev="hdc"/>
<readonly/>
<serial/>
</disk>
<disk device="disk" snapshot="no" type="block">
<address bus="0x00" domain="0x0000" function="0x0" slot="0x05" type="pci"/>
<source dev="/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65079e05dd4d"/>
<target bus="virtio" dev="vda"/>
<serial>272b7bb5-38e6-41b3-9da4-4cc278873fbf</serial>
<boot order="1"/>
<driver cache="none" error_policy="stop" io="native" name="qemu" type="raw"/>
</disk>
<memballoon model="none"/>
</devices>
<os>
<type arch="x86_64" machine="rhel6.4.0">hvm</type>
<smbios mode="sysinfo"/>
</os>
<sysinfo type="smbios">
<system>
<entry name="manufacturer">oVirt</entry>
<entry name="product">oVirt Node</entry>
<entry name="version">6-4.el6.centos.10</entry>
<entry name="serial">32393735-3933-5A43-4A32-34333046564B</entry>
<entry name="uuid">8798d0da-a82c-4bcf-b41a-7e3fe1c613ef</entry>
</system>
</sysinfo>
<clock adjustment="1" offset="variable">
<timer name="rtc" tickpolicy="catchup"/>
</clock>
<features>
<acpi/>
</features>
<cpu match="exact">
<model>Nehalem</model>
<topology cores="1" sockets="1" threads="1"/>
</cpu>
</domain>
Thread-166407::DEBUG::2013-11-26 14:58:53,588::blockSD::594::Storage.Misc.excCmd::(getReadDelay) '/bin/dd iflag=direct if=/dev/8c8ad4f8-f187-410c-82a7-2beb79a51a30/metadata bs=4096 count=1' (cwd None)
Thread-166407::DEBUG::2013-11-26 14:58:53,599::blockSD::594::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '1+0 records in\n1+0 records out\n4096 bytes (4.1 kB) copied, 0.000345562 s, 11.9 MB/s\n'; <rc> = 0
Thread-24::DEBUG::2013-11-26 14:58:53,791::fileSD::238::Storage.Misc.excCmd::(getReadDelay) '/bin/dd iflag=direct
if=/rhev/data-center/mnt/engine.privat.com:_export_VMs/48055e27-f1ca-466a-8a2c-e191c34f0226/dom_md/metadata bs=4096 count=1' (cwd None)
Thread-24::DEBUG::2013-11-26 14:58:53,801::fileSD::238::Storage.Misc.excCmd::(getReadDelay) SUCCESS: <err> = '0+1 records in\n0+1 records out\n349 bytes (349 B) copied, 0.000683955 s, 510 kB/s\n'; <rc> = 0
libvirtEventLoop::DEBUG::2013-11-26 14:58:54,094::vm::4724::vm.Vm::(_onLibvirtLifecycleEvent) vmId=`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::event Started detail 0 opaque None
Thread-867486::DEBUG::2013-11-26 14:58:54,248::sampling::285::vm.Vm::(start) vmId=`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::Start statistics collection
Thread-867488::DEBUG::2013-11-26 14:58:54,249::sampling::314::vm.Vm::(run) vmId=`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::Stats thread started
Thread-867486::DEBUG::2013-11-26 14:58:54,251::vmChannels::194::vds::(register) Add fileno 51 to listener's channels.
Thread-867488::DEBUG::2013-11-26 14:58:54,253::task::579::TaskManager.Task::(_updateState) Task=`c5c6d816-7de8-4ab5-a5fa-a3fba225d797`::moving from state init -> state preparing
Thread-867488::INFO::2013-11-26 14:58:54,253::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='8c8ad4f8-f187-410c-82a7-2beb79a51a30', spUUID='5849b030-626e-47cb-ad90-3ce782d831b3', imgUUID='272b7bb5-38e6-41b3-9da4-4cc278873fbf', volUUID='d3011aef-3297-401c-88d7-65079e05dd4d', options=None)
Thread-867486::WARNING::2013-11-26 14:58:54,253::vm::3326::vm.Vm::(_readPauseCode) vmId=`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::_readPauseCode unsupported by libvirt vm
Thread-867488::INFO::2013-11-26 14:58:54,255::logUtils::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '42949672960', 'apparentsize': '42949672960'}
Thread-867488::DEBUG::2013-11-26 14:58:54,256::task::1168::TaskManager.Task::(prepare) Task=`c5c6d816-7de8-4ab5-a5fa-a3fba225d797`::finished: {'truesize': '42949672960', 'apparentsize': '42949672960'}
Thread-867488::DEBUG::2013-11-26 14:58:54,256::task::579::TaskManager.Task::(_updateState) Task=`c5c6d816-7de8-4ab5-a5fa-a3fba225d797`::moving from state preparing -> state finished
Thread-867488::DEBUG::2013-11-26 14:58:54,256::resourceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}
Thread-867488::DEBUG::2013-11-26 14:58:54,257::resourceManager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}
Thread-867488::DEBUG::2013-11-26 14:58:54,257::task::974::TaskManager.Task::(_decref) Task=`c5c6d816-7de8-4ab5-a5fa-a3fba225d797`::ref 0 aborting False
Thread-867486::DEBUG::2013-11-26 14:58:54,263::vm::2036::vm.Vm::(_startUnderlyingVm) vmId=`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::_ongoingCreations released
VM Channels Listener::DEBUG::2013-11-26 14:58:54,694::vmChannels::102::vds::(_do_add_channels) fileno 51 was added to unconnected channels.
VM Channels Listener::DEBUG::2013-11-26 14:58:54,694::vmChannels::128::vds::(_handle_unconnected) Trying to connect fileno 51.
VM Channels Listener::DEBUG::2013-11-26 14:58:54,695::guestIF::147::vm.Vm::(_connect) vmId=`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::Attempting connection to /var/lib/libvirt/qemu/channels/8798d0da-a82c-4bcf-b41a-7e3fe1c613ef.com.redhat.rhevm.vdsm
VM Channels Listener::DEBUG::2013-11-26 14:58:54,695::guestIF::150::vm.Vm::(_connect) vmId=`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::Connected to /var/lib/libvirt/qemu/channels/8798d0da-a82c-4bcf-b41a-7e3fe1c613ef.com.redhat.rhevm.vdsm
VM Channels Listener::DEBUG::2013-11-26 14:58:54,695::vmChannels::144::vds::(_handle_unconnected) Connecting to fileno 51 succeeded.
Thread-867490::DEBUG::2013-11-26 14:58:55,170::BindingXMLRPC::979::vds::(wrapper) client [192.168.1.29]::call vmGetStats with ('8798d0da-a82c-4bcf-b41a-7e3fe1c613ef',) {}
Thread-867490::DEBUG::2013-11-26 14:58:55,170::vm::579::vm.Vm::(_getCpuStats) vmId=`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::CPU stats not available: 'NoneType' object is unsubscriptable
Thread-867490::DEBUG::2013-11-26 14:58:55,170::vm::613::vm.Vm::(_getNetworkStats) vmId=`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::Network stats not available
--========GMXBoundary242171385563631782200
Content-Type: text/html; charset="utf-8"
Content-Transfer-Encoding: quoted-printable
<span style=3D'font-family:Verdana'><span style=3D'font-size:12px'>Hello,<b=
r /><br />I'm running in troubles.....<br />After migrating the storage of =
an powered off VM to a different iSCSI storage, my CentOS 4 VM does not sta=
rt any more (well, it's not the reality, but for the system the VM stays in=
Wait for launch for hours). In reality, the VM starts on the node.<br /><b=
r />Any hints?<br /><br />My Config:<br />CentOS 6.4<br />oVirt 3.3.1-2<br =
/>VDSM 4.12.1-4<br /><br />engine.log<br /><br />2013-11-26 14:58:50,171 IN=
FO [org.ovirt.engine.core.bll.AsyncTaskManager] (DefaultQuartzSchedul=
er_Worker-46) Setting new tasks map. The map contains now 0 tasks<br />2013=
-11-26 14:58:50,172 INFO [org.ovirt.engine.core.bll.AsyncTaskManager]=
(DefaultQuartzScheduler_Worker-46) Cleared all tasks of pool 5849b030-626e=
-47cb-ad90-3ce782d831b3.<br />2013-11-26 14:58:52,106 INFO [org.ovirt=
.engine.core.bll.RunVmCommand] (ajp--127.0.0.1-8702-2) [574ec4d2] Lock Acqu=
ired to object EngineLock [exclusiveLocks=3D key: 8798d0da-a82c-4bcf-b41a-7=
e3fe1c613ef value: VM<br />, sharedLocks=3D ]<br />2013-11-26 14:58:52,124 =
INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringInitiatingVDSCommand]=
(ajp--127.0.0.1-8702-2) [574ec4d2] START, IsVmDuringInitiatingVDSCommand( =
vmId =3D 8798d0da-a82c-4bcf-b41a-7e3fe1c613ef), log id: 13e7aadf<br />2013-=
11-26 14:58:52,125 INFO [org.ovirt.engine.core.vdsbroker.IsVmDuringIn=
itiatingVDSCommand] (ajp--127.0.0.1-8702-2) [574ec4d2] FINISH, IsVmDuringIn=
itiatingVDSCommand, return: false, log id: 13e7aadf<br />2013-11-26 14:58:5=
2,251 INFO [org.ovirt.engine.core.bll.RunVmCommand] (pool-6-thread-50=
) [574ec4d2] Running command: RunVmCommand internal: false. Entities affect=
ed : ID: 8798d0da-a82c-4bcf-b41a-7e3fe1c613ef Type: VM<br />2013-11-2=
6 14:58:52,406 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.IsoPre=
fixVDSCommand] (pool-6-thread-50) [574ec4d2] START, IsoPrefixVDSCommand(Hos=
tName =3D HOST01, HostId =3D b34d1e33-bdda-4ba8-9c23-0d136f372ad8, storageP=
oolId=3D5849b030-626e-47cb-ad90-3ce782d831b3), log id: 1a6a3b22<br />2013-1=
1-26 14:58:52,408 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.Iso=
PrefixVDSCommand] (pool-6-thread-50) [574ec4d2] FINISH, IsoPrefixVDSCommand=
, return: /rhev/data-center/mnt/engine.private.com:_var_lib_exports_iso/53a=
22027-fd2d-451b-8cd7-0e604fb8e460/images/11111111-1111-1111-1111-1111111111=
11, log id: 1a6a3b22<br />2013-11-26 14:58:52,441 INFO [org.ovirt.eng=
ine.core.vdsbroker.CreateVmVDSCommand] (pool-6-thread-50) [574ec4d2] START,=
CreateVmVDSCommand(HostName =3D HOST01, HostId =3D b34d1e33-bdda-4ba8-9c23=
-0d136f372ad8, vmId=3D8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, vm=3DVM [vm01])=
, log id: 2da012df<br />2013-11-26 14:58:52,476 INFO [org.ovirt.engin=
e.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-6-thread-50) [574ec4d2] =
START, CreateVDSCommand(HostName =3D HOST01, HostId =3D b34d1e33-bdda-4ba8-=
9c23-0d136f372ad8, vmId=3D8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, vm=3DVM [vm=
01]), log id: 727a7bf7<br />2013-11-26 14:58:52,539 INFO [org.ovirt.e=
ngine.core.vdsbroker.vdsbroker.CreateVDSCommand] (pool-6-thread-50) [574ec4=
d2] org.ovirt.engine.core.vdsbroker.vdsbroker.CreateVDSCommand spiceSslCiph=
erSuite=3DDEFAULT,memSize=3D1024,kvmEnable=3Dtrue,smp=3D1,vmType=3Dkvm,emul=
atedMachine=3Drhel6.4.0,keyboardLayout=3Dde,memGuaranteedSize=3D512,pitRein=
jection=3Dfalse,nice=3D0,display=3Dvnc,smartcardEnable=3Dfalse,tabletEnable=
=3Dtrue,smpCoresPerSocket=3D1,spiceSecureChannels=3Dsmain,sinputs,scursor,s=
playback,srecord,sdisplay,susbredir,ssmartcard,timeOffset=3D1,transparentHu=
gePages=3Dtrue,vmId=3D8798d0da-a82c-4bcf-b41a-7e3fe1c613ef,devices=3D[Ljava=
.util.HashMap;@1030ba06,acpiEnable=3Dtrue,vmName=3Dvm01,cpuType=3DNehalem,c=
ustom=3D{device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41=
b4-b286-311dee724813=3DVmDevice {vmId=3D8798d0da-a82c-4bcf-b41a-7e3fe1c613e=
f, deviceId=3D5b94ca77-fab8-41b4-b286-311dee724813, device=3Dunix, type=3DC=
HANNEL, bootOrder=3D0, specParams=3D{}, address=3D{port=3D2, bus=3D0, contr=
oller=3D0, type=3Dvirtio-serial}, managed=3Dfalse, plugged=3Dtrue, readOnly=
=3Dfalse, deviceAlias=3Dchannel1, customProperties=3D{}}, device_99b583e9-9=
030-40af-bb41-55d62a4a6b6a=3DVmDevice {vmId=3D8798d0da-a82c-4bcf-b41a-7e3fe=
1c613ef, deviceId=3D99b583e9-9030-40af-bb41-55d62a4a6b6a, device=3Dunix, ty=
pe=3DCHANNEL, bootOrder=3D0, specParams=3D{}, address=3D{port=3D1, bus=3D0,=
controller=3D0, type=3Dvirtio-serial}, managed=3Dfalse, plugged=3Dtrue, re=
adOnly=3Dfalse, deviceAlias=3Dchannel0, customProperties=3D{}}, device_99b5=
83e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813=
device_c3d8dcbf-d977-4d4d-8240-35b973ee00b9device_839371b0-1967-4435-910e-0=
d8e1c980850=3DVmDevice {vmId=3D8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, device=
Id=3D839371b0-1967-4435-910e-0d8e1c980850, device=3Dide, type=3DCONTROLLER,=
bootOrder=3D0, specParams=3D{}, address=3D{bus=3D0x00, domain=3D0x0000, ty=
pe=3Dpci, slot=3D0x01, function=3D0x1}, managed=3Dfalse, plugged=3Dtrue, re=
adOnly=3Dfalse, deviceAlias=3Dide0, customProperties=3D{}}, device_99b583e9=
-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813devi=
ce_c3d8dcbf-d977-4d4d-8240-35b973ee00b9=3DVmDevice {vmId=3D8798d0da-a82c-4b=
cf-b41a-7e3fe1c613ef, deviceId=3Dc3d8dcbf-d977-4d4d-8240-35b973ee00b9, devi=
ce=3Dscsi, type=3DCONTROLLER, bootOrder=3D0, specParams=3D{}, address=3D{bu=
s=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x04, function=3D0x0}, manage=
d=3Dfalse, plugged=3Dtrue, readOnly=3Dfalse, deviceAlias=3Dscsi0, customPro=
perties=3D{}}, device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-f=
ab8-41b4-b286-311dee724813device_c3d8dcbf-d977-4d4d-8240-35b973ee00b9device=
_839371b0-1967-4435-910e-0d8e1c980850device_920282ca-79c2-4abf-b1f2-7425f16=
f7820=3DVmDevice {vmId=3D8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=3D9=
20282ca-79c2-4abf-b1f2-7425f16f7820, device=3Dvirtio-serial, type=3DCONTROL=
LER, bootOrder=3D0, specParams=3D{}, address=3D{bus=3D0x00, domain=3D0x0000=
, type=3Dpci, slot=3D0x06, function=3D0x0}, managed=3Dfalse, plugged=3Dtrue=
, readOnly=3Dfalse, deviceAlias=3Dvirtio-serial0, customProperties=3D{}}}<b=
r />2013-11-26 14:58:52,552 INFO [org.ovirt.engine.core.vdsbroker.vds=
broker.CreateVDSCommand] (pool-6-thread-50) [574ec4d2] FINISH, CreateVDSCom=
mand, log id: 727a7bf7<br />2013-11-26 14:58:52,567 INFO [org.ovirt.e=
ngine.core.vdsbroker.CreateVmVDSCommand] (pool-6-thread-50) [574ec4d2] FINI=
SH, CreateVmVDSCommand, return: WaitForLaunch, log id: 2da012df<br />2013-1=
1-26 14:58:52,568 INFO [org.ovirt.engine.core.bll.RunVmCommand] (pool=
-6-thread-50) [574ec4d2] Lock freed to object EngineLock [exclusiveLocks=3D=
key: 8798d0da-a82c-4bcf-b41a-7e3fe1c613ef value: VM<br />, sharedLocks=3D =
]<br />2013-11-26 14:58:52,576 INFO [org.ovirt.engine.core.dal.dbbrok=
er.auditloghandling.AuditLogDirector] (pool-6-thread-50) [574ec4d2] Correla=
tion ID: 574ec4d2, Job ID: d3d270e1-607b-4599-983a-1ef884e81a43, Call Stack=
: null, Custom Event ID: -1, Message: VM vm01 was started by User01 (Host: =
HOST01).<br />2013-11-26 14:58:55,177 WARN [org.ovirt.engine.core.vds=
broker.VdsManager] (DefaultQuartzScheduler_Worker-33) Failed to refresh VDS=
, vds =3D b34d1e33-bdda-4ba8-9c23-0d136f372ad8 : HOST01, error =3D java.la=
ng.NullPointerException, continuing.: java.lang.NullPointerException<br />&=
nbsp; at org.ovirt.engine.core.vdsbroke=
r.VdsUpdateRunTimeInfo.proceedBalloonCheck(VdsUpdateRunTimeInfo.java:1312) =
[vdsbroker.jar:]<br /> at org.ovi=
rt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.refreshVmStats(VdsUpdateRunTi=
meInfo.java:926) [vdsbroker.jar:]<br /> =
at org.ovirt.engine.core.vdsbroker.VdsUpdateRunTimeInfo.refreshVdsRu=
nTimeInfo(VdsUpdateRunTimeInfo.java:502) [vdsbroker.jar:]<br /> =
at org.ovirt.engine.core.vdsbroker.VdsUpdate=
RunTimeInfo.Refresh(VdsUpdateRunTimeInfo.java:343) [vdsbroker.jar:]<br />&n=
bsp; at org.ovirt.engine.core.vdsbroker=
.VdsManager.OnTimer(VdsManager.java:237) [vdsbroker.jar:]<br /> =
at sun.reflect.GeneratedMethodAccessor9.invo=
ke(Unknown Source) [:1.7.0_45]<br /> &nb=
sp; at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcce=
ssorImpl.java:43) [rt.jar:1.7.0_45]<br /> &nbs=
p; at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_=
45]<br /> at org.ovirt.engine.cor=
e.utils.timer.JobWrapper.execute(JobWrapper.java:60) [scheduler.jar:]<br />=
at org.quartz.core.JobRunShell.r=
un(JobRunShell.java:213) [quartz.jar:]<br /> &=
nbsp; at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThr=
eadPool.java:557) [quartz.jar:]<br /><br />vdsm.log<br />Thread-867485::DEB=
UG::2013-11-26 14:58:52,504::BindingXMLRPC::979::vds::(wrapper) client [192=
.168.1.29]::call vmCreate with ({'acpiEnable': 'true', 'emulatedMachine': '=
rhel6.4.0', 'tabletEnable': 'true', 'vmId': '8798d0da-a82c-4bcf-b41a-7e3fe1=
c613ef', 'memGuaranteedSize': 512, 'spiceSslCipherSuite': 'DEFAULT', 'timeO=
ffset': '1', 'cpuType': 'Nehalem', 'custom': {'device_99b583e9-9030-40af-bb=
41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813device_c3d8dcbf-d=
977-4d4d-8240-35b973ee00b9': 'VmDevice {vmId=3D8798d0da-a82c-4bcf-b41a-7e3f=
e1c613ef, deviceId=3Dc3d8dcbf-d977-4d4d-8240-35b973ee00b9, device=3Dscsi, t=
ype=3DCONTROLLER, bootOrder=3D0, specParams=3D{}, address=3D{bus=3D0x00, do=
main=3D0x0000, type=3Dpci, slot=3D0x04, function=3D0x0}, managed=3Dfalse, p=
lugged=3Dtrue, readOnly=3Dfalse, deviceAlias=3Dscsi0, customProperties=3D{}=
}', 'device_99b583e9-9030-40af-bb41-55d62a4a6b6a': 'VmDevice {vmId=3D8798d0=
da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=3D99b583e9-9030-40af-bb41-55d62a4a=
6b6a, device=3Dunix, type=3DCHANNEL, bootOrder=3D0, specParams=3D{}, addres=
s=3D{port=3D1, bus=3D0, controller=3D0, type=3Dvirtio-serial}, managed=3Dfa=
lse, plugged=3Dtrue, readOnly=3Dfalse, deviceAlias=3Dchannel0, customProper=
ties=3D{}}', 'device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fa=
b8-41b4-b286-311dee724813device_c3d8dcbf-d977-4d4d-8240-35b973ee00b9device_=
839371b0-1967-4435-910e-0d8e1c980850device_920282ca-79c2-4abf-b1f2-7425f16f=
7820': 'VmDevice {vmId=3D8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=3D9=
20282ca-79c2-4abf-b1f2-7425f16f7820, device=3Dvirtio-serial, type=3DCONTROL=
LER, bootOrder=3D0, specParams=3D{}, address=3D{bus=3D0x00, domain=3D0x0000=
, type=3Dpci, slot=3D0x06, function=3D0x0}, managed=3Dfalse, plugged=3Dtrue=
, readOnly=3Dfalse, deviceAlias=3Dvirtio-serial0, customProperties=3D{}}', =
'device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-=
311dee724813device_c3d8dcbf-d977-4d4d-8240-35b973ee00b9device_839371b0-1967=
-4435-910e-0d8e1c980850': 'VmDevice {vmId=3D8798d0da-a82c-4bcf-b41a-7e3fe1c=
613ef, deviceId=3D839371b0-1967-4435-910e-0d8e1c980850, device=3Dide, type=
=3DCONTROLLER, bootOrder=3D0, specParams=3D{}, address=3D{bus=3D0x00, domai=
n=3D0x0000, type=3Dpci, slot=3D0x01, function=3D0x1}, managed=3Dfalse, plug=
ged=3Dtrue, readOnly=3Dfalse, deviceAlias=3Dide0, customProperties=3D{}}', =
'device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-=
311dee724813': 'VmDevice {vmId=3D8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, devi=
ceId=3D5b94ca77-fab8-41b4-b286-311dee724813, device=3Dunix, type=3DCHANNEL,=
bootOrder=3D0, specParams=3D{}, address=3D{port=3D2, bus=3D0, controller=
=3D0, type=3Dvirtio-serial}, managed=3Dfalse, plugged=3Dtrue, readOnly=3Dfa=
lse, deviceAlias=3Dchannel1, customProperties=3D{}}'}, 'smp': '1', 'vmType'=
: 'kvm', 'memSize': 1024, 'smpCoresPerSocket': '1', 'vmName':<br />'vm01', =
'nice': '0', 'smartcardEnable': 'false', 'keyboardLayout': 'de', 'kvmEnable=
': 'true', 'pitReinjection': 'false', 'transparentHugePages': 'true', 'devi=
ces': [{'device': 'cirrus', 'specParams': {'vram': '65536'}, 'type': 'video=
', 'deviceId': 'bf71f555-dc86-417b-9649-b06083b863b8', 'address': {'bus': '=
0x00', ' slot': '0x02', ' domain': '0x0000', ' type': 'pci', ' function': '=
0x0'}}, {'index': '2', 'iface': 'ide', 'address': {' controller': '0', ' ta=
rget': '0', 'unit': '0', ' bus': '1', ' type': 'drive'}, 'specParams': {'pa=
th': ''}, 'readonly': 'true', 'deviceId': '865f42a1-f64a-49cd-a706-76bc1bea=
8517', 'path': '', 'device': 'cdrom', 'shared': 'false', 'type': 'disk'}, {=
'index': 0, 'iface': 'virtio', 'format': 'raw', 'bootOrder': '1', 'poolID':=
'5849b030-626e-47cb-ad90-3ce782d831b3', 'volumeID': 'd3011aef-3297-401c-88=
d7-65079e05dd4d', 'imageID': '272b7bb5-38e6-41b3-9da4-4cc278873fbf', 'specP=
arams': {}, 'readonly': 'false', 'domainID': '8c8ad4f8-f187-410c-82a7-2beb7=
9a51a30', 'optional': 'false', 'deviceId': '272b7bb5-38e6-41b3-9da4-4cc2788=
73fbf', 'address': {'bus': '0x00', ' slot': '0x05', ' domain': '0x0000', ' =
type': 'pci', ' function': '0x0'}, 'device': 'disk', 'shared': 'false', 'pr=
opagateErrors': 'off', 'type': 'disk'}, {'nicModel': 'pv', 'macAddr': '52:5=
4:00:6d:ce:c8', 'linkActive': 'true', 'network': 'VM', 'custom': {}, 'filte=
r': 'vdsm-no-mac-spoofing', 'specParams': {}, 'deviceId': '78c714a7-9bc5-46=
4b-85ae-328d29ba0b50', 'address': {'bus': '0x00', ' slot': '0x03', ' domain=
': '0x0000', ' type': 'pci', ' function': '0x0'}, 'device': 'bridge', 'type=
': 'interface'}], 'spiceSecureChannels': 'smain,sinputs,scursor,splayback,s=
record,sdisplay,susbredir,ssmartcard', 'display': 'vnc'},) {} flowID [574ec=
4d2]<br />Thread-867485::INFO::2013-11-26 14:58:52,509::API::641::vds::(_ge=
tNetworkIp) network None: using 0<br />Thread-867485::INFO::2013-11-26 14:5=
8:52,509::clientIF::366::vds::(createVm) vmContainerLock acquired by vm 879=
8d0da-a82c-4bcf-b41a-7e3fe1c613ef<br />Thread-867485::DEBUG::2013-11-26 14:=
58:52,515::clientIF::380::vds::(createVm) Total desktops after creation of =
8798d0da-a82c-4bcf-b41a-7e3fe1c613ef is 5<br />Thread-867486::DEBUG::2013-1=
1-26 14:58:52,516::vm::2015::vm.Vm::(_startUnderlyingVm) vmId=3D`8798d0da-a=
82c-4bcf-b41a-7e3fe1c613ef`::Start<br />Thread-867485::DEBUG::2013-11-26 14=
:58:52,516::BindingXMLRPC::986::vds::(wrapper) return vmCreate with {'statu=
s': {'message': 'Done', 'code': 0}, 'vmList': {'status': 'WaitForLaunch', '=
acpiEnable': 'true', 'emulatedMachine': 'rhel6.4.0', 'tabletEnable': 'true'=
, 'pid': '0', 'memGuaranteedSize': 512, 'timeOffset': '1', 'keyboardLayout'=
: 'de', 'displayPort': '-1', 'displaySecurePort': '-1', 'spiceSslCipherSuit=
e': 'DEFAULT', 'cpuType': 'Nehalem', 'smp': '1', 'clientIp': '', 'nicModel'=
: 'rtl8139,pv', 'smartcardEnable': 'false', 'kvmEnable': 'true', 'pitReinje=
ction': 'false', 'vmId': '8798d0da-a82c-4bcf-b41a-7e3fe1c613ef', 'transpare=
ntHugePages': 'true', 'devices': [{'device': 'cirrus', 'specParams': {'vram=
': '65536'}, 'type': 'video', 'deviceId': 'bf71f555-dc86-417b-9649-b06083b8=
63b8', 'address': {'bus': '0x00', ' slot': '0x02', ' domain': '0x0000', ' t=
ype': 'pci', ' function': '0x0'}}, {'index': '2', 'iface': 'ide', 'address'=
: {' controller': '0', ' target': '0', 'unit': '0', ' bus': '1', ' type': '=
drive'}, 'specParams': {'path': ''}, 'readonly': 'true', 'deviceId': '865f4=
2a1-f64a-49cd-a706-76bc1bea8517', 'path': '', 'device': 'cdrom', 'shared': =
'false', 'type': 'disk'}, {'index': 0, 'iface': 'virtio', 'format': 'raw', =
'bootOrder': '1', 'poolID': '5849b030-626e-47cb-ad90-3ce782d831b3', 'volume=
ID': 'd3011aef-3297-401c-88d7-65079e05dd4d', 'imageID': '272b7bb5-38e6-41b3=
-9da4-4cc278873fbf', 'specParams': {}, 'readonly': 'false', 'domainID': '8c=
8ad4f8-f187-410c-82a7-2beb79a51a30', 'optional': 'false', 'deviceId': '272b=
7bb5-38e6-41b3-9da4-4cc278873fbf', 'address': {'bus': '0x00', ' slot': '0x0=
5', ' domain': '0x0000', ' type': 'pci', ' function': '0x0'}, 'device': 'di=
sk', 'shared': 'false', 'propagateErrors': 'off', 'type': 'disk'}, {'nicMod=
el': 'pv', 'macAddr': '52:54:00:6d:ce:c8', 'linkActive': 'true', 'network':=
'VM', 'custom': {}, 'filter': 'vdsm-no-mac-spoofing', 'specParams': {}, 'd=
eviceId': '78c714a7-9bc5-464b-85ae-328d29ba0b50', 'address': {'bus': '0x00'=
, ' slot': '0x03', ' domain': '0x0000', ' type': 'pci', ' function': '0x0'}=
, 'device': 'bridge', 'type': 'interface'}], 'custom': {'device_99b583e9-90=
30-40af-bb41-55d62a4a6b6adevice_5b94ca77-fab8-41b4-b286-311dee724813device_=
c3d8dcbf-d977-4d4d-8240-35b973ee00b9': 'VmDevice {vmId=3D8798d0da-a82c-4bcf=
-b41a-7e3fe1c613ef, deviceId=3Dc3d8dcbf-d977-4d4d-8240-35b973ee00b9, device=
=3Dscsi, type=3DCONTROLLER, bootOrder=3D0, specParams=3D{}, address=3D{bus=
=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x04, function=3D0x0}, managed=
=3Dfalse, plugged=3Dtrue, readOnly=3Dfalse, deviceAlias=3Dscsi0, customProp=
erties=3D{}}', 'device_99b583e9-9030-40af-bb41-55d62a4a6b6a': 'VmDevice {vm=
Id=3D8798d0da-a82c-4bcf-b41a-7e3fe1c613ef, deviceId=3D99b583e9-9030-40af-bb=
41-55d62a4a6b6a, device=3Dunix, type=3DCHANNEL, bootOrder=3D0, specParams=
=3D{}, address=3D{port=3D1, bus=3D0, controller=3D0, type=3Dvirtio-serial},=
managed=3Dfalse, plugged=3Dtrue, readOnly=3Dfalse, deviceAlias=3Dchannel0,=
customProperties=3D{}}', 'device_99b583e9-9030-40af-bb41-55d62a4a6b6adevic=
e_5b94ca77-fab8-41b4-b286-311dee724813device_c3d8dcbf-d977-4d4d-8240-35b973=
ee00b9device_839371b0-1967-4435-910e-0d8e1c980850device_920282ca-79c2-4abf-=
b1f2-7425f16f7820': 'VmDevice {vmId=3D8798d0da-a82c-4bcf-b41a-7e3fe1c613ef,=
deviceId=3D920282ca-79c2-4abf-b1f2-7425f16f7820, device=3Dvirtio-serial, t=
ype=3DCONTROLLER, bootOrder=3D0, specParams=3D{}, address=3D{bus=3D0x00, do=
main=3D0x0000, type=3Dpci, slot=3D0x06, function=3D0x0}, managed=3Dfalse, p=
lugged=3Dtrue, readOnly=3Dfalse, deviceAlias=3Dvirtio-serial0, customProper=
ties=3D{}}', 'device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-fa=
b8-41b4-b286-311dee724813device_c3d8dcbf-d977-4d4d-8240-35b973ee00b9device_=
839371b0-1967-4435-910e-0d8e1c980850': 'VmDevice {vmId=3D8798d0da-a82c-4bcf=
-b41a-7e3fe1c613ef, deviceId=3D839371b0-1967-4435-910e-0d8e1c980850, device=
=3Dide, type=3DCONTROLLER, bootOrder=3D0, specParams=3D{}, address=3D{bus=
=3D0x00, domain=3D0x0000, type=3Dpci, slot=3D0x01, function=3D0x1}, managed=
=3Dfalse, plugged=3Dtrue, readOnly=3Dfalse, deviceAlias=3Dide0, customPrope=
rties=3D{}}', 'device_99b583e9-9030-40af-bb41-55d62a4a6b6adevice_5b94ca77-f=
ab8-41b4-b286-311dee724813': 'VmDevice {vmId=3D8798d0da-a82c-4bcf-b41a-7e3f=
e1c613ef, deviceId=3D5b94ca77-fab8-41b4-b286-311dee724813, device=3Dunix, t=
ype=3DCHANNEL, bootOrder=3D0, specParams=3D{}, address=3D{port=3D2, bus=3D0=
, controller=3D0, type=3Dvirtio-serial}, managed=3Dfalse, plugged=3Dtrue, r=
eadOnly=3Dfalse, deviceAlias=3Dchannel1, customProperties=3D{}}'}, 'vmType'=
: 'kvm', 'memSize': 1024, 'displayIp': '0', 'spiceSecureChannels': 'smain,s=
inputs,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard', 'smpCoresP=
erSocket': '1', 'vmName':<br />'vm01', 'display': 'vnc', 'nice': '0'}}<br /=
>Thread-867486::DEBUG::2013-11-26 14:58:52,519::vm::2019::vm.Vm::(_startUnd=
erlyingVm) vmId=3D`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::_ongoingCreations=
acquired<br />Thread-867486::INFO::2013-11-26 14:58:52,522::vm::2815::vm.V=
m::(_run) vmId=3D`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::VM wrapper has sta=
rted<br />Thread-867486::DEBUG::2013-11-26 14:58:52,527::task::579::TaskMan=
ager.Task::(_updateState) Task=3D`e64eb271-e389-4057-81f7-1148059464d7`::mo=
ving from state init -> state preparing<br />Thread-867486::INFO::2013-1=
1-26 14:58:52,530::logUtils::44::dispatcher::(wrapper) Run and protect: get=
VolumeSize(sdUUID=3D'8c8ad4f8-f187-410c-82a7-2beb79a51a30', spUUID=3D'5849b=
030-626e-47cb-ad90-3ce782d831b3', imgUUID=3D'272b7bb5-38e6-41b3-9da4-4cc278=
873fbf', volUUID=3D'd3011aef-3297-401c-88d7-65079e05dd4d', options=3DNone)<=
br />Thread-867486::DEBUG::2013-11-26 14:58:52,534::lvm::415::OperationMute=
x::(_reloadlvs) Operation 'lvm reload operation' got the operation mutex<br=
/>Thread-867486::DEBUG::2013-11-26 14:58:52,539::lvm::311::Storage.Misc.ex=
cCmd::(cmd) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { preferred_=
names =3D [\\"^/dev/mapper/\\"] ignore_suspended_devices=3D1 write_cache_st=
ate=3D0 disable_after_error_count=3D3 filter =3D [ \'a|/dev/mapper/36001405=
1fd69751de087d46f1da5aadb|/dev/mapper/360014056ce3d140de6a5d4fffd9218da|/de=
v/mapper/360014056db0fc0fdcda7d4a27da043d5|/dev/mapper/36001405917dfc0dd080=
9d41cfd86c9d4|/dev/mapper/3600508b1001cd6f84303d050b8fb5a80|\', \'r|.*|\' ]=
} global { locking_type=3D1 prioritise_write_locks=3D1&n=
bsp; wait_for_locks=3D1 } backup { retain_min =3D 50 reta=
in_days =3D 0 } " --noheadings --units b --nosuffix --separator | -o uuid,n=
ame,vg_name,attr,size,seg_start_pe,devices,tags 8c8ad4f8-f187-410c-82a7-2be=
b79a51a30' (cwd None)<br />Thread-867486::DEBUG::2013-11-26 14:58:52,588::l=
vm::311::Storage.Misc.excCmd::(cmd) SUCCESS: <err> =3D ''; <rc>=
=3D 0<br />Thread-867486::DEBUG::2013-11-26 14:58:52,623::lvm::448::Operat=
ionMutex::(_reloadlvs) Operation 'lvm reload operation' released the operat=
ion mutex<br />Thread-867486::INFO::2013-11-26 14:58:52,623::logUtils::47::=
dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'tr=
uesize': '42949672960', 'apparentsize': '42949672960'}<br />Thread-867486::=
DEBUG::2013-11-26 14:58:52,624::task::1168::TaskManager.Task::(prepare) Tas=
k=3D`e64eb271-e389-4057-81f7-1148059464d7`::finished: {'truesize': '4294967=
2960', 'apparentsize': '42949672960'}<br />Thread-867486::DEBUG::2013-11-26=
14:58:52,624::task::579::TaskManager.Task::(_updateState) Task=3D`e64eb271=
-e389-4057-81f7-1148059464d7`::moving from state preparing -> state fini=
shed<br />Thread-867486::DEBUG::2013-11-26 14:58:52,624::resourceManager::9=
39::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resour=
ces {}<br />Thread-867486::DEBUG::2013-11-26 14:58:52,625::resourceManager:=
:976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<br />T=
hread-867486::DEBUG::2013-11-26 14:58:52,625::task::974::TaskManager.Task::=
(_decref) Task=3D`e64eb271-e389-4057-81f7-1148059464d7`::ref 0 aborting Fal=
se<br />Thread-867486::INFO::2013-11-26 14:58:52,625::clientIF::325::vds::(=
prepareVolumePath) prepared volume path:<br />Thread-867486::DEBUG::2013-11=
-26 14:58:52,626::task::579::TaskManager.Task::(_updateState) Task=3D`e0d90=
71f-a343-400e-865d-81656dd8862b`::moving from state init -> state prepar=
ing<br />Thread-867486::INFO::2013-11-26 14:58:52,626::logUtils::44::dispat=
cher::(wrapper) Run and protect: prepareImage(sdUUID=3D'8c8ad4f8-f187-410c-=
82a7-2beb79a51a30', spUUID=3D'5849b030-626e-47cb-ad90-3ce782d831b3', imgUUI=
D=3D'272b7bb5-38e6-41b3-9da4-4cc278873fbf', volUUID=3D'd3011aef-3297-401c-8=
8d7-65079e05dd4d')<br />Thread-867486::DEBUG::2013-11-26 14:58:52,627::reso=
urceManager::197::ResourceManager.Request::(__init__) ResName=3D`Storage.8c=
8ad4f8-f187-410c-82a7-2beb79a51a30`ReqID=3D`664dc122-58c1-49d1-a03e-faa2182=
f42da`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '3240' at=
'prepareImage'<br />Thread-867486::DEBUG::2013-11-26 14:58:52,627::resourc=
eManager::541::ResourceManager::(registerResource) Trying to register resou=
rce 'Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30' for lock type 'shared'<b=
r />Thread-867486::DEBUG::2013-11-26 14:58:52,628::resourceManager::600::Re=
sourceManager::(registerResource) Resource 'Storage.8c8ad4f8-f187-410c-82a7=
-2beb79a51a30' is free. Now locking as 'shared' (1 active user)<br />Thread=
-867486::DEBUG::2013-11-26 14:58:52,628::resourceManager::237::ResourceMana=
ger.Request::(grant) ResName=3D`Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a3=
0`ReqID=3D`664dc122-58c1-49d1-a03e-faa2182f42da`::Granted request<br />Thre=
ad-867486::DEBUG::2013-11-26 14:58:52,629::task::811::TaskManager.Task::(re=
sourceAcquired) Task=3D`e0d9071f-a343-400e-865d-81656dd8862b`::_resourcesAc=
quired: Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30 (shared)<br />Thread-8=
67486::DEBUG::2013-11-26 14:58:52,629::task::974::TaskManager.Task::(_decre=
f) Task=3D`e0d9071f-a343-400e-865d-81656dd8862b`::ref 1 aborting False<br /=
>Thread-867486::DEBUG::2013-11-26 14:58:52,635::blockVolume::588::Storage.M=
isc.excCmd::(getMetadata) '/bin/dd iflag=3Ddirect skip=3D23 bs=3D512 if=3D/=
dev/8c8ad4f8-f187-410c-82a7-2beb79a51a30/metadata count=3D1' (cwd None)<br =
/>Thread-867486::DEBUG::2013-11-26 14:58:52,644::blockVolume::588::Storage.=
Misc.excCmd::(getMetadata) SUCCESS: <err> =3D '1+0 records in\n1+0 re=
cords out\n512 bytes (512 B) copied, 0.000281928 s, 1.8 MB/s\n'; <rc>=
=3D 0<br />Thread-867486::DEBUG::2013-11-26 14:58:52,644::misc::288::Stora=
ge.Misc::(validateDDBytes) err: ['1+0 records in', '1+0 records out', '512 =
bytes (512 B) copied, 0.000281928 s, 1.8 MB/s'], size: 512<br />Thread-8674=
86::INFO::2013-11-26 14:58:52,645::image::215::Storage.Image::(getChain) sd=
UUID=3D8c8ad4f8-f187-410c-82a7-2beb79a51a30 imgUUID=3D272b7bb5-38e6-41b3-9d=
a4-4cc278873fbf chain=3D[<storage.blockVolume.BlockVolume object at 0x14=
f6ad0>]<br />Thread-867486::DEBUG::2013-11-26 14:58:52,646::lvm::311::St=
orage.Misc.excCmd::(cmd) '/usr/bin/sudo -n /sbin/lvm lvchange --config " de=
vices { preferred_names =3D [\\"^/dev/mapper/\\"] ignore_suspended_devices=
=3D1 write_cache_state=3D0 disable_after_error_count=3D3 filter =3D [ \'a|/=
dev/mapper/360014051fd69751de087d46f1da5aadb|/dev/mapper/360014056ce3d140de=
6a5d4fffd9218da|/dev/mapper/360014056db0fc0fdcda7d4a27da043d5|/dev/mapper/3=
6001405917dfc0dd0809d41cfd86c9d4|/dev/mapper/3600508b1001cd6f84303d050b8fb5=
a80|\', \'r|.*|\' ] } global { locking_type=3D1 prioritis=
e_write_locks=3D1 wait_for_locks=3D1 } backup { retain_mi=
n =3D 50 retain_days =3D 0 } " --autobackup n --available y 8c8ad4f8-=
f187-410c-82a7-2beb79a51a30/d3011aef-3297-401c-88d7-65079e05dd4d' (cwd None=
)<br />Thread-867486::DEBUG::2013-11-26 14:58:52,942::lvm::311::Storage.Mis=
c.excCmd::(cmd) SUCCESS: <err> =3D ''; <rc> =3D 0<br />Thread-8=
67486::DEBUG::2013-11-26 14:58:52,943::lvm::499::OperationMutex::(_invalida=
telvs) Operation 'lvm invalidate operation' got the operation mutex<br />Th=
read-867486::DEBUG::2013-11-26 14:58:52,943::lvm::511::OperationMutex::(_in=
validatelvs) Operation 'lvm invalidate operation' released the operation mu=
tex<br />Thread-867486::DEBUG::2013-11-26 14:58:52,943::lvm::415::Operation=
Mutex::(_reloadlvs) Operation 'lvm reload operation' got the operation mute=
x<br />Thread-867486::DEBUG::2013-11-26 14:58:52,944::lvm::311::Storage.Mis=
c.excCmd::(cmd) '/usr/bin/sudo -n /sbin/lvm lvs --config " devices { prefer=
red_names =3D [\\"^/dev/mapper/\\"] ignore_suspended_devices=3D1 write_cach=
e_state=3D0 disable_after_error_count=3D3 filter =3D [ \'a|/dev/mapper/3600=
14051fd69751de087d46f1da5aadb|/dev/mapper/360014056ce3d140de6a5d4fffd9218da=
|/dev/mapper/360014056db0fc0fdcda7d4a27da043d5|/dev/mapper/36001405917dfc0d=
d0809d41cfd86c9d4|/dev/mapper/3600508b1001cd6f84303d050b8fb5a80|\', \'r|.*|=
\' ] } global { locking_type=3D1 prioritise_write_locks=
=3D1 wait_for_locks=3D1 } backup { retain_min =3D 50 =
; retain_days =3D 0 } " --noheadings --units b --nosuffix --separator | -o =
uuid,name,vg_name,attr,size,seg_start_pe,devices,tags 8c8ad4f8-f187-410c-82=
a7-2beb79a51a30' (cwd None)<br />Thread-867486::DEBUG::2013-11-26 14:58:53,=
242::lvm::311::Storage.Misc.excCmd::(cmd) SUCCESS: <err> =3D ''; <=
rc> =3D 0<br />Thread-867486::DEBUG::2013-11-26 14:58:53,277::lvm::448::=
OperationMutex::(_reloadlvs) Operation 'lvm reload operation' released the =
operation mutex<br />Thread-867486::DEBUG::2013-11-26 14:58:53,283::blockVo=
lume::588::Storage.Misc.excCmd::(getMetadata) '/bin/dd iflag=3Ddirect skip=
=3D23 bs=3D512 if=3D/dev/8c8ad4f8-f187-410c-82a7-2beb79a51a30/metadata coun=
t=3D1' (cwd None)<br />Thread-867486::DEBUG::2013-11-26 14:58:53,292::block=
Volume::588::Storage.Misc.excCmd::(getMetadata) SUCCESS: <err> =3D '1=
+0 records in\n1+0 records out\n512 bytes (512 B) copied, 0.000298328 s, 1.=
7 MB/s\n'; <rc> =3D 0<br />Thread-867486::DEBUG::2013-11-26 14:58:53,=
292::misc::288::Storage.Misc::(validateDDBytes) err: ['1+0 records in', '1+=
0 records out', '512 bytes (512 B) copied, 0.000298328 s, 1.7 MB/s'], size:=
512<br />Thread-867486::INFO::2013-11-26 14:58:53,293::logUtils::47::dispa=
tcher::(wrapper) Run and protect: prepareImage, Return response: {'info': {=
'path': '/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f1=
87-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011=
aef-3297-401c-88d7-65079e05dd4d', 'volType': 'path'}, 'path': '/rhev/data-c=
enter/5849b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a5=
1a30/images/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65=
079e05dd4d', 'chain': [{'path': '/rhev/data-center/5849b030-626e-47cb-ad90-=
3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3=
-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65079e05dd4d', 'domainID': '8c8a=
d4f8-f187-410c-82a7-2beb79a51a30', 'vmVolInfo': {'path': '/rhev/data-center=
/5849b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/=
images/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65079e0=
5dd4d', 'volType': 'path'}, 'volumeID': 'd3011aef-3297-401c-88d7-65079e05dd=
4d', 'imageID': '272b7bb5-38e6-41b3-9da4-4cc278873fbf'}]}<br />Thread-86748=
6::DEBUG::2013-11-26 14:58:53,293::task::1168::TaskManager.Task::(prepare) =
Task=3D`e0d9071f-a343-400e-865d-81656dd8862b`::finished: {'info': {'path': =
'/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-=
82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297=
-401c-88d7-65079e05dd4d', 'volType': 'path'}, 'path': '/rhev/data-center/58=
49b030-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/ima=
ges/272b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65079e05dd=
4d', 'chain': [{'path': '/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d8=
31b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4c=
c278873fbf/d3011aef-3297-401c-88d7-65079e05dd4d', 'domainID': '8c8ad4f8-f18=
7-410c-82a7-2beb79a51a30', 'vmVolInfo': {'path': '/rhev/data-center/5849b03=
0-626e-47cb-ad90-3ce782d831b3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/images/2=
72b7bb5-38e6-41b3-9da4-4cc278873fbf/d3011aef-3297-401c-88d7-65079e05dd4d', =
'volType': 'path'}, 'volumeID': 'd3011aef-3297-401c-88d7-65079e05dd4d', 'im=
ageID': '272b7bb5-38e6-41b3-9da4-4cc278873fbf'}]}<br />Thread-867486::DEBUG=
::2013-11-26 14:58:53,293::task::579::TaskManager.Task::(_updateState) Task=
=3D`e0d9071f-a343-400e-865d-81656dd8862b`::moving from state preparing ->=
; state finished<br />Thread-867486::DEBUG::2013-11-26 14:58:53,294::resour=
ceManager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll reques=
ts {} resources {'Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30': < Resou=
rceRef 'Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30', isValid: 'True' obj:=
'None'>}<br />Thread-867486::DEBUG::2013-11-26 14:58:53,294::resourceMa=
nager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}<=
br />Thread-867486::DEBUG::2013-11-26 14:58:53,294::resourceManager::615::R=
esourceManager::(releaseResource) Trying to release resource 'Storage.8c8ad=
4f8-f187-410c-82a7-2beb79a51a30'<br />Thread-867486::DEBUG::2013-11-26 14:5=
8:53,295::resourceManager::634::ResourceManager::(releaseResource) Released=
resource 'Storage.8c8ad4f8-f187-410c-82a7-2beb79a51a30' (0 active users)<b=
r />Thread-867486::DEBUG::2013-11-26 14:58:53,295::resourceManager::640::Re=
sourceManager::(releaseResource) Resource 'Storage.8c8ad4f8-f187-410c-82a7-=
2beb79a51a30' is free, finding out if anyone is waiting for it.<br />Thread=
-867486::DEBUG::2013-11-26 14:58:53,295::resourceManager::648::ResourceMana=
ger::(releaseResource) No one is waiting for resource 'Storage.8c8ad4f8-f18=
7-410c-82a7-2beb79a51a30', Clearing records.<br />Thread-867486::DEBUG::201=
3-11-26 14:58:53,296::task::974::TaskManager.Task::(_decref) Task=3D`e0d907=
1f-a343-400e-865d-81656dd8862b`::ref 0 aborting False<br />Thread-867486::I=
NFO::2013-11-26 14:58:53,296::clientIF::325::vds::(prepareVolumePath) prepa=
red volume path: /rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b3/8c8=
ad4f8-f187-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4cc278873f=
bf/d3011aef-3297-401c-88d7-65079e05dd4d<br />Thread-867486::DEBUG::2013-11-=
26 14:58:53,318::utils::486::root::(execCmd) '/usr/libexec/vdsm/hooks/befor=
e_vm_start/50_smbios' (cwd None)<br />Thread-867486::DEBUG::2013-11-26 14:5=
8:53,400::utils::505::root::(execCmd) SUCCESS: <err> =3D ''; <rc&g=
t; =3D 0<br />Thread-867486::INFO::2013-11-26 14:58:53,401::hooks::88::root=
::(_runHooksDir)<br />Thread-867486::DEBUG::2013-11-26 14:58:53,401::vm::28=
72::vm.Vm::(_run) vmId=3D`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::<?xml v=
ersion=3D"1.0" encoding=3D"utf-8"?><br /><domain type=3D"kvm"><br =
/> <name>vm01</name><=
br /> <uuid>8798d0da-a82c-4=
bcf-b41a-7e3fe1c613ef</uuid><br />  =
; <memory>1048576</memory><br /> &=
nbsp; <currentMemory>1048576</currentMemory><br />&=
nbsp; <vcpu>1</vcpu><br />&=
nbsp; <memtune><br /> =
&nb=
sp; <min_guarantee>524288</min_guarantee><br /> &nbs=
p; </memtune><br /> &n=
bsp; <devices><br /> &=
nbsp; <channel type=3D"u=
nix"><br /> &=
nbsp; &nbs=
p; <target name=3D"com.redhat.rhevm.vdsm" type=3D"virtio"/><br />&nbs=
p; &=
nbsp; <source mode=
=3D"bind" path=3D"/var/lib/libvirt/qemu/channels/8798d0da-a82c-4bcf-b41a-7e=
3fe1c613ef.com.redhat.rhevm.vdsm"/><br /> &=
nbsp; </channel>=
;<br /> &n=
bsp; <channel type=3D"unix"><br />  =
; &n=
bsp; <target name=3D"org.qemu.=
guest_agent.0" type=3D"virtio"/><br /> &nbs=
p; &=
nbsp; <source mode=3D"bind" path=3D"/var/lib/lib=
virt/qemu/channels/8798d0da-a82c-4bcf-b41a-7e3fe1c613ef.org.qemu.guest_agen=
t.0"/><br /> =
</channel><br /> &nbs=
p; <in=
put bus=3D"usb" type=3D"tablet"/><br /> &nb=
sp; <graphics auto=
port=3D"yes" keymap=3D"de" listen=3D"0" passwd=3D"*****" passwdValidTo=3D"1=
970-01-01T00:00:01" port=3D"-1" type=3D"vnc"/><br /> &n=
bsp; <=
video><br /> =
&nb=
sp; <address bus=3D"0x00" domain=3D"0x0000" function=3D"0x0" slot=3D"0x0=
2" type=3D"pci"/><br /> &=
nbsp; &nbs=
p; <model heads=3D"1" type=3D"cirrus" vram=3D"65536"/><br=
/> =
</video><br /> =
<interface type=
=3D"bridge"><br /> =
&nb=
sp; <address bus=3D"0x00" domain=3D"0x0000" function=3D"0x0" slot=
=3D"0x03" type=3D"pci"/><br /> =
&nb=
sp; <mac address=3D"52:54:00:6d:ce:c8"/><br /> =
; &n=
bsp; <model type=
=3D"virtio"/><br />  =
; &n=
bsp; <source bridge=3D"VM"/><br />  =
; &n=
bsp; <filterref filter=3D"vdsm-no-mac-spoo=
fing"/><br />  =
; &n=
bsp; <link state=3D"up"/><br /> &n=
bsp; </interface><br =
/> &=
nbsp; <disk device=3D"cdrom" snapshot=3D"no" type=3D"file"&g=
t;<br /> &=
nbsp; <=
;address bus=3D"1" controller=3D"0" target=3D"0" type=3D"drive" unit=3D"0"/=
><br />  =
; &=
lt;source file=3D"" startupPolicy=3D"optional"/><br /> =
&nb=
sp; <target bus=3D"ide" dev=3D=
"hdc"/><br />  =
; &n=
bsp; <readonly/><br />  =
; &n=
bsp; <serial/><br /> &=
nbsp; </disk><br />&n=
bsp;  =
; <disk device=3D"disk" snapshot=3D"no" type=3D"block"><b=
r />  =
; <add=
ress bus=3D"0x00" domain=3D"0x0000" function=3D"0x0" slot=3D"0x05" type=3D"=
pci"/><br /> =
&nb=
sp; <source dev=3D"/rhev/data-center/5849b030-626e-47cb-ad90-3ce782d831b=
3/8c8ad4f8-f187-410c-82a7-2beb79a51a30/images/272b7bb5-38e6-41b3-9da4-4cc27=
8873fbf/d3011aef-3297-401c-88d7-65079e05dd4d"/><br /> &=
nbsp; &nbs=
p; <target bus=3D"virtio" dev=
=3D"vda"/><br /> &n=
bsp;  =
; <serial>272b7bb5-38e6-41b3-9da4-4cc278873fbf</serial><b=
r />  =
; <boo=
t order=3D"1"/><br /> &nb=
sp; =
<driver cache=3D"none" error_policy=3D"stop" io=3D"native" =
name=3D"qemu" type=3D"raw"/><br /> &n=
bsp; </disk><br />&nb=
sp; =
<memballoon model=3D"none"/><br /> &nbs=
p; </devices><br /> &n=
bsp; <os><br /> =
<type arch=3D"x86_64" machine=
=3D"rhel6.4.0">hvm</type><br />  =
; <smbios mode=3D"=
sysinfo"/><br /> </os><b=
r /> <sysinfo type=3D"smbios"&=
gt;<br /> =
<system><br /> =
&nb=
sp; <entry name=3D"manufacturer">oVirt&=
lt;/entry><br /> &n=
bsp;  =
; <entry name=3D"product">oVirt Node</entry><br /> &=
nbsp; &nbs=
p; <entry name=3D"=
version">6-4.el6.centos.10</entry><br /> &n=
bsp;  =
; <entry name=3D"serial">32393735=
-3933-5A43-4A32-34333046564B</entry><br /> &nb=
sp; =
<entry name=3D"uuid">8798d0da-a8=
2c-4bcf-b41a-7e3fe1c613ef</entry><br /> =
</system>=
;<br /> </sysinfo><br />&nb=
sp; <clock adjustment=3D"1" offset=
=3D"variable"><br /> &nbs=
p; <timer name=3D"rtc" tickpolicy=3D=
"catchup"/><br /> </clock&g=
t;<br /> <features><br />&n=
bsp;  =
; <acpi/><br /> =
</features><br /> <cpu =
match=3D"exact"><br /> &n=
bsp; <model>Nehalem</model>=
<br /> &nb=
sp; <topology cores=3D"1" sockets=3D"1" threads=3D"1"/=
><br /> </cpu><br /><=
/domain><br /><br />Thread-166407::DEBUG::2013-11-26 14:58:53,588::block=
SD::594::Storage.Misc.excCmd::(getReadDelay) '/bin/dd iflag=3Ddirect if=3D/=
dev/8c8ad4f8-f187-410c-82a7-2beb79a51a30/metadata bs=3D4096 count=3D1' (cwd=
None)<br />Thread-166407::DEBUG::2013-11-26 14:58:53,599::blockSD::594::St=
orage.Misc.excCmd::(getReadDelay) SUCCESS: <err> =3D '1+0 records in\=
n1+0 records out\n4096 bytes (4.1 kB) copied, 0.000345562 s, 11.9 MB/s\n'; =
<rc> =3D 0<br />Thread-24::DEBUG::2013-11-26 14:58:53,791::fileSD::23=
8::Storage.Misc.excCmd::(getReadDelay) '/bin/dd iflag=3Ddirect<br />if=3D/r=
hev/data-center/mnt/engine.privat.com:_export_VMs/48055e27-f1ca-466a-8a2c-e=
191c34f0226/dom_md/metadata bs=3D4096 count=3D1' (cwd None)<br />Thread-24:=
:DEBUG::2013-11-26 14:58:53,801::fileSD::238::Storage.Misc.excCmd::(getRead=
Delay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n349 bytes=
(349 B) copied, 0.000683955 s, 510 kB/s\n'; <rc> =3D 0<br />libvirtE=
ventLoop::DEBUG::2013-11-26 14:58:54,094::vm::4724::vm.Vm::(_onLibvirtLifec=
ycleEvent) vmId=3D`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::event Started det=
ail 0 opaque None<br />Thread-867486::DEBUG::2013-11-26 14:58:54,248::sampl=
ing::285::vm.Vm::(start) vmId=3D`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::Sta=
rt statistics collection<br />Thread-867488::DEBUG::2013-11-26 14:58:54,249=
::sampling::314::vm.Vm::(run) vmId=3D`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`=
::Stats thread started<br />Thread-867486::DEBUG::2013-11-26 14:58:54,251::=
vmChannels::194::vds::(register) Add fileno 51 to listener's channels.<br /=
>Thread-867488::DEBUG::2013-11-26 14:58:54,253::task::579::TaskManager.Task=
::(_updateState) Task=3D`c5c6d816-7de8-4ab5-a5fa-a3fba225d797`::moving from=
state init -> state preparing<br />Thread-867488::INFO::2013-11-26 14:5=
8:54,253::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSiz=
e(sdUUID=3D'8c8ad4f8-f187-410c-82a7-2beb79a51a30', spUUID=3D'5849b030-626e-=
47cb-ad90-3ce782d831b3', imgUUID=3D'272b7bb5-38e6-41b3-9da4-4cc278873fbf', =
volUUID=3D'd3011aef-3297-401c-88d7-65079e05dd4d', options=3DNone)<br />Thre=
ad-867486::WARNING::2013-11-26 14:58:54,253::vm::3326::vm.Vm::(_readPauseCo=
de) vmId=3D`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::_readPauseCode unsupport=
ed by libvirt vm<br />Thread-867488::INFO::2013-11-26 14:58:54,255::logUtil=
s::47::dispatcher::(wrapper) Run and protect: getVolumeSize, Return respons=
e: {'truesize': '42949672960', 'apparentsize': '42949672960'}<br />Thread-8=
67488::DEBUG::2013-11-26 14:58:54,256::task::1168::TaskManager.Task::(prepa=
re) Task=3D`c5c6d816-7de8-4ab5-a5fa-a3fba225d797`::finished: {'truesize': '=
42949672960', 'apparentsize': '42949672960'}<br />Thread-867488::DEBUG::201=
3-11-26 14:58:54,256::task::579::TaskManager.Task::(_updateState) Task=3D`c=
5c6d816-7de8-4ab5-a5fa-a3fba225d797`::moving from state preparing -> sta=
te finished<br />Thread-867488::DEBUG::2013-11-26 14:58:54,256::resourceMan=
ager::939::ResourceManager.Owner::(releaseAll) Owner.releaseAll requests {}=
resources {}<br />Thread-867488::DEBUG::2013-11-26 14:58:54,257::resourceM=
anager::976::ResourceManager.Owner::(cancelAll) Owner.cancelAll requests {}=
<br />Thread-867488::DEBUG::2013-11-26 14:58:54,257::task::974::TaskManager=
.Task::(_decref) Task=3D`c5c6d816-7de8-4ab5-a5fa-a3fba225d797`::ref 0 abort=
ing False<br />Thread-867486::DEBUG::2013-11-26 14:58:54,263::vm::2036::vm.=
Vm::(_startUnderlyingVm) vmId=3D`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::_on=
goingCreations released<br />VM Channels Listener::DEBUG::2013-11-26 14:58:=
54,694::vmChannels::102::vds::(_do_add_channels) fileno 51 was added to unc=
onnected channels.<br />VM Channels Listener::DEBUG::2013-11-26 14:58:54,69=
4::vmChannels::128::vds::(_handle_unconnected) Trying to connect fileno 51.=
<br />VM Channels Listener::DEBUG::2013-11-26 14:58:54,695::guestIF::147::v=
m.Vm::(_connect) vmId=3D`8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::Attempting =
connection to /var/lib/libvirt/qemu/channels/8798d0da-a82c-4bcf-b41a-7e3fe1=
c613ef.com.redhat.rhevm.vdsm<br />VM Channels Listener::DEBUG::2013-11-26 1=
4:58:54,695::guestIF::150::vm.Vm::(_connect) vmId=3D`8798d0da-a82c-4bcf-b41=
a-7e3fe1c613ef`::Connected to /var/lib/libvirt/qemu/channels/8798d0da-a82c-=
4bcf-b41a-7e3fe1c613ef.com.redhat.rhevm.vdsm<br />VM Channels Listener::DEB=
UG::2013-11-26 14:58:54,695::vmChannels::144::vds::(_handle_unconnected) Co=
nnecting to fileno 51 succeeded.<br />Thread-867490::DEBUG::2013-11-26 14:5=
8:55,170::BindingXMLRPC::979::vds::(wrapper) client [192.168.1.29]::call vm=
GetStats with ('8798d0da-a82c-4bcf-b41a-7e3fe1c613ef',) {}<br />Thread-8674=
90::DEBUG::2013-11-26 14:58:55,170::vm::579::vm.Vm::(_getCpuStats) vmId=3D`=
8798d0da-a82c-4bcf-b41a-7e3fe1c613ef`::CPU stats not available: 'NoneType' =
object is unsubscriptable<br />Thread-867490::DEBUG::2013-11-26 14:58:55,17=
0::vm::613::vm.Vm::(_getNetworkStats) vmId=3D`8798d0da-a82c-4bcf-b41a-7e3fe=
1c613ef`::Network stats not available</span></span>
--========GMXBoundary242171385563631782200--
2
1
Blaster schreef op 27-11-2013 17:23:
> On 11/27/2013 4:24 AM, Martijn Grendelman wrote:
>> The problem with snapshot-based backups is, that they are usually only
>> crash-consistent, meaning that they contain the state of a system's
>> disks as they would be if you pulled the power plug on a server. If
>> you restore a system from this type of backup, you would see file
>> system recovery happening at the first boot, and you risk data loss
>> from -for example- database servers.
>
> The work-around for this is to SSH into the guest first, put the
> database into backup mode(maybe run sync a time or two to flush out as
> much from RAM as possible), take the snap shot, ssh back in to resume
> the database, backup the snap, delete the snap.
Yes, for example for MySQL, you could
1. issue a FLUSH TABLES WITH READ LOCK statement
2. create a snapshot
3. issue a UNLOCK TABLES statement
before starting a backup from the snapshot, to get a consistent backup
of the binary table space.
Cheers,
Martijn.
1
0
Hi,
anybody can report about PPC status for 3.3.2 and 3.4.0 target releases?
It would be nice having someone for PPC at ovirt-sync meeting from next week on, so please join :-)
Thanks,
--
Sandro Bonazzola
Better technology. Faster innovation. Powered by community collaboration.
See how it works at redhat.com
1
0