- Users - oVirt List Archives

[Users] Migration failed (previous migrations succeded)
by Markus Stockhausen 04 Feb '14

04 Feb '14

This is a multi-part message in MIME format. ------=_NextPartTM-000-16e476a9-dc0a-459b-91a5-33c52e66e68f Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: quoted-printable Hello,=0A= =0A= we did some migration tests this day and all of a sudden the migration=0A= failed. That particular VM was moved around several times that day without= =0A= any problems. During the migration the VM was running a download.=0A= =0A= The logs are attached. If you need more, do not hesitate to ask.=0A= =0A= Thanks in advance.=0A= =0A= Markus=0A= =0A= **************************=0A= web log:=0A= =0A= 2014-Jan-30, 16:17 Migration failed due to Error: Migration not in progress= (VM: Win7x64_Master, Source: colovn02, Destination: colovn04).=0A= 2014-Jan-30, 16:11 Migration started (VM: Win7x64_Master, Source: colovn02,= Destination: colovn04, User: hil1).=0A= 2014-Jan-30, 16:10 Migration completed (VM: Win7x64_Master, Source: colovn0= 4, Destination: colovn02, Duration: 52 sec).=0A= 2014-Jan-30, 16:05 Migration started (VM: Win7x64_Master, Source: colovn04,= Destination: colovn02, User: hil1).=0A= 2014-Jan-30, 16:04 Migration completed (VM: Win7x64_Master, Source: colovn0= 3, Destination: colovn04, Duration: 24 sec).=0A= 2014-Jan-30, 16:01 Migration started (VM: Win7x64_Master, Source: colovn03,= Destination: colovn04, User: hil1).=0A= =0A= **************************=0A= Engine=0A= =0A= 2014-01-30 16:17:31,871 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRun= TimeInfo] (DefaultQuartzScheduler_Worker-97) RefreshVmList vm id ce64f528-9= 981-4ec6-a172-9d70a00a34cd status =3D Paused on vds colovn04 ignoring it in= the refresh until migration is done=0A= 2014-01-30 16:17:34,955 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRun= TimeInfo] (DefaultQuartzScheduler_Worker-96) RefreshVmList vm id ce64f528-9= 981-4ec6-a172-9d70a00a34cd status =3D Paused on vds colovn04 ignoring it in= the refresh until migration is done=0A= 2014-01-30 16:17:38,067 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRun= TimeInfo] (DefaultQuartzScheduler_Worker-2) RefreshVmList vm id ce64f528-99= 81-4ec6-a172-9d70a00a34cd status =3D Paused on vds colovn04 ignoring it in = the refresh until migration is done=0A= 2014-01-30 16:17:41,147 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRun= TimeInfo] (DefaultQuartzScheduler_Worker-100) RefreshVmList vm id ce64f528-= 9981-4ec6-a172-9d70a00a34cd status =3D Paused on vds colovn04 ignoring it i= n the refresh until migration is done=0A= 2014-01-30 16:17:44,268 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRun= TimeInfo] (DefaultQuartzScheduler_Worker-88) RefreshVmList vm id ce64f528-9= 981-4ec6-a172-9d70a00a34cd status =3D Paused on vds colovn04 ignoring it in= the refresh until migration is done=0A= 2014-01-30 16:17:46,440 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRun= TimeInfo] (DefaultQuartzScheduler_Worker-13) VM Win7x64_Master ce64f528-998= 1-4ec6-a172-9d70a00a34cd moved from MigratingFrom --> Up=0A= 2014-01-30 16:17:46,444 INFO [org.ovirt.engine.core.vdsbroker.VdsUpdateRun= TimeInfo] (DefaultQuartzScheduler_Worker-13) Adding VM ce64f528-9981-4ec6-a= 172-9d70a00a34cd to re-run list=0A= 2014-01-30 16:17:46,456 ERROR [org.ovirt.engine.core.vdsbroker.VdsUpdateRun= TimeInfo] (DefaultQuartzScheduler_Worker-13) Rerun vm ce64f528-9981-4ec6-a1= 72-9d70a00a34cd. Called from vds colovn02=0A= 2014-01-30 16:17:46,475 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.Mi= grateStatusVDSCommand] (pool-6-thread-48) START, MigrateStatusVDSCommand(Ho= stName =3D colovn02, HostId =3D 1303e86e-cd91-406b-8a27-e75ef0a9defb, vmId= =3Dce64f528-9981-4ec6-a172-9d70a00a34cd), log id: 91bccfb=0A= 2014-01-30 16:17:46,485 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.Mi= grateStatusVDSCommand] (pool-6-thread-48) Failed in MigrateStatusVDS method= =0A= 2014-01-30 16:17:46,488 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.Mi= grateStatusVDSCommand] (pool-6-thread-48) Error code MIGRATION_CANCEL_ERROR= and error message VDSGenericException: VDSErrorException: Failed to Migrat= eStatusVDS, error =3D Migration canceled=0A= 2014-01-30 16:17:46,492 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.Mi= grateStatusVDSCommand] (pool-6-thread-48) Command org.ovirt.engine.core.vds= broker.vdsbroker.MigrateStatusVDSCommand return value=0A= StatusOnlyReturnForXmlRpc [mStatus=3DStatusForXmlRpc [mCode=3D47, mMessage= =3DMigration canceled]]=0A= 2014-01-30 16:17:46,495 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.Mi= grateStatusVDSCommand] (pool-6-thread-48) HostName =3D colovn02=0A= 2014-01-30 16:17:46,508 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.Mi= grateStatusVDSCommand] (pool-6-thread-48) Command MigrateStatusVDS executio= n failed. Exception: VDSErrorException: VDSGenericException: VDSErrorExcept= ion: Failed to MigrateStatusVDS, error =3D Migration canceled=0A= 2014-01-30 16:17:46,511 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.Mi= grateStatusVDSCommand] (pool-6-thread-48) FINISH, MigrateStatusVDSCommand, = log id: 91bccfb=0A= 2014-01-30 16:17:46,522 INFO [org.ovirt.engine.core.dal.dbbroker.auditlogh= andling.AuditLogDirector] (pool-6-thread-48) Correlation ID: 71aa9786, Job = ID: 4f805590-135a-49a6-871a-91389ae99d9a, Call Stack: null, Custom Event ID= : -1, Message: Migration failed due to Error: Migration not in progress (VM= : Win7x64_Master, Source: colovn02, Destination: colovn04).=0A= 2014-01-30 16:18:27,016 INFO [org.ovirt.engine.core.bll.MigrateVmToServerC= ommand] (ajp--127.0.0.1-8702-2) [5fed7321] Failed to Acquire Lock to object= EngineLock [exclusiveLocks=3D key: ce64f528-9981-4ec6-a172-9d70a00a34cd va= lue: VM=0A= , sharedLocks=3D ]=0A= 2014-01-30 16:18:27,020 WARN [org.ovirt.engine.core.bll.MigrateVmToServerC= ommand] (ajp--127.0.0.1-8702-2) [5fed7321] CanDoAction of action MigrateVmT= oServer failed. Reasons:VAR__ACTION__MIGRATE,VAR__TYPE__VM,ACTION_TYPE_FAIL= ED_VM_IS_BEING_MIGRATED,$VmName Win7x64_Master=0A= 2014-01-30 16:18:56,318 INFO [org.ovirt.engine.core.bll.MigrateVmToServerC= ommand] (ajp--127.0.0.1-8702-12) [4b6f62e9] Failed to Acquire Lock to objec= t EngineLock [exclusiveLocks=3D key: ce64f528-9981-4ec6-a172-9d70a00a34cd v= alue: VM=0A= =0A= **************************=0A= vdsm_source:=0A= =0A= Thread-290096::DEBUG::2014-01-30 16:17:04,874::task::1168::TaskManager.Task= ::(prepare) Task=3D`d313ee92-9094-49ad-8850-fbb6df383a22`::finished: {'2c51= d320-88ce-4f23-8215-e15f55f66906': {'delay': '0.000176962', 'lastCheck': '1= .8', 'code': 0, 'valid': True, 'version': 3}, '965ca3b6-4f9c-4e81-b6e8-5ed4= a9e58545': {'delay': '0.000154703', 'lastCheck': '8.0', 'code': 0, 'valid':= True, 'version': 3}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'delay': '0.= 000147093', 'lastCheck': '7.5', 'code': 0, 'valid': True, 'version': 0}, '6= 3041fa9-e093-4b44-b36f-f39f16d3974f': {'delay': '0.000179083', 'lastCheck':= '7.1', 'code': 0, 'valid': True, 'version': 0}, '272ec473-6041-42ee-bd1a-7= 32789dd18d4': {'delay': '0.000224103', 'lastCheck': '6.3', 'code': 0, 'vali= d': True, 'version': 3}}=0A= Thread-290096::DEBUG::2014-01-30 16:17:04,874::task::579::TaskManager.Task:= :(_updateState) Task=3D`d313ee92-9094-49ad-8850-fbb6df383a22`::moving from = state preparing -> state finished=0A= Thread-290096::DEBUG::2014-01-30 16:17:04,874::resourceManager::939::Resour= ceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}=0A= Thread-290096::DEBUG::2014-01-30 16:17:04,874::resourceManager::976::Resour= ceManager.Owner::(cancelAll) Owner.cancelAll requests {}=0A= Thread-290096::DEBUG::2014-01-30 16:17:04,874::task::974::TaskManager.Task:= :(_decref) Task=3D`d313ee92-9094-49ad-8850-fbb6df383a22`::ref 0 aborting Fa= lse=0A= Thread-289929::WARNING::2014-01-30 16:17:05,585::vm::800::vm.Vm::(run) vmId= =3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Migration stalling: dataRemainin= g (24MiB) > smallest_dataRemaining (9MiB). Refer to RHBZ#919201.=0A= Thread-289929::INFO::2014-01-30 16:17:05,585::vm::812::vm.Vm::(run) vmId=3D= `ce64f528-9981-4ec6-a172-9d70a00a34cd`::Migration Progress: 360 seconds ela= psed, 99% of data processed, 99% of mem processed=0A= Thread-26::DEBUG::2014-01-30 16:17:06,907::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-26::DEBUG::2014-01-30 16:17:06,913::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000192548 s, 2.9 MB/s\n'; <rc> =3D 0=0A= Thread-27::DEBUG::2014-01-30 16:17:07,394::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-27::DEBUG::2014-01-30 16:17:07,400::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n357 b= ytes (357 B) copied, 0.000213713 s, 1.7 MB/s\n'; <rc> =3D 0=0A= Thread-33::DEBUG::2014-01-30 16:17:07,771::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-33::DEBUG::2014-01-30 16:17:07,778::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n363 b= ytes (363 B) copied, 0.000190935 s, 1.9 MB/s\n'; <rc> =3D 0=0A= Thread-38::DEBUG::2014-01-30 16:17:08,586::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-38::DEBUG::2014-01-30 16:17:08,593::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000184154 s, 3.0 MB/s\n'; <rc> =3D 0=0A= Thread-25::DEBUG::2014-01-30 16:17:13,044::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-25::DEBUG::2014-01-30 16:17:13,050::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n645 b= ytes (645 B) copied, 0.00017907 s, 3.6 MB/s\n'; <rc> =3D 0=0A= Thread-289929::WARNING::2014-01-30 16:17:15,586::vm::800::vm.Vm::(run) vmId= =3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Migration stalling: dataRemainin= g (16MiB) > smallest_dataRemaining (9MiB). Refer to RHBZ#919201.=0A= Thread-289929::INFO::2014-01-30 16:17:15,587::vm::812::vm.Vm::(run) vmId=3D= `ce64f528-9981-4ec6-a172-9d70a00a34cd`::Migration Progress: 370 seconds ela= psed, 99% of data processed, 99% of mem processed=0A= Thread-26::DEBUG::2014-01-30 16:17:16,923::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-26::DEBUG::2014-01-30 16:17:16,929::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000248981 s, 2.2 MB/s\n'; <rc> =3D 0=0A= Thread-27::DEBUG::2014-01-30 16:17:17,412::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-27::DEBUG::2014-01-30 16:17:17,418::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n357 b= ytes (357 B) copied, 0.000252188 s, 1.4 MB/s\n'; <rc> =3D 0=0A= Thread-33::DEBUG::2014-01-30 16:17:17,789::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-33::DEBUG::2014-01-30 16:17:17,796::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n363 b= ytes (363 B) copied, 0.000203099 s, 1.8 MB/s\n'; <rc> =3D 0=0A= Thread-38::DEBUG::2014-01-30 16:17:18,604::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-38::DEBUG::2014-01-30 16:17:18,611::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000177334 s, 3.1 MB/s\n'; <rc> =3D 0=0A= Thread-290102::DEBUG::2014-01-30 16:17:20,057::task::579::TaskManager.Task:= :(_updateState) Task=3D`0d381417-48c8-4035-99e5-01f34f55f98c`::moving from = state init -> state preparing=0A= Thread-290102::INFO::2014-01-30 16:17:20,057::logUtils::44::dispatcher::(wr= apper) Run and protect: repoStats(options=3DNone)=0A= Thread-290102::INFO::2014-01-30 16:17:20,058::logUtils::47::dispatcher::(wr= apper) Run and protect: repoStats, Return response: {'2c51d320-88ce-4f23-82= 15-e15f55f66906': {'delay': '0.00017907', 'lastCheck': '7.0', 'code': 0, 'v= alid': True, 'version': 3}, '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545': {'delay= ': '0.000248981', 'lastCheck': '3.1', 'code': 0, 'valid': True, 'version': = 3}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'delay': '0.000252188', 'lastC= heck': '2.6', 'code': 0, 'valid': True, 'version': 0}, '63041fa9-e093-4b44-= b36f-f39f16d3974f': {'delay': '0.000203099', 'lastCheck': '2.3', 'code': 0,= 'valid': True, 'version': 0}, '272ec473-6041-42ee-bd1a-732789dd18d4': {'de= lay': '0.000177334', 'lastCheck': '1.4', 'code': 0, 'valid': True, 'version= ': 3}}=0A= Thread-290102::DEBUG::2014-01-30 16:17:20,058::task::1168::TaskManager.Task= ::(prepare) Task=3D`0d381417-48c8-4035-99e5-01f34f55f98c`::finished: {'2c51= d320-88ce-4f23-8215-e15f55f66906': {'delay': '0.00017907', 'lastCheck': '7.= 0', 'code': 0, 'valid': True, 'version': 3}, '965ca3b6-4f9c-4e81-b6e8-5ed4a= 9e58545': {'delay': '0.000248981', 'lastCheck': '3.1', 'code': 0, 'valid': = True, 'version': 3}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'delay': '0.0= 00252188', 'lastCheck': '2.6', 'code': 0, 'valid': True, 'version': 0}, '63= 041fa9-e093-4b44-b36f-f39f16d3974f': {'delay': '0.000203099', 'lastCheck': = '2.3', 'code': 0, 'valid': True, 'version': 0}, '272ec473-6041-42ee-bd1a-73= 2789dd18d4': {'delay': '0.000177334', 'lastCheck': '1.4', 'code': 0, 'valid= ': True, 'version': 3}}=0A= Thread-290102::DEBUG::2014-01-30 16:17:20,058::task::579::TaskManager.Task:= :(_updateState) Task=3D`0d381417-48c8-4035-99e5-01f34f55f98c`::moving from = state preparing -> state finished=0A= Thread-290102::DEBUG::2014-01-30 16:17:20,058::resourceManager::939::Resour= ceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}=0A= Thread-290102::DEBUG::2014-01-30 16:17:20,058::resourceManager::976::Resour= ceManager.Owner::(cancelAll) Owner.cancelAll requests {}=0A= Thread-290102::DEBUG::2014-01-30 16:17:20,059::task::974::TaskManager.Task:= :(_decref) Task=3D`0d381417-48c8-4035-99e5-01f34f55f98c`::ref 0 aborting Fa= lse=0A= Thread-289906::DEBUG::2014-01-30 16:17:22,908::task::579::TaskManager.Task:= :(_updateState) Task=3D`308ddd49-b5c0-43a5-93fc-ccfd6220eb28`::moving from = state init -> state preparing=0A= Thread-289906::INFO::2014-01-30 16:17:22,909::logUtils::44::dispatcher::(wr= apper) Run and protect: getVolumeSize(sdUUID=3D'965ca3b6-4f9c-4e81-b6e8-5ed= 4a9e58545', spUUID=3D'94ed7a19-fade-4bd6-83f2-2cbb2f730b95', imgUUID=3D'1b2= 3ac73-0748-49cd-94b6-11555e35be81', volUUID=3D'5156a43b-c9dc-40fa-a9b7-a35b= 7f22f0eb', options=3DNone)=0A= Thread-289906::INFO::2014-01-30 16:17:22,911::logUtils::47::dispatcher::(wr= apper) Run and protect: getVolumeSize, Return response: {'truesize': '17700= 114432', 'apparentsize': '21474836480'}=0A= Thread-289906::DEBUG::2014-01-30 16:17:22,911::task::1168::TaskManager.Task= ::(prepare) Task=3D`308ddd49-b5c0-43a5-93fc-ccfd6220eb28`::finished: {'true= size': '17700114432', 'apparentsize': '21474836480'}=0A= Thread-289906::DEBUG::2014-01-30 16:17:22,911::task::579::TaskManager.Task:= :(_updateState) Task=3D`308ddd49-b5c0-43a5-93fc-ccfd6220eb28`::moving from = state preparing -> state finished=0A= Thread-289906::DEBUG::2014-01-30 16:17:22,911::resourceManager::939::Resour= ceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}=0A= Thread-289906::DEBUG::2014-01-30 16:17:22,912::resourceManager::976::Resour= ceManager.Owner::(cancelAll) Owner.cancelAll requests {}=0A= Thread-289906::DEBUG::2014-01-30 16:17:22,912::task::974::TaskManager.Task:= :(_decref) Task=3D`308ddd49-b5c0-43a5-93fc-ccfd6220eb28`::ref 0 aborting Fa= lse=0A= Thread-25::DEBUG::2014-01-30 16:17:23,063::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-25::DEBUG::2014-01-30 16:17:23,069::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n645 b= ytes (645 B) copied, 0.000189592 s, 3.4 MB/s\n'; <rc> =3D 0=0A= VM Channels Listener::DEBUG::2014-01-30 16:17:23,109::vmChannels::91::vds::= (_handle_timeouts) Timeout on fileno 105.=0A= Thread-289929::WARNING::2014-01-30 16:17:25,588::vm::800::vm.Vm::(run) vmId= =3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Migration stalling: dataRemainin= g (15MiB) > smallest_dataRemaining (9MiB). Refer to RHBZ#919201.=0A= Thread-289929::INFO::2014-01-30 16:17:25,588::vm::812::vm.Vm::(run) vmId=3D= `ce64f528-9981-4ec6-a172-9d70a00a34cd`::Migration Progress: 380 seconds ela= psed, 99% of data processed, 99% of mem processed=0A= Thread-26::DEBUG::2014-01-30 16:17:26,940::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-26::DEBUG::2014-01-30 16:17:26,947::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.00019559 s, 2.8 MB/s\n'; <rc> =3D 0=0A= Thread-27::DEBUG::2014-01-30 16:17:27,430::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-27::DEBUG::2014-01-30 16:17:27,439::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n357 b= ytes (357 B) copied, 0.00317489 s, 112 kB/s\n'; <rc> =3D 0=0A= Thread-33::DEBUG::2014-01-30 16:17:27,808::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-33::DEBUG::2014-01-30 16:17:27,815::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n363 b= ytes (363 B) copied, 0.000189549 s, 1.9 MB/s\n'; <rc> =3D 0=0A= Thread-38::DEBUG::2014-01-30 16:17:28,621::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-38::DEBUG::2014-01-30 16:17:28,632::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.00469703 s, 119 kB/s\n'; <rc> =3D 0=0A= Thread-25::DEBUG::2014-01-30 16:17:33,081::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-25::DEBUG::2014-01-30 16:17:33,087::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n645 b= ytes (645 B) copied, 0.000191272 s, 3.4 MB/s\n'; <rc> =3D 0=0A= Thread-290108::DEBUG::2014-01-30 16:17:35,257::task::579::TaskManager.Task:= :(_updateState) Task=3D`c598fcf4-774b-4420-af70-090d43cd58b5`::moving from = state init -> state preparing=0A= Thread-290108::INFO::2014-01-30 16:17:35,257::logUtils::44::dispatcher::(wr= apper) Run and protect: repoStats(options=3DNone)=0A= Thread-290108::INFO::2014-01-30 16:17:35,257::logUtils::47::dispatcher::(wr= apper) Run and protect: repoStats, Return response: {'2c51d320-88ce-4f23-82= 15-e15f55f66906': {'delay': '0.000191272', 'lastCheck': '2.2', 'code': 0, '= valid': True, 'version': 3}, '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545': {'dela= y': '0.00019559', 'lastCheck': '8.3', 'code': 0, 'valid': True, 'version': = 3}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'delay': '0.00317489', 'lastCh= eck': '7.8', 'code': 0, 'valid': True, 'version': 0}, '63041fa9-e093-4b44-b= 36f-f39f16d3974f': {'delay': '0.000189549', 'lastCheck': '7.4', 'code': 0, = 'valid': True, 'version': 0}, '272ec473-6041-42ee-bd1a-732789dd18d4': {'del= ay': '0.00469703', 'lastCheck': '6.6', 'code': 0, 'valid': True, 'version':= 3}}=0A= Thread-290108::DEBUG::2014-01-30 16:17:35,258::task::1168::TaskManager.Task= ::(prepare) Task=3D`c598fcf4-774b-4420-af70-090d43cd58b5`::finished: {'2c51= d320-88ce-4f23-8215-e15f55f66906': {'delay': '0.000191272', 'lastCheck': '2= .2', 'code': 0, 'valid': True, 'version': 3}, '965ca3b6-4f9c-4e81-b6e8-5ed4= a9e58545': {'delay': '0.00019559', 'lastCheck': '8.3', 'code': 0, 'valid': = True, 'version': 3}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'delay': '0.0= 0317489', 'lastCheck': '7.8', 'code': 0, 'valid': True, 'version': 0}, '630= 41fa9-e093-4b44-b36f-f39f16d3974f': {'delay': '0.000189549', 'lastCheck': '= 7.4', 'code': 0, 'valid': True, 'version': 0}, '272ec473-6041-42ee-bd1a-732= 789dd18d4': {'delay': '0.00469703', 'lastCheck': '6.6', 'code': 0, 'valid':= True, 'version': 3}}=0A= Thread-290108::DEBUG::2014-01-30 16:17:35,258::task::579::TaskManager.Task:= :(_updateState) Task=3D`c598fcf4-774b-4420-af70-090d43cd58b5`::moving from = state preparing -> state finished=0A= Thread-290108::DEBUG::2014-01-30 16:17:35,258::resourceManager::939::Resour= ceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}=0A= Thread-290108::DEBUG::2014-01-30 16:17:35,258::resourceManager::976::Resour= ceManager.Owner::(cancelAll) Owner.cancelAll requests {}=0A= Thread-290108::DEBUG::2014-01-30 16:17:35,258::task::974::TaskManager.Task:= :(_decref) Task=3D`c598fcf4-774b-4420-af70-090d43cd58b5`::ref 0 aborting Fa= lse=0A= Thread-289929::WARNING::2014-01-30 16:17:35,590::vm::800::vm.Vm::(run) vmId= =3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Migration stalling: dataRemainin= g (33MiB) > smallest_dataRemaining (9MiB). Refer to RHBZ#919201.=0A= Thread-289929::INFO::2014-01-30 16:17:35,590::vm::812::vm.Vm::(run) vmId=3D= `ce64f528-9981-4ec6-a172-9d70a00a34cd`::Migration Progress: 390 seconds ela= psed, 99% of data processed, 99% of mem processed=0A= Thread-26::DEBUG::2014-01-30 16:17:36,959::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-26::DEBUG::2014-01-30 16:17:36,966::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000212972 s, 2.6 MB/s\n'; <rc> =3D 0=0A= Thread-27::DEBUG::2014-01-30 16:17:37,450::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-27::DEBUG::2014-01-30 16:17:37,457::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n357 b= ytes (357 B) copied, 0.000199826 s, 1.8 MB/s\n'; <rc> =3D 0=0A= Thread-33::DEBUG::2014-01-30 16:17:37,826::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-33::DEBUG::2014-01-30 16:17:37,833::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n363 b= ytes (363 B) copied, 0.000200537 s, 1.8 MB/s\n'; <rc> =3D 0=0A= Thread-38::DEBUG::2014-01-30 16:17:38,644::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-38::DEBUG::2014-01-30 16:17:38,650::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000206259 s, 2.7 MB/s\n'; <rc> =3D 0=0A= Thread-25::DEBUG::2014-01-30 16:17:43,099::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-25::DEBUG::2014-01-30 16:17:43,105::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n645 b= ytes (645 B) copied, 0.000187228 s, 3.4 MB/s\n'; <rc> =3D 0=0A= Thread-289929::WARNING::2014-01-30 16:17:45,592::vm::789::vm.Vm::(run) vmId= =3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Migration is stuck: Hasn't progr= essed in 300.055635929 seconds. Aborting.=0A= Thread-289929::DEBUG::2014-01-30 16:17:45,594::vm::815::vm.Vm::(stop) vmId= =3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::stopping migration monitor threa= d=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:45,918::vm::4840::vm.Vm::(_onLibv= irtLifecycleEvent) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::event Res= umed detail 1 opaque None=0A= Thread-289927::DEBUG::2014-01-30 16:17:45,920::libvirtconnection::108::libv= irtconnection::(wrapper) Unknown libvirterror: ecode: 78 edom: 10 level: 2 = message: Operation abgebrochen: Migrations-Job: abgebrochen durch Client=0A= Thread-289927::DEBUG::2014-01-30 16:17:45,920::vm::745::vm.Vm::(cancel) vmI= d=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::canceling migration downtime th= read=0A= Thread-289927::DEBUG::2014-01-30 16:17:45,920::vm::815::vm.Vm::(stop) vmId= =3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::stopping migration monitor threa= d=0A= Thread-289927::ERROR::2014-01-30 16:17:45,920::vm::238::vm.Vm::(_recover) v= mId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Operation abgebrochen: Migrat= ions-Job: abgebrochen durch Client=0A= Thread-289927::ERROR::2014-01-30 16:17:45,949::vm::337::vm.Vm::(run) vmId= =3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Failed to migrate=0A= Traceback (most recent call last):=0A= File "/usr/share/vdsm/vm.py", line 323, in run=0A= self._startUnderlyingMigration()=0A= File "/usr/share/vdsm/vm.py", line 400, in _startUnderlyingMigration=0A= None, maxBandwidth)=0A= File "/usr/share/vdsm/vm.py", line 838, in f=0A= ret =3D attr(*args, **kwargs)=0A= File "/usr/lib64/python2.7/site-packages/vdsm/libvirtconnection.py", line= 76, in wrapper=0A= ret =3D f(*args, **kwargs)=0A= File "/usr/lib64/python2.7/site-packages/libvirt.py", line 1274, in migra= teToURI2=0A= if ret =3D=3D -1: raise libvirtError ('virDomainMigrateToURI2() failed'= , dom=3Dself)=0A= libvirtError: Operation abgebrochen: Migrations-Job: abgebrochen durch Clie= nt=0A= Thread-26::DEBUG::2014-01-30 16:17:46,976::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-26::DEBUG::2014-01-30 16:17:46,982::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000163843 s, 3.4 MB/s\n'; <rc> =3D 0=0A= Thread-290114::DEBUG::2014-01-30 16:17:47,444::BindingXMLRPC::974::vds::(wr= apper) client [192.168.11.2]::call vmGetStats with ('ce64f528-9981-4ec6-a17= 2-9d70a00a34cd',) {}=0A= Thread-290114::DEBUG::2014-01-30 16:17:47,445::BindingXMLRPC::981::vds::(wr= apper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 's= tatsList': [{'status': 'Up', 'username': 'Unknown', 'memUsage': '0', 'acpiE= nable': 'true', 'guestFQDN': '', 'pid': '14467', 'displayIp': '192.168.11.4= 2', 'displayPort': '-1', 'session': 'Unknown', 'displaySecurePort': u'5900'= , 'timeOffset': '0', 'hash': '3172497814970917300', 'balloonInfo': {'balloo= n_max': '2097152', 'balloon_target': '2097152', 'balloon_cur': '2097152', '= balloon_min': '2097152'}, 'clientIp': '', 'kvmEnable': 'true', 'network': {= u'vnet0': {'macAddr': '00:1a:4a:ee:d3:4a', 'rxDropped': '605', 'rxErrors': = '0', 'txDropped': '0', 'txRate': '0.0', 'rxRate': '1.4', 'txErrors': '0', '= state': 'unknown', 'speed': '1000', 'name': u'vnet0'}}, 'vmId': 'ce64f528-9= 981-4ec6-a172-9d70a00a34cd', 'displayType': 'qxl', 'cpuUser': '35.99', 'dis= ks': {u'hdc': {'readLatency': '0', 'apparentsize': '0', 'writeLatency': '0'= , 'flushLatency': '0', 'readRate': '0.00', 'truesize': '0', 'writeRate': '0= .00'}, u'sda': {'readLatency': '0', 'apparentsize': '21474836480', 'writeLa= tency': '2110228', 'imageID': '1b23ac73-0748-49cd-94b6-11555e35be81', 'flus= hLatency': '0', 'readRate': '0.00', 'truesize': '17700114432', 'writeRate':= '1640924.26'}}, 'monitorResponse': '0', 'statsAge': '0.49', 'elapsedTime':= '1235', 'vmType': 'kvm', 'cpuSys': '35.99', 'appsList': [], 'guestIPs': ''= }]}=0A= Thread-27::DEBUG::2014-01-30 16:17:47,468::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-27::DEBUG::2014-01-30 16:17:47,474::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n357 b= ytes (357 B) copied, 0.000176178 s, 2.0 MB/s\n'; <rc> =3D 0=0A= Thread-290115::DEBUG::2014-01-30 16:17:47,493::BindingXMLRPC::974::vds::(wr= apper) client [192.168.11.2]::call vmGetMigrationStatus with ('ce64f528-998= 1-4ec6-a172-9d70a00a34cd',) {}=0A= Thread-290115::DEBUG::2014-01-30 16:17:47,493::BindingXMLRPC::981::vds::(wr= apper) return vmGetMigrationStatus with {'status': {'message': 'Migration c= anceled', 'code': 47}, 'progress': 99}=0A= Thread-33::DEBUG::2014-01-30 16:17:47,845::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-33::DEBUG::2014-01-30 16:17:47,851::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n363 b= ytes (363 B) copied, 0.000191543 s, 1.9 MB/s\n'; <rc> =3D 0=0A= Thread-38::DEBUG::2014-01-30 16:17:48,662::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-38::DEBUG::2014-01-30 16:17:48,668::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000225105 s, 2.5 MB/s\n'; <rc> =3D 0=0A= Thread-290116::DEBUG::2014-01-30 16:17:50,490::task::579::TaskManager.Task:= :(_updateState) Task=3D`cd241aee-e845-4143-bfe3-01383c65e90e`::moving from = state init -> state preparing=0A= Thread-290116::INFO::2014-01-30 16:17:50,490::logUtils::44::dispatcher::(wr= apper) Run and protect: repoStats(options=3DNone)=0A= =0A= **************************=0A= vdsm_target:=0A= =0A= Thread-285228::DEBUG::2014-01-30 16:17:07,460::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc latency not a= vailable=0A= Thread-285228::DEBUG::2014-01-30 16:17:07,460::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda latency not a= vailable=0A= Thread-285228::DEBUG::2014-01-30 16:17:07,461::BindingXMLRPC::981::vds::(wr= apper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 's= tatsList': [{'status': 'Paused', 'username': 'Unknown', 'memUsage': '0', 'a= cpiEnable': 'true', 'guestFQDN': '', 'pid': '7671', 'displayIp': '192.168.1= 1.44', 'displayPort': '-1', 'session': 'Unknown', 'displaySecurePort': u'59= 00', 'timeOffset': '0', 'hash': '7219603903902024642', 'balloonInfo': {'bal= loon_max': '2097152', 'balloon_target': '2097152', 'balloon_cur': '2097152'= , 'balloon_min': '2097152'}, 'clientIp': '', 'kvmEnable': 'true', 'network'= : {u'vnet0': {'macAddr': '00:1a:4a:ee:d3:4a', 'rxDropped': '867', 'rxErrors= ': '0', 'txDropped': '0', 'txRate': '0.0', 'rxRate': '0.0', 'txErrors': '0'= , 'state': 'unknown', 'speed': '1000', 'name': u'vnet0'}}, 'vmId': 'ce64f52= 8-9981-4ec6-a172-9d70a00a34cd', 'displayType': 'qxl', 'cpuUser': '0.38', 'd= isks': {u'hdc': {'truesize': '0', 'apparentsize': '0'}, u'sda': {'truesize'= : '17700114432', 'apparentsize': '21474836480', 'imageID': '1b23ac73-0748-4= 9cd-94b6-11555e35be81'}}, 'monitorResponse': '0', 'statsAge': '0.44', 'elap= sedTime': '1212', 'vmType': 'kvm', 'cpuSys': '2.07', 'appsList': [], 'guest= IPs': ''}]}=0A= Thread-40::DEBUG::2014-01-30 16:17:07,811::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-40::DEBUG::2014-01-30 16:17:07,818::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n645 b= ytes (645 B) copied, 0.000160605 s, 4.0 MB/s\n'; <rc> =3D 0=0A= Thread-42::DEBUG::2014-01-30 16:17:08,363::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-42::DEBUG::2014-01-30 16:17:08,369::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n357 b= ytes (357 B) copied, 0.000144136 s, 2.5 MB/s\n'; <rc> =3D 0=0A= Thread-47::DEBUG::2014-01-30 16:17:10,080::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-47::DEBUG::2014-01-30 16:17:10,086::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n363 b= ytes (363 B) copied, 0.000213518 s, 1.7 MB/s\n'; <rc> =3D 0=0A= Thread-285230::DEBUG::2014-01-30 16:17:10,569::BindingXMLRPC::974::vds::(wr= apper) client [192.168.11.2]::call vmGetStats with ('ce64f528-9981-4ec6-a17= 2-9d70a00a34cd',) {}=0A= Thread-285230::DEBUG::2014-01-30 16:17:10,569::vm::645::vm.Vm::(_getDiskSta= ts) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc stats not avail= able=0A= Thread-285230::DEBUG::2014-01-30 16:17:10,569::vm::645::vm.Vm::(_getDiskSta= ts) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda stats not avail= able=0A= Thread-285230::DEBUG::2014-01-30 16:17:10,569::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc latency not a= vailable=0A= Thread-285230::DEBUG::2014-01-30 16:17:10,570::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda latency not a= vailable=0A= Thread-285230::DEBUG::2014-01-30 16:17:10,571::BindingXMLRPC::981::vds::(wr= apper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 's= tatsList': [{'status': 'Paused', 'username': 'Unknown', 'memUsage': '0', 'a= cpiEnable': 'true', 'guestFQDN': '', 'pid': '7671', 'displayIp': '192.168.1= 1.44', 'displayPort': '-1', 'session': 'Unknown', 'displaySecurePort': u'59= 00', 'timeOffset': '0', 'hash': '7219603903902024642', 'balloonInfo': {'bal= loon_max': '2097152', 'balloon_target': '2097152', 'balloon_cur': '2097152'= , 'balloon_min': '2097152'}, 'clientIp': '', 'kvmEnable': 'true', 'network'= : {u'vnet0': {'macAddr': '00:1a:4a:ee:d3:4a', 'rxDropped': '887', 'rxErrors= ': '0', 'txDropped': '0', 'txRate': '0.0', 'rxRate': '0.0', 'txErrors': '0'= , 'state': 'unknown', 'speed': '1000', 'name': u'vnet0'}}, 'vmId': 'ce64f52= 8-9981-4ec6-a172-9d70a00a34cd', 'displayType': 'qxl', 'cpuUser': '0.38', 'd= isks': {u'hdc': {'truesize': '0', 'apparentsize': '0'}, u'sda': {'truesize'= : '17700114432', 'apparentsize': '21474836480', 'imageID': '1b23ac73-0748-4= 9cd-94b6-11555e35be81'}}, 'monitorResponse': '0', 'statsAge': '1.55', 'elap= sedTime': '1215', 'vmType': 'kvm', 'cpuSys': '2.07', 'appsList': [], 'guest= IPs': ''}]}=0A= Thread-41::DEBUG::2014-01-30 16:17:11,570::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-41::DEBUG::2014-01-30 16:17:11,577::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000211434 s, 2.6 MB/s\n'; <rc> =3D 0=0A= Thread-285232::DEBUG::2014-01-30 16:17:13,656::BindingXMLRPC::974::vds::(wr= apper) client [192.168.11.2]::call vmGetStats with ('ce64f528-9981-4ec6-a17= 2-9d70a00a34cd',) {}=0A= Thread-285232::DEBUG::2014-01-30 16:17:13,656::vm::645::vm.Vm::(_getDiskSta= ts) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc stats not avail= able=0A= Thread-285232::DEBUG::2014-01-30 16:17:13,657::vm::645::vm.Vm::(_getDiskSta= ts) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda stats not avail= able=0A= Thread-285232::DEBUG::2014-01-30 16:17:13,657::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc latency not a= vailable=0A= Thread-285232::DEBUG::2014-01-30 16:17:13,657::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda latency not a= vailable=0A= Thread-285232::DEBUG::2014-01-30 16:17:13,658::BindingXMLRPC::981::vds::(wr= apper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 's= tatsList': [{'status': 'Paused', 'username': 'Unknown', 'memUsage': '0', 'a= cpiEnable': 'true', 'guestFQDN': '', 'pid': '7671', 'displayIp': '192.168.1= 1.44', 'displayPort': '-1', 'session': 'Unknown', 'displaySecurePort': u'59= 00', 'timeOffset': '0', 'hash': '7219603903902024642', 'balloonInfo': {'bal= loon_max': '2097152', 'balloon_target': '2097152', 'balloon_cur': '2097152'= , 'balloon_min': '2097152'}, 'clientIp': '', 'kvmEnable': 'true', 'network'= : {u'vnet0': {'macAddr': '00:1a:4a:ee:d3:4a', 'rxDropped': '887', 'rxErrors= ': '0', 'txDropped': '0', 'txRate': '0.0', 'rxRate': '0.0', 'txErrors': '0'= , 'state': 'unknown', 'speed': '1000', 'name': u'vnet0'}}, 'vmId': 'ce64f52= 8-9981-4ec6-a172-9d70a00a34cd', 'displayType': 'qxl', 'cpuUser': '0.38', 'd= isks': {u'hdc': {'truesize': '0', 'apparentsize': '0'}, u'sda': {'truesize'= : '17700114432', 'apparentsize': '21474836480', 'imageID': '1b23ac73-0748-4= 9cd-94b6-11555e35be81'}}, 'monitorResponse': '0', 'statsAge': '0.63', 'elap= sedTime': '1218', 'vmType': 'kvm', 'cpuSys': '2.07', 'appsList': [], 'guest= IPs': ''}]}=0A= Thread-52::DEBUG::2014-01-30 16:17:14,494::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-52::DEBUG::2014-01-30 16:17:14,501::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000228157 s, 2.4 MB/s\n'; <rc> =3D 0=0A= Thread-285233::DEBUG::2014-01-30 16:17:16,719::task::579::TaskManager.Task:= :(_updateState) Task=3D`3b433b6a-d9ed-4edc-adcc-b9994ba7877a`::moving from = state init -> state preparing=0A= Thread-285233::INFO::2014-01-30 16:17:16,720::logUtils::44::dispatcher::(wr= apper) Run and protect: repoStats(options=3DNone)=0A= Thread-285233::INFO::2014-01-30 16:17:16,720::logUtils::47::dispatcher::(wr= apper) Run and protect: repoStats, Return response: {'2c51d320-88ce-4f23-82= 15-e15f55f66906': {'delay': '0.000160605', 'lastCheck': '8.9', 'code': 0, '= valid': True, 'version': 3}, '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545': {'dela= y': '0.000211434', 'lastCheck': '5.1', 'code': 0, 'valid': True, 'version':= 3}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'delay': '0.000144136', 'last= Check': '8.3', 'code': 0, 'valid': True, 'version': 0}, '63041fa9-e093-4b44= -b36f-f39f16d3974f': {'delay': '0.000213518', 'lastCheck': '6.6', 'code': 0= , 'valid': True, 'version': 0}, '272ec473-6041-42ee-bd1a-732789dd18d4': {'d= elay': '0.000228157', 'lastCheck': '2.2', 'code': 0, 'valid': True, 'versio= n': 3}}=0A= Thread-285233::DEBUG::2014-01-30 16:17:16,720::task::1168::TaskManager.Task= ::(prepare) Task=3D`3b433b6a-d9ed-4edc-adcc-b9994ba7877a`::finished: {'2c51= d320-88ce-4f23-8215-e15f55f66906': {'delay': '0.000160605', 'lastCheck': '8= .9', 'code': 0, 'valid': True, 'version': 3}, '965ca3b6-4f9c-4e81-b6e8-5ed4= a9e58545': {'delay': '0.000211434', 'lastCheck': '5.1', 'code': 0, 'valid':= True, 'version': 3}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'delay': '0.= 000144136', 'lastCheck': '8.3', 'code': 0, 'valid': True, 'version': 0}, '6= 3041fa9-e093-4b44-b36f-f39f16d3974f': {'delay': '0.000213518', 'lastCheck':= '6.6', 'code': 0, 'valid': True, 'version': 0}, '272ec473-6041-42ee-bd1a-7= 32789dd18d4': {'delay': '0.000228157', 'lastCheck': '2.2', 'code': 0, 'vali= d': True, 'version': 3}}=0A= Thread-285233::DEBUG::2014-01-30 16:17:16,720::task::579::TaskManager.Task:= :(_updateState) Task=3D`3b433b6a-d9ed-4edc-adcc-b9994ba7877a`::moving from = state preparing -> state finished=0A= Thread-285233::DEBUG::2014-01-30 16:17:16,720::resourceManager::939::Resour= ceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}=0A= Thread-285233::DEBUG::2014-01-30 16:17:16,721::resourceManager::976::Resour= ceManager.Owner::(cancelAll) Owner.cancelAll requests {}=0A= Thread-285233::DEBUG::2014-01-30 16:17:16,721::task::974::TaskManager.Task:= :(_decref) Task=3D`3b433b6a-d9ed-4edc-adcc-b9994ba7877a`::ref 0 aborting Fa= lse=0A= Thread-285234::DEBUG::2014-01-30 16:17:16,733::vm::645::vm.Vm::(_getDiskSta= ts) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc stats not avail= able=0A= Thread-285234::DEBUG::2014-01-30 16:17:16,733::vm::645::vm.Vm::(_getDiskSta= ts) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda stats not avail= able=0A= Thread-285234::DEBUG::2014-01-30 16:17:16,733::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc latency not a= vailable=0A= Thread-285234::DEBUG::2014-01-30 16:17:16,733::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda latency not a= vailable=0A= Thread-40::DEBUG::2014-01-30 16:17:17,821::domainMonitor::182::Storage.Doma= inMonitorThread::(_monitorDomain) Refreshing domain 2c51d320-88ce-4f23-8215= -e15f55f66906=0A= Thread-40::DEBUG::2014-01-30 16:17:17,834::fileSD::154::Storage.StorageDoma= in::(__init__) Reading domain in path /rhev/data-center/mnt/10.10.30.253:_v= ar_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906=0A= Thread-40::DEBUG::2014-01-30 16:17:17,835::persistentDict::192::Storage.Per= sistentDict::(__init__) Created a persistent dict with FileMetadataRW backe= nd=0A= Thread-40::DEBUG::2014-01-30 16:17:17,842::persistentDict::234::Storage.Per= sistentDict::(refresh) read lines (FileMetadataRW)=3D['CLASS=3DData', 'DESC= RIPTION=3Dcolnas03_IB', 'IOOPTIMEOUTSEC=3D10', 'LEASERETRIES=3D3', 'LEASETI= MESEC=3D60', 'LOCKPOLICY=3D', 'LOCKRENEWALINTERVALSEC=3D5', 'MASTER_VERSION= =3D3', 'POOL_DESCRIPTION=3DCollogia', 'POOL_DOMAINS=3D272ec473-6041-42ee-bd= 1a-732789dd18d4:Active,965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545:Active,2c51d320= -88ce-4f23-8215-e15f55f66906:Active,63041fa9-e093-4b44-b36f-f39f16d3974f:Ac= tive,bff3a2be-fdd9-4e37-b416-fa4ef7fafba2:Active', 'POOL_SPM_ID=3D2', 'POOL= _SPM_LVER=3D33', 'POOL_UUID=3D94ed7a19-fade-4bd6-83f2-2cbb2f730b95', 'REMOT= E_PATH=3D10.10.30.253:/var/nas3/OVirtIB', 'ROLE=3DMaster', 'SDUUID=3D2c51d3= 20-88ce-4f23-8215-e15f55f66906', 'TYPE=3DNFS', 'VERSION=3D3', '_SHA_CKSUM= =3D75ca15b219476f472d87a8c375650d35eabb8d16']=0A= Thread-40::DEBUG::2014-01-30 16:17:17,843::fileSD::572::Storage.StorageDoma= in::(imageGarbageCollector) Removing remnants of deleted images []=0A= Thread-40::INFO::2014-01-30 16:17:17,844::sd::374::Storage.StorageDomain::(= _registerResourceNamespaces) Resource namespace 2c51d320-88ce-4f23-8215-e15= f55f66906_imageNS already registered=0A= Thread-40::INFO::2014-01-30 16:17:17,844::sd::382::Storage.StorageDomain::(= _registerResourceNamespaces) Resource namespace 2c51d320-88ce-4f23-8215-e15= f55f66906_volumeNS already registered=0A= Thread-40::DEBUG::2014-01-30 16:17:17,854::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-40::DEBUG::2014-01-30 16:17:17,860::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n645 b= ytes (645 B) copied, 0.000216469 s, 3.0 MB/s\n'; <rc> =3D 0=0A= Thread-42::DEBUG::2014-01-30 16:17:18,381::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-42::DEBUG::2014-01-30 16:17:18,387::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n357 b= ytes (357 B) copied, 0.000243463 s, 1.5 MB/s\n'; <rc> =3D 0=0A= Thread-285241::DEBUG::2014-01-30 16:17:19,814::BindingXMLRPC::974::vds::(wr= apper) client [192.168.11.2]::call vmGetStats with ('ce64f528-9981-4ec6-a17= 2-9d70a00a34cd',) {}=0A= Thread-285241::DEBUG::2014-01-30 16:17:19,815::vm::645::vm.Vm::(_getDiskSta= ts) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc stats not avail= able=0A= Thread-285241::DEBUG::2014-01-30 16:17:19,815::vm::645::vm.Vm::(_getDiskSta= ts) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda stats not avail= able=0A= Thread-285241::DEBUG::2014-01-30 16:17:19,815::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc latency not a= vailable=0A= Thread-285241::DEBUG::2014-01-30 16:17:19,815::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda latency not a= vailable=0A= Thread-285241::DEBUG::2014-01-30 16:17:19,816::BindingXMLRPC::981::vds::(wr= apper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 's= tatsList': [{'status': 'Paused', 'username': 'Unknown', 'memUsage': '0', 'a= cpiEnable': 'true', 'guestFQDN': '', 'pid': '7671', 'displayIp': '192.168.1= 1.44', 'displayPort': '-1', 'session': 'Unknown', 'displaySecurePort': u'59= 00', 'timeOffset': '0', 'hash': '7219603903902024642', 'balloonInfo': {'bal= loon_max': '2097152', 'balloon_target': '2097152', 'balloon_cur': '2097152'= , 'balloon_min': '2097152'}, 'clientIp': '', 'kvmEnable': 'true', 'network'= : {u'vnet0': {'macAddr': '00:1a:4a:ee:d3:4a', 'rxDropped': '909', 'rxErrors= ': '0', 'txDropped': '0', 'txRate': '0.0', 'rxRate': '0.0', 'txErrors': '0'= , 'state': 'unknown', 'speed': '1000', 'name': u'vnet0'}}, 'vmId': 'ce64f52= 8-9981-4ec6-a172-9d70a00a34cd', 'displayType': 'qxl', 'cpuUser': '0.44', 'd= isks': {u'hdc': {'truesize': '0', 'apparentsize': '0'}, u'sda': {'truesize'= : '17700114432', 'apparentsize': '21474836480', 'imageID': '1b23ac73-0748-4= 9cd-94b6-11555e35be81'}}, 'monitorResponse': '0', 'statsAge': '0.78', 'elap= sedTime': '1224', 'vmType': 'kvm', 'cpuSys': '1.93', 'appsList': [], 'guest= IPs': ''}]}=0A= VM Channels Listener::DEBUG::2014-01-30 16:17:20,026::vmChannels::91::vds::= (_handle_timeouts) Timeout on fileno 98.=0A= Thread-47::DEBUG::2014-01-30 16:17:20,096::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-47::DEBUG::2014-01-30 16:17:20,103::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n363 b= ytes (363 B) copied, 0.00022031 s, 1.6 MB/s\n'; <rc> =3D 0=0A= Thread-41::DEBUG::2014-01-30 16:17:21,589::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-41::DEBUG::2014-01-30 16:17:21,596::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.0002126 s, 2.6 MB/s\n'; <rc> =3D 0=0A= Thread-285243::DEBUG::2014-01-30 16:17:22,928::BindingXMLRPC::974::vds::(wr= apper) client [192.168.11.2]::call vmGetStats with ('ce64f528-9981-4ec6-a17= 2-9d70a00a34cd',) {}=0A= Thread-285243::DEBUG::2014-01-30 16:17:22,928::vm::645::vm.Vm::(_getDiskSta= ts) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc stats not avail= able=0A= Thread-285243::DEBUG::2014-01-30 16:17:22,928::vm::645::vm.Vm::(_getDiskSta= ts) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda stats not avail= able=0A= Thread-285243::DEBUG::2014-01-30 16:17:22,928::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc latency not a= vailable=0A= Thread-285243::DEBUG::2014-01-30 16:17:22,929::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda latency not a= vailable=0A= Thread-285243::DEBUG::2014-01-30 16:17:22,930::BindingXMLRPC::981::vds::(wr= apper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 's= tatsList': [{'status': 'Paused', 'username': 'Unknown', 'memUsage': '0', 'a= cpiEnable': 'true', 'guestFQDN': '', 'pid': '7671', 'displayIp': '192.168.1= 1.44', 'displayPort': '-1', 'session': 'Unknown', 'displaySecurePort': u'59= 00', 'timeOffset': '0', 'hash': '7219603903902024642', 'balloonInfo': {'bal= loon_max': '2097152', 'balloon_target': '2097152', 'balloon_cur': '2097152'= , 'balloon_min': '2097152'}, 'clientIp': '', 'kvmEnable': 'true', 'network'= : {u'vnet0': {'macAddr': '00:1a:4a:ee:d3:4a', 'rxDropped': '909', 'rxErrors= ': '0', 'txDropped': '0', 'txRate': '0.0', 'rxRate': '0.0', 'txErrors': '0'= , 'state': 'unknown', 'speed': '1000', 'name': u'vnet0'}}, 'vmId': 'ce64f52= 8-9981-4ec6-a172-9d70a00a34cd', 'displayType': 'qxl', 'cpuUser': '0.44', 'd= isks': {u'hdc': {'truesize': '0', 'apparentsize': '0'}, u'sda': {'truesize'= : '17700114432', 'apparentsize': '21474836480', 'imageID': '1b23ac73-0748-4= 9cd-94b6-11555e35be81'}}, 'monitorResponse': '0', 'statsAge': '1.88', 'elap= sedTime': '1227', 'vmType': 'kvm', 'cpuSys': '1.93', 'appsList': [], 'guest= IPs': ''}]}=0A= Thread-52::DEBUG::2014-01-30 16:17:24,512::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-52::DEBUG::2014-01-30 16:17:24,519::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000195213 s, 2.9 MB/s\n'; <rc> =3D 0=0A= Thread-285245::DEBUG::2014-01-30 16:17:26,006::BindingXMLRPC::974::vds::(wr= apper) client [192.168.11.2]::call vmGetStats with ('ce64f528-9981-4ec6-a17= 2-9d70a00a34cd',) {}=0A= Thread-285245::DEBUG::2014-01-30 16:17:26,006::vm::645::vm.Vm::(_getDiskSta= ts) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc stats not avail= able=0A= Thread-285245::DEBUG::2014-01-30 16:17:26,006::vm::645::vm.Vm::(_getDiskSta= ts) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda stats not avail= able=0A= Thread-285245::DEBUG::2014-01-30 16:17:26,007::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc latency not a= vailable=0A= Thread-285245::DEBUG::2014-01-30 16:17:26,007::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda latency not a= vailable=0A= Thread-285245::DEBUG::2014-01-30 16:17:26,008::BindingXMLRPC::981::vds::(wr= apper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 's= tatsList': [{'status': 'Paused', 'username': 'Unknown', 'memUsage': '0', 'a= cpiEnable': 'true', 'guestFQDN': '', 'pid': '7671', 'displayIp': '192.168.1= 1.44', 'displayPort': '-1', 'session': 'Unknown', 'displaySecurePort': u'59= 00', 'timeOffset': '0', 'hash': '7219603903902024642', 'balloonInfo': {'bal= loon_max': '2097152', 'balloon_target': '2097152', 'balloon_cur': '2097152'= , 'balloon_min': '2097152'}, 'clientIp': '', 'kvmEnable': 'true', 'network'= : {u'vnet0': {'macAddr': '00:1a:4a:ee:d3:4a', 'rxDropped': '929', 'rxErrors= ': '0', 'txDropped': '0', 'txRate': '0.0', 'rxRate': '0.0', 'txErrors': '0'= , 'state': 'unknown', 'speed': '1000', 'name': u'vnet0'}}, 'vmId': 'ce64f52= 8-9981-4ec6-a172-9d70a00a34cd', 'displayType': 'qxl', 'cpuUser': '0.44', 'd= isks': {u'hdc': {'truesize': '0', 'apparentsize': '0'}, u'sda': {'truesize'= : '17700114432', 'apparentsize': '21474836480', 'imageID': '1b23ac73-0748-4= 9cd-94b6-11555e35be81'}}, 'monitorResponse': '0', 'statsAge': '0.95', 'elap= sedTime': '1230', 'vmType': 'kvm', 'cpuSys': '1.93', 'appsList': [], 'guest= IPs': ''}]}=0A= Thread-40::DEBUG::2014-01-30 16:17:27,875::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-40::DEBUG::2014-01-30 16:17:27,881::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n645 b= ytes (645 B) copied, 0.000195778 s, 3.3 MB/s\n'; <rc> =3D 0=0A= Thread-42::DEBUG::2014-01-30 16:17:28,399::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-42::DEBUG::2014-01-30 16:17:28,406::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n357 b= ytes (357 B) copied, 0.00021875 s, 1.6 MB/s\n'; <rc> =3D 0=0A= Thread-285247::DEBUG::2014-01-30 16:17:29,119::BindingXMLRPC::974::vds::(wr= apper) client [192.168.11.2]::call vmGetStats with ('ce64f528-9981-4ec6-a17= 2-9d70a00a34cd',) {}=0A= Thread-285247::DEBUG::2014-01-30 16:17:29,119::vm::645::vm.Vm::(_getDiskSta= ts) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc stats not avail= able=0A= Thread-285247::DEBUG::2014-01-30 16:17:29,119::vm::645::vm.Vm::(_getDiskSta= ts) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda stats not avail= able=0A= Thread-285247::DEBUG::2014-01-30 16:17:29,119::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk hdc latency not a= vailable=0A= Thread-285247::DEBUG::2014-01-30 16:17:29,120::vm::684::vm.Vm::(_getDiskLat= ency) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Disk sda latency not a= vailable=0A= Thread-285247::DEBUG::2014-01-30 16:17:29,121::BindingXMLRPC::981::vds::(wr= apper) return vmGetStats with {'status': {'message': 'Done', 'code': 0}, 's= tatsList': [{'status': 'Paused', 'username': 'Unknown', 'memUsage': '0', 'a= cpiEnable': 'true', 'guestFQDN': '', 'pid': '7671', 'displayIp': '192.168.1= 1.44', 'displayPort': '-1', 'session': 'Unknown', 'displaySecurePort': u'59= 00', 'timeOffset': '0', 'hash': '7219603903902024642', 'balloonInfo': {'bal= loon_max': '2097152', 'balloon_target': '2097152', 'balloon_cur': '2097152'= , 'balloon_min': '2097152'}, 'clientIp': '', 'kvmEnable': 'true', 'network'= : {u'vnet0': {'macAddr': '00:1a:4a:ee:d3:4a', 'rxDropped': '946', 'rxErrors= ': '0', 'txDropped': '0', 'txRate': '0.0', 'rxRate': '0.0', 'txErrors': '0'= , 'state': 'unknown', 'speed': '1000', 'name': u'vnet0'}}, 'vmId': 'ce64f52= 8-9981-4ec6-a172-9d70a00a34cd', 'displayType': 'qxl', 'cpuUser': '0.44', 'd= isks': {u'hdc': {'truesize': '0', 'apparentsize': '0'}, u'sda': {'truesize'= : '17700114432', 'apparentsize': '21474836480', 'imageID': '1b23ac73-0748-4= 9cd-94b6-11555e35be81'}}, 'monitorResponse': '0', 'statsAge': '0.07', 'elap= sedTime': '1233', 'vmType': 'kvm', 'cpuSys': '1.93', 'appsList': [], 'guest= IPs': ''}]}=0A= VM Channels Listener::ERROR::2014-01-30 16:17:29,729::vmChannels::53::vds::= (_handle_event) Received 00000019 on fileno 98=0A= VM Channels Listener::DEBUG::2014-01-30 16:17:29,729::vmChannels::128::vds:= :(_handle_unconnected) Trying to connect fileno 98.=0A= VM Channels Listener::DEBUG::2014-01-30 16:17:29,730::guestIF::147::vm.Vm::= (_connect) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Attempting connec= tion to /var/lib/libvirt/qemu/channels/ce64f528-9981-4ec6-a172-9d70a00a34cd= .com.redhat.rhevm.vdsm=0A= VM Channels Listener::DEBUG::2014-01-30 16:17:29,730::guestIF::158::vm.Vm::= (_connect) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Failed to connect= to /var/lib/libvirt/qemu/channels/ce64f528-9981-4ec6-a172-9d70a00a34cd.com= .redhat.rhevm.vdsm with 111=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,770::vm::4840::vm.Vm::(_onLibv= irtLifecycleEvent) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::event Sto= pped detail 5 opaque None=0A= libvirtEventLoop::INFO::2014-01-30 16:17:29,770::vm::2166::vm.Vm::(_onQemuD= eath) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::underlying process dis= connected=0A= libvirtEventLoop::INFO::2014-01-30 16:17:29,770::vm::4320::vm.Vm::(releaseV= m) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Release VM resources=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,775::libvirtconnection::108::l= ibvirtconnection::(wrapper) Unknown libvirterror: ecode: 42 edom: 10 level:= 2 message: Domain nicht gefunden: Keine Domain mit ?bereinstimmender UUID = 'ce64f528-9981-4ec6-a172-9d70a00a34cd' (Win7x64_Master)=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,776::sampling::292::vm.Vm::(st= op) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Stop statistics collecti= on=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,776::vmChannels::205::vds::(un= register) Delete fileno 98 from listener.=0A= Thread-285161::DEBUG::2014-01-30 16:17:29,776::sampling::323::vm.Vm::(run) = vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Stats thread finished=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,777::libvirtconnection::108::l= ibvirtconnection::(wrapper) Unknown libvirterror: ecode: 42 edom: 10 level:= 2 message: Domain nicht gefunden: Keine Domain mit ?bereinstimmender UUID = 'ce64f528-9981-4ec6-a172-9d70a00a34cd' (Win7x64_Master)=0A= libvirtEventLoop::WARNING::2014-01-30 16:17:29,777::clientIF::362::vds::(te= ardownVolumePath) Drive is not a vdsm image: VOLWM_CHUNK_MB:1024 VOLWM_CHUN= K_REPLICATE_MULT:2 VOLWM_FREE_PCT:50 _blockDev:False _checkIoTuneCategories= :<bound method Drive._checkIoTuneCategories of <vm.Drive object at 0x7f3560= 03bb90>> _customize:<bound method Drive._customize of <vm.Drive object at 0= x7f356003bb90>> _deviceXML:<disk device=3D"cdrom" type=3D"file">=0A= <driver name=3D"qemu" type=3D"raw"/>=0A= <source startupPolicy=3D"optional"/>=0A= <target bus=3D"ide" dev=3D"hdc"/>=0A= <readonly/>=0A= <serial/>=0A= <alias name=3D"ide0-1-0"/>=0A= <address bus=3D"1" controller=3D"0" target=3D"0" type=3D"drive" unit= =3D"0"/>=0A= </disk> _makeName:<bound method Drive._makeName of <vm.Drive object at = 0x7f356003bb90>> _setExtSharedState:<bound method Drive._setExtSharedState = of <vm.Drive object at 0x7f356003bb90>> _validateIoTuneParams:<bound method= Drive._validateIoTuneParams of <vm.Drive object at 0x7f356003bb90>> addres= s:{u'bus': u'1', u'controller': u'0', u'type': u'drive', u'target': u'0', u= 'unit': u'0'} alias:ide0-1-0 apparentsize:0 blockDev:False cache:none conf:= {'acpiEnable': 'true', 'emulatedMachine': 'pc-1.0', 'afterMigrationStatus':= '', 'pid': '7671', 'memGuaranteedSize': 2048, 'transparentHugePages': 'tru= e', 'displaySecurePort': u'5900', 'timeOffset': '0', 'cpuType': 'Nehalem', = 'smp': '2', 'custom': {'device_aff6efaa-b33b-4385-a311-0c770cf56cf2device_3= 073f208-c700-4b39-99f1-56c33e884c78device_0c7f4f0b-98d4-4a1a-934e-6210ecabd= 3e9device_50fb5c9c-d9b3-4422-b216-3ff71ac6d774device_bb8234b4-44d4-4086-906= c-744b572ddbd9': 'VmDevice {vmId=3Dce64f528-9981-4ec6-a172-9d70a00a34cd, de= viceId=3Dbb8234b4-44d4-4086-906c-744b572ddbd9, device=3Dspicevmc, type=3DCH= ANNEL, bootOrder=3D0, specParams=3D{}, address=3D{port=3D3, bus=3D0, contro= ller=3D0, type=3Dvirtio-serial}, managed=3Dfalse, plugged=3Dtrue, readOnly= =3Dfalse, deviceAlias=3Dchannel2, customProperties=3D{}, snapshotId=3Dnull}= ', 'device_aff6efaa-b33b-4385-a311-0c770cf56cf2device_3073f208-c700-4b39-99= f1-56c33e884c78': 'VmDevice {vmId=3Dce64f528-9981-4ec6-a172-9d70a00a34cd, d= eviceId=3D3073f208-c700-4b39-99f1-56c33e884c78, device=3Dvirtio-serial, typ= e=3DCONTROLLER, bootOrder=3D0, specParams=3D{}, address=3D{bus=3D0x00, doma= in=3D0x0000, type=3Dpci, slot=3D0x06, function=3D0x0}, managed=3Dfalse, plu= gged=3Dtrue, readOnly=3Dfalse, deviceAlias=3Dvirtio-serial0, customProperti= es=3D{}, snapshotId=3Dnull}', 'device_aff6efaa-b33b-4385-a311-0c770cf56cf2d= evice_3073f208-c700-4b39-99f1-56c33e884c78device_0c7f4f0b-98d4-4a1a-934e-62= 10ecabd3e9device_50fb5c9c-d9b3-4422-b216-3ff71ac6d774': 'VmDevice {vmId=3Dc= e64f528-9981-4ec6-a172-9d70a00a34cd, deviceId=3D50fb5c9c-d9b3-4422-b216-3ff= 71ac6d774, device=3Dunix, type=3DCHANNEL, bootOrder=3D0, specParams=3D{}, a= ddress=3D{port=3D2, bus=3D0, controller=3D0, type=3Dvirtio-serial}, managed= =3Dfalse, plugged=3Dtrue, readOnly=3Dfalse, deviceAlias=3Dchannel1, customP= roperties=3D{}, snapshotId=3Dnull}', 'sap_agent': 'false', 'device_aff6efaa= -b33b-4385-a311-0c770cf56cf2': 'VmDevice {vmId=3Dce64f528-9981-4ec6-a172-9d= 70a00a34cd, deviceId=3Daff6efaa-b33b-4385-a311-0c770cf56cf2, device=3Dide, = type=3DCONTROLLER, bootOrder=3D0, specParams=3D{}, address=3D{bus=3D0x00, d= omain=3D0x0000, type=3Dpci, slot=3D0x01, function=3D0x1}, managed=3Dfalse, = plugged=3Dtrue, readOnly=3Dfalse, deviceAlias=3Dide0, customProperties=3D{}= , snapshotId=3Dnull}', 'device_aff6efaa-b33b-4385-a311-0c770cf56cf2device_3= 073f208-c700-4b39-99f1-56c33e884c78device_0c7f4f0b-98d4-4a1a-934e-6210ecabd= 3e9': 'VmDevice {vmId=3Dce64f528-9981-4ec6-a172-9d70a00a34cd, deviceId=3D0c= 7f4f0b-98d4-4a1a-934e-6210ecabd3e9, device=3Dunix, type=3DCHANNEL, bootOrde= r=3D0, specParams=3D{}, address=3D{port=3D1, bus=3D0, controller=3D0, type= =3Dvirtio-serial}, managed=3Dfalse, plugged=3Dtrue, readOnly=3Dfalse, devic= eAlias=3Dchannel0, customProperties=3D{}, snapshotId=3Dnull}'}, 'vmType': '= kvm', 'spiceSslCipherSuite': 'DEFAULT', 'memSize': 2048, 'vmName': 'Win7x64= _Master', 'nice': '0', 'clientIp': '', 'vmId': 'ce64f528-9981-4ec6-a172-9d7= 0a00a34cd', 'displayIp': '192.168.11.44', 'keyboardLayout': 'de', 'displayP= ort': '-1', 'smartcardEnable': 'false', 'spiceSecureChannels': 'smain,sinpu= ts,scursor,splayback,srecord,sdisplay,susbredir,ssmartcard', 'nicModel': 'r= tl8139,pv', 'smpCoresPerSocket': '2', 'kvmEnable': 'true', 'displayNetwork'= : 'ovirtmgmt', 'devices': [{'device': 'unix', 'alias': 'channel0', 'type': = 'channel', 'address': {'bus': '0', 'controller': '0', 'type': 'virtio-seria= l', 'port': '1'}}, {'device': 'unix', 'alias': 'channel1', 'type': 'channel= ', 'address': {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'por= t': '2'}}, {'device': 'spicevmc', 'alias': 'channel2', 'type': 'channel', '= address': {'bus': '0', 'controller': '0', 'type': 'virtio-serial', 'port': = '3'}}, {'specParams': {}, 'alias': u'scsi0', 'deviceId': '294da3e7-42c8-487= 2-918c-cafa13cec438', 'address': {u'slot': u'0x04', u'bus': u'0x00', u'doma= in': u'0x0000', u'type': u'pci', u'function': u'0x0'}, 'device': 'scsi', 'm= odel': 'virtio-scsi', 'type': 'controller'}, {'device': 'usb', 'alias': u'u= sb0', 'type': 'controller', 'address': {u'slot': u'0x01', u'bus': u'0x00', = u'domain': u'0x0000', u'type': u'pci', u'function': u'0x2'}}, {'device': 'i= de', 'alias': u'ide0', 'type': 'controller', 'address': {u'slot': u'0x01', = u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'function': u'0x1'= }}, {'device': 'virtio-serial', 'alias': u'virtio-serial0', 'type': 'contro= ller', 'address': {u'slot': u'0x06', u'bus': u'0x00', u'domain': u'0x0000',= u'type': u'pci', u'function': u'0x0'}}, {'specParams': {'vram': '32768', '= heads': '1'}, 'alias': 'video0', 'deviceId': '14faa0f4-9b5f-4997-bcdb-889d4= 9672122', 'address': {'slot': '0x02', 'bus': '0x00', 'domain': '0x0000', 't= ype': 'pci', 'function': '0x0'}, 'device': 'qxl', 'type': 'video'}, {'nicMo= del': 'pv', 'macAddr': '00:1a:4a:ee:d3:4a', 'linkActive': True, 'network': = 'ovirtmgmt', 'specParams': {}, 'filter': 'vdsm-no-mac-spoofing', 'alias': u= 'net0', 'deviceId': '0109b881-8911-40ef-9e19-ad0d8daf5917', 'address': {u's= lot': u'0x03', u'bus': u'0x00', u'domain': u'0x0000', u'type': u'pci', u'fu= nction': u'0x0'}, 'device': 'bridge', 'type': 'interface', 'name': u'vnet0'= }, {'index': '2', 'iface': 'ide', 'name': u'hdc', 'alias': u'ide0-1-0', 'sp= ecParams': {'path': ''}, 'readonly': 'True', 'deviceId': '6aad5e48-613b-48d= b-838a-fc923fb0cdd7', 'address': {u'bus': u'1', u'controller': u'0', u'type= ': u'drive', u'target': u'0', u'unit': u'0'}, 'device': 'cdrom', 'shared': = 'false', 'path': '', 'type': 'disk'}, {'address': {u'bus': u'0', u'controll= er': u'0', u'type': u'drive', u'target': u'0', u'unit': u'0'}, 'reqsize': '= 0', 'index': 0, 'iface': 'scsi', 'apparentsize': '21474836480', 'specParams= ': {}, 'imageID': '1b23ac73-0748-49cd-94b6-11555e35be81', 'readonly': 'Fals= e', 'shared': 'false', 'truesize': '17698430976', 'type': 'disk', 'domainID= ': '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545', 'volumeInfo': {'domainID': '965c= a3b6-4f9c-4e81-b6e8-5ed4a9e58545', 'volType': 'path', 'leaseOffset': 0, 'pa= th': '/rhev/data-center/mnt/10.10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e= 81-b6e8-5ed4a9e58545/images/1b23ac73-0748-49cd-94b6-11555e35be81/5156a43b-c= 9dc-40fa-a9b7-a35b7f22f0eb', 'volumeID': '5156a43b-c9dc-40fa-a9b7-a35b7f22f= 0eb', 'leasePath': '/rhev/data-center/mnt/10.10.30.251:_var_nas1_OVirtIB/96= 5ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/images/1b23ac73-0748-49cd-94b6-11555e35b= e81/5156a43b-c9dc-40fa-a9b7-a35b7f22f0eb.lease', 'imageID': '1b23ac73-0748-= 49cd-94b6-11555e35be81'}, 'format': 'raw', 'deviceId': '1b23ac73-0748-49cd-= 94b6-11555e35be81', 'poolID': '94ed7a19-fade-4bd6-83f2-2cbb2f730b95', 'devi= ce': 'disk', 'path': '/rhev/data-center/mnt/10.10.30.251:_var_nas1_OVirtIB/= 965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/images/1b23ac73-0748-49cd-94b6-11555e3= 5be81/5156a43b-c9dc-40fa-a9b7-a35b7f22f0eb', 'propagateErrors': 'off', 'opt= ional': 'false', 'name': u'sda', 'bootOrder': u'1', 'volumeID': '5156a43b-c= 9dc-40fa-a9b7-a35b7f22f0eb', 'alias': u'scsi0-0-0-0', 'volumeChain': [{'dom= ainID': '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545', 'volType': 'path', 'leaseOf= fset': 0, 'path': '/rhev/data-center/mnt/10.10.30.251:_var_nas1_OVirtIB/965= ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/images/1b23ac73-0748-49cd-94b6-11555e35be= 81/5156a43b-c9dc-40fa-a9b7-a35b7f22f0eb', 'volumeID': '5156a43b-c9dc-40fa-a= 9b7-a35b7f22f0eb', 'leasePath': '/rhev/data-center/mnt/10.10.30.251:_var_na= s1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/images/1b23ac73-0748-49cd-9= 4b6-11555e35be81/5156a43b-c9dc-40fa-a9b7-a35b7f22f0eb.lease', 'imageID': '1= b23ac73-0748-49cd-94b6-11555e35be81'}]}, {'specParams': {}, 'alias': 'sound= 0', 'deviceId': '38b39d1b-7573-4112-b04f-669402652413', 'address': {'slot':= '0x05', 'bus': '0x00', 'domain': '0x0000', 'type': 'pci', 'function': '0x0= '}, 'device': 'ich6', 'type': 'sound'}, {'target': 2097152, 'specParams': {= 'model': 'virtio'}, 'alias': 'balloon0', 'deviceId': '7c9ed232-f54e-4382-a2= 2e-f74c2b6412f4', 'address': {'slot': '0x07', 'bus': '0x00', 'domain': '0x0= 000', 'type': 'pci', 'function': '0x0'}, 'device': 'memballoon', 'type': 'b= alloon'}], 'status': 'Paused', 'display': 'qxl'} createXmlElem:<bound metho= d Drive.createXmlElem of <vm.Drive object at 0x7f356003bb90>> device:cdrom = deviceId:6aad5e48-613b-48db-838a-fc923fb0cdd7 drv:raw extSharedState:none g= etLeasesXML:<bound method Drive.getLeasesXML of <vm.Drive object at 0x7f356= 003bb90>> getNextVolumeSize:<bound method Drive.getNextVolumeSize of <vm.Dr= ive object at 0x7f356003bb90>> getXML:<bound method Drive.getXML of <vm.Dri= ve object at 0x7f356003bb90>> hasVolumeLeases:False iface:ide index:2 isDis= kReplicationInProgress:<bound method Drive.isDiskReplicationInProgress of <= vm.Drive object at 0x7f356003bb90>> isVdsmImage:<bound method Drive.isVdsmI= mage of <vm.Drive object at 0x7f356003bb90>> log:<logUtils.SimpleLogAdapter= object at 0x7f356002ef90> name:hdc networkDev:False path: readonly:True re= qsize:0 serial: shared:false specParams:{'path': ''} truesize:0 type:cdrom = volExtensionChunk:1024 watermarkLimit:536870912=0A= Traceback (most recent call last):=0A= File "/usr/share/vdsm/clientIF.py", line 356, in teardownVolumePath=0A= res =3D self.irs.teardownImage(drive['domainID'],=0A= File "/usr/share/vdsm/vm.py", line 1389, in __getitem__=0A= raise KeyError(key)=0A= KeyError: 'domainID'=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,779::task::579::TaskManager.Ta= sk::(_updateState) Task=3D`b2f2b540-29c7-436f-b28a-e3fa961e9ddd`::moving fr= om state init -> state preparing=0A= libvirtEventLoop::INFO::2014-01-30 16:17:29,779::logUtils::44::dispatcher::= (wrapper) Run and protect: teardownImage(sdUUID=3D'965ca3b6-4f9c-4e81-b6e8-= 5ed4a9e58545', spUUID=3D'94ed7a19-fade-4bd6-83f2-2cbb2f730b95', imgUUID=3D'= 1b23ac73-0748-49cd-94b6-11555e35be81', volUUID=3DNone)=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,780::resourceManager::197::Res= ourceManager.Request::(__init__) ResName=3D`Storage.965ca3b6-4f9c-4e81-b6e8= -5ed4a9e58545`ReqID=3D`ce6ba549-acf2-49fa-8b36-2194b81606a5`::Request was m= ade in '/usr/share/vdsm/storage/hsm.py' line '3283' at 'teardownImage'=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,780::resourceManager::541::Res= ourceManager::(registerResource) Trying to register resource 'Storage.965ca= 3b6-4f9c-4e81-b6e8-5ed4a9e58545' for lock type 'shared'=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,780::resourceManager::600::Res= ourceManager::(registerResource) Resource 'Storage.965ca3b6-4f9c-4e81-b6e8-= 5ed4a9e58545' is free. Now locking as 'shared' (1 active user)=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,780::resourceManager::237::Res= ourceManager.Request::(grant) ResName=3D`Storage.965ca3b6-4f9c-4e81-b6e8-5e= d4a9e58545`ReqID=3D`ce6ba549-acf2-49fa-8b36-2194b81606a5`::Granted request= =0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,780::task::811::TaskManager.Ta= sk::(resourceAcquired) Task=3D`b2f2b540-29c7-436f-b28a-e3fa961e9ddd`::_reso= urcesAcquired: Storage.965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545 (shared)=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,781::task::974::TaskManager.Ta= sk::(_decref) Task=3D`b2f2b540-29c7-436f-b28a-e3fa961e9ddd`::ref 1 aborting= False=0A= libvirtEventLoop::INFO::2014-01-30 16:17:29,781::logUtils::47::dispatcher::= (wrapper) Run and protect: teardownImage, Return response: None=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,781::task::1168::TaskManager.T= ask::(prepare) Task=3D`b2f2b540-29c7-436f-b28a-e3fa961e9ddd`::finished: Non= e=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,781::task::579::TaskManager.Ta= sk::(_updateState) Task=3D`b2f2b540-29c7-436f-b28a-e3fa961e9ddd`::moving fr= om state preparing -> state finished=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,781::resourceManager::939::Res= ourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {'S= torage.965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545': < ResourceRef 'Storage.965ca3= b6-4f9c-4e81-b6e8-5ed4a9e58545', isValid: 'True' obj: 'None'>}=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,781::resourceManager::976::Res= ourceManager.Owner::(cancelAll) Owner.cancelAll requests {}=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,782::resourceManager::615::Res= ourceManager::(releaseResource) Trying to release resource 'Storage.965ca3b= 6-4f9c-4e81-b6e8-5ed4a9e58545'=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,782::resourceManager::634::Res= ourceManager::(releaseResource) Released resource 'Storage.965ca3b6-4f9c-4e= 81-b6e8-5ed4a9e58545' (0 active users)=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,782::resourceManager::640::Res= ourceManager::(releaseResource) Resource 'Storage.965ca3b6-4f9c-4e81-b6e8-5= ed4a9e58545' is free, finding out if anyone is waiting for it.=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,782::resourceManager::648::Res= ourceManager::(releaseResource) No one is waiting for resource 'Storage.965= ca3b6-4f9c-4e81-b6e8-5ed4a9e58545', Clearing records.=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,782::task::974::TaskManager.Ta= sk::(_decref) Task=3D`b2f2b540-29c7-436f-b28a-e3fa961e9ddd`::ref 0 aborting= False=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,783::task::579::TaskManager.Ta= sk::(_updateState) Task=3D`889a75b9-0702-40d3-99da-f7994e33c40c`::moving fr= om state init -> state preparing=0A= libvirtEventLoop::INFO::2014-01-30 16:17:29,783::logUtils::44::dispatcher::= (wrapper) Run and protect: inappropriateDevices(thiefId=3D'ce64f528-9981-4e= c6-a172-9d70a00a34cd')=0A= libvirtEventLoop::INFO::2014-01-30 16:17:29,783::logUtils::47::dispatcher::= (wrapper) Run and protect: inappropriateDevices, Return response: None=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,784::task::1168::TaskManager.T= ask::(prepare) Task=3D`889a75b9-0702-40d3-99da-f7994e33c40c`::finished: Non= e=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,784::task::579::TaskManager.Ta= sk::(_updateState) Task=3D`889a75b9-0702-40d3-99da-f7994e33c40c`::moving fr= om state preparing -> state finished=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,784::resourceManager::939::Res= ourceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}= =0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,784::resourceManager::976::Res= ourceManager.Owner::(cancelAll) Owner.cancelAll requests {}=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,784::task::974::TaskManager.Ta= sk::(_decref) Task=3D`889a75b9-0702-40d3-99da-f7994e33c40c`::ref 0 aborting= False=0A= Thread-285248::DEBUG::2014-01-30 16:17:29,787::BindingXMLRPC::974::vds::(wr= apper) client [192.168.11.42]::call vmDestroy with ('ce64f528-9981-4ec6-a17= 2-9d70a00a34cd',) {}=0A= Thread-285248::INFO::2014-01-30 16:17:29,787::API::318::vds::(destroy) vmCo= ntainerLock acquired by vm ce64f528-9981-4ec6-a172-9d70a00a34cd=0A= Thread-285248::DEBUG::2014-01-30 16:17:29,787::vm::4374::vm.Vm::(destroy) v= mId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::destroy Called=0A= Thread-285248::DEBUG::2014-01-30 16:17:29,788::vm::4368::vm.Vm::(deleteVm) = vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Total desktops after destroy= of ce64f528-9981-4ec6-a172-9d70a00a34cd is 0=0A= Thread-285248::DEBUG::2014-01-30 16:17:29,788::BindingXMLRPC::981::vds::(wr= apper) return vmDestroy with {'status': {'message': 'Machine destroyed', 'c= ode': 0}}=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,792::libvirtconnection::108::l= ibvirtconnection::(wrapper) Unknown libvirterror: ecode: 42 edom: 10 level:= 2 message: Domain nicht gefunden: Keine Domain mit ?bereinstimmender UUID = 'ce64f528-9981-4ec6-a172-9d70a00a34cd' (Win7x64_Master)=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,792::vm::2577::vm.Vm::(setDown= Status) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Changed state to Dow= n: Lost connection with qemu process=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,792::sampling::292::vm.Vm::(st= op) vmId=3D`ce64f528-9981-4ec6-a172-9d70a00a34cd`::Stop statistics collecti= on=0A= libvirtEventLoop::DEBUG::2014-01-30 16:17:29,793::libvirtconnection::108::l= ibvirtconnection::(wrapper) Unknown libvirterror: ecode: 42 edom: 10 level:= 2 message: Domain nicht gefunden: Keine Domain mit ?bereinstimmender UUID = 'ce64f528-9981-4ec6-a172-9d70a00a34cd' (Win7x64_Master)=0A= Thread-47::DEBUG::2014-01-30 16:17:30,113::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-47::DEBUG::2014-01-30 16:17:30,120::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n363 b= ytes (363 B) copied, 0.000169437 s, 2.1 MB/s\n'; <rc> =3D 0=0A= VM Channels Listener::DEBUG::2014-01-30 16:17:30,731::vmChannels::112::vds:= :(_do_del_channels) fileno 98 was removed from listener.=0A= Thread-41::DEBUG::2014-01-30 16:17:31,606::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-41::DEBUG::2014-01-30 16:17:31,612::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000246606 s, 2.3 MB/s\n'; <rc> =3D 0=0A= Thread-285249::DEBUG::2014-01-30 16:17:32,200::task::579::TaskManager.Task:= :(_updateState) Task=3D`e44ca35a-0638-43b2-99b7-85790a96f8a2`::moving from = state init -> state preparing=0A= Thread-285249::INFO::2014-01-30 16:17:32,200::logUtils::44::dispatcher::(wr= apper) Run and protect: repoStats(options=3DNone)=0A= Thread-285249::INFO::2014-01-30 16:17:32,201::logUtils::47::dispatcher::(wr= apper) Run and protect: repoStats, Return response: {'2c51d320-88ce-4f23-82= 15-e15f55f66906': {'delay': '0.000195778', 'lastCheck': '4.3', 'code': 0, '= valid': True, 'version': 3}, '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545': {'dela= y': '0.000246606', 'lastCheck': '0.6', 'code': 0, 'valid': True, 'version':= 3}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'delay': '0.00021875', 'lastC= heck': '3.8', 'code': 0, 'valid': True, 'version': 0}, '63041fa9-e093-4b44-= b36f-f39f16d3974f': {'delay': '0.000169437', 'lastCheck': '2.1', 'code': 0,= 'valid': True, 'version': 0}, '272ec473-6041-42ee-bd1a-732789dd18d4': {'de= lay': '0.000195213', 'lastCheck': '7.7', 'code': 0, 'valid': True, 'version= ': 3}}=0A= Thread-285249::DEBUG::2014-01-30 16:17:32,201::task::1168::TaskManager.Task= ::(prepare) Task=3D`e44ca35a-0638-43b2-99b7-85790a96f8a2`::finished: {'2c51= d320-88ce-4f23-8215-e15f55f66906': {'delay': '0.000195778', 'lastCheck': '4= .3', 'code': 0, 'valid': True, 'version': 3}, '965ca3b6-4f9c-4e81-b6e8-5ed4= a9e58545': {'delay': '0.000246606', 'lastCheck': '0.6', 'code': 0, 'valid':= True, 'version': 3}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'delay': '0.= 00021875', 'lastCheck': '3.8', 'code': 0, 'valid': True, 'version': 0}, '63= 041fa9-e093-4b44-b36f-f39f16d3974f': {'delay': '0.000169437', 'lastCheck': = '2.1', 'code': 0, 'valid': True, 'version': 0}, '272ec473-6041-42ee-bd1a-73= 2789dd18d4': {'delay': '0.000195213', 'lastCheck': '7.7', 'code': 0, 'valid= ': True, 'version': 3}}=0A= Thread-285249::DEBUG::2014-01-30 16:17:32,201::task::579::TaskManager.Task:= :(_updateState) Task=3D`e44ca35a-0638-43b2-99b7-85790a96f8a2`::moving from = state preparing -> state finished=0A= Thread-285249::DEBUG::2014-01-30 16:17:32,201::resourceManager::939::Resour= ceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}=0A= Thread-285249::DEBUG::2014-01-30 16:17:32,201::resourceManager::976::Resour= ceManager.Owner::(cancelAll) Owner.cancelAll requests {}=0A= Thread-285249::DEBUG::2014-01-30 16:17:32,201::task::974::TaskManager.Task:= :(_decref) Task=3D`e44ca35a-0638-43b2-99b7-85790a96f8a2`::ref 0 aborting Fa= lse=0A= Thread-52::DEBUG::2014-01-30 16:17:34,531::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-52::DEBUG::2014-01-30 16:17:34,538::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000202672 s, 2.7 MB/s\n'; <rc> =3D 0=0A= Thread-40::DEBUG::2014-01-30 16:17:37,893::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-40::DEBUG::2014-01-30 16:17:37,899::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n645 b= ytes (645 B) copied, 0.000200736 s, 3.2 MB/s\n'; <rc> =3D 0=0A= Thread-42::DEBUG::2014-01-30 16:17:38,418::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-42::DEBUG::2014-01-30 16:17:38,423::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n357 b= ytes (357 B) copied, 0.000239232 s, 1.5 MB/s\n'; <rc> =3D 0=0A= Thread-47::DEBUG::2014-01-30 16:17:40,132::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-47::DEBUG::2014-01-30 16:17:40,137::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n363 b= ytes (363 B) copied, 0.000199954 s, 1.8 MB/s\n'; <rc> =3D 0=0A= Thread-41::DEBUG::2014-01-30 16:17:41,622::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-41::DEBUG::2014-01-30 16:17:41,628::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000177973 s, 3.1 MB/s\n'; <rc> =3D 0=0A= Thread-52::DEBUG::2014-01-30 16:17:44,549::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-52::DEBUG::2014-01-30 16:17:44,555::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000217367 s, 2.6 MB/s\n'; <rc> =3D 0=0A= Thread-285255::DEBUG::2014-01-30 16:17:47,564::task::579::TaskManager.Task:= :(_updateState) Task=3D`feb38342-e432-4cdf-afc4-39582ee67c68`::moving from = state init -> state preparing=0A= Thread-285255::INFO::2014-01-30 16:17:47,564::logUtils::44::dispatcher::(wr= apper) Run and protect: repoStats(options=3DNone)=0A= Thread-285255::INFO::2014-01-30 16:17:47,564::logUtils::47::dispatcher::(wr= apper) Run and protect: repoStats, Return response: {'2c51d320-88ce-4f23-82= 15-e15f55f66906': {'delay': '0.000200736', 'lastCheck': '9.7', 'code': 0, '= valid': True, 'version': 3}, '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545': {'dela= y': '0.000177973', 'lastCheck': '5.9', 'code': 0, 'valid': True, 'version':= 3}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'delay': '0.000239232', 'last= Check': '9.1', 'code': 0, 'valid': True, 'version': 0}, '63041fa9-e093-4b44= -b36f-f39f16d3974f': {'delay': '0.000199954', 'lastCheck': '7.4', 'code': 0= , 'valid': True, 'version': 0}, '272ec473-6041-42ee-bd1a-732789dd18d4': {'d= elay': '0.000217367', 'lastCheck': '3.0', 'code': 0, 'valid': True, 'versio= n': 3}}=0A= Thread-285255::DEBUG::2014-01-30 16:17:47,564::task::1168::TaskManager.Task= ::(prepare) Task=3D`feb38342-e432-4cdf-afc4-39582ee67c68`::finished: {'2c51= d320-88ce-4f23-8215-e15f55f66906': {'delay': '0.000200736', 'lastCheck': '9= .7', 'code': 0, 'valid': True, 'version': 3}, '965ca3b6-4f9c-4e81-b6e8-5ed4= a9e58545': {'delay': '0.000177973', 'lastCheck': '5.9', 'code': 0, 'valid':= True, 'version': 3}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'delay': '0.= 000239232', 'lastCheck': '9.1', 'code': 0, 'valid': True, 'version': 0}, '6= 3041fa9-e093-4b44-b36f-f39f16d3974f': {'delay': '0.000199954', 'lastCheck':= '7.4', 'code': 0, 'valid': True, 'version': 0}, '272ec473-6041-42ee-bd1a-7= 32789dd18d4': {'delay': '0.000217367', 'lastCheck': '3.0', 'code': 0, 'vali= d': True, 'version': 3}}=0A= Thread-285255::DEBUG::2014-01-30 16:17:47,565::task::579::TaskManager.Task:= :(_updateState) Task=3D`feb38342-e432-4cdf-afc4-39582ee67c68`::moving from = state preparing -> state finished=0A= Thread-285255::DEBUG::2014-01-30 16:17:47,565::resourceManager::939::Resour= ceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}=0A= Thread-285255::DEBUG::2014-01-30 16:17:47,565::resourceManager::976::Resour= ceManager.Owner::(cancelAll) Owner.cancelAll requests {}=0A= Thread-285255::DEBUG::2014-01-30 16:17:47,565::task::974::TaskManager.Task:= :(_decref) Task=3D`feb38342-e432-4cdf-afc4-39582ee67c68`::ref 0 aborting Fa= lse=0A= Thread-40::DEBUG::2014-01-30 16:17:47,913::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-40::DEBUG::2014-01-30 16:17:47,919::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n645 b= ytes (645 B) copied, 0.000156636 s, 4.1 MB/s\n'; <rc> =3D 0=0A= Thread-42::DEBUG::2014-01-30 16:17:48,435::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-42::DEBUG::2014-01-30 16:17:48,440::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n357 b= ytes (357 B) copied, 0.000219512 s, 1.6 MB/s\n'; <rc> =3D 0=0A= Thread-47::DEBUG::2014-01-30 16:17:50,153::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-47::DEBUG::2014-01-30 16:17:50,158::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n363 b= ytes (363 B) copied, 0.000129306 s, 2.8 MB/s\n'; <rc> =3D 0=0A= Thread-41::DEBUG::2014-01-30 16:17:51,639::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-41::DEBUG::2014-01-30 16:17:51,645::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000299809 s, 1.9 MB/s\n'; <rc> =3D 0=0A= Thread-52::DEBUG::2014-01-30 16:17:54,565::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-52::DEBUG::2014-01-30 16:17:54,571::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.00023204 s, 2.4 MB/s\n'; <rc> =3D 0=0A= Thread-40::DEBUG::2014-01-30 16:17:57,934::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-40::DEBUG::2014-01-30 16:17:57,940::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n645 b= ytes (645 B) copied, 0.000197083 s, 3.3 MB/s\n'; <rc> =3D 0=0A= Thread-42::DEBUG::2014-01-30 16:17:58,453::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-42::DEBUG::2014-01-30 16:17:58,458::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n357 b= ytes (357 B) copied, 0.000150387 s, 2.4 MB/s\n'; <rc> =3D 0=0A= Thread-47::DEBUG::2014-01-30 16:18:00,168::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-47::DEBUG::2014-01-30 16:18:00,174::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n363 b= ytes (363 B) copied, 0.000222782 s, 1.6 MB/s\n'; <rc> =3D 0=0A= Thread-41::DEBUG::2014-01-30 16:18:01,655::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-41::DEBUG::2014-01-30 16:18:01,661::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000197351 s, 2.8 MB/s\n'; <rc> =3D 0=0A= Thread-285261::DEBUG::2014-01-30 16:18:02,942::task::579::TaskManager.Task:= :(_updateState) Task=3D`5683bb8f-2158-4c8f-a263-46b6e7a086da`::moving from = state init -> state preparing=0A= Thread-285261::INFO::2014-01-30 16:18:02,943::logUtils::44::dispatcher::(wr= apper) Run and protect: repoStats(options=3DNone)=0A= Thread-285261::INFO::2014-01-30 16:18:02,943::logUtils::47::dispatcher::(wr= apper) Run and protect: repoStats, Return response: {'2c51d320-88ce-4f23-82= 15-e15f55f66906': {'delay': '0.000197083', 'lastCheck': '5.0', 'code': 0, '= valid': True, 'version': 3}, '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545': {'dela= y': '0.000197351', 'lastCheck': '1.3', 'code': 0, 'valid': True, 'version':= 3}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'delay': '0.000150387', 'last= Check': '4.5', 'code': 0, 'valid': True, 'version': 0}, '63041fa9-e093-4b44= -b36f-f39f16d3974f': {'delay': '0.000222782', 'lastCheck': '2.8', 'code': 0= , 'valid': True, 'version': 0}, '272ec473-6041-42ee-bd1a-732789dd18d4': {'d= elay': '0.00023204', 'lastCheck': '8.4', 'code': 0, 'valid': True, 'version= ': 3}}=0A= Thread-285261::DEBUG::2014-01-30 16:18:02,943::task::1168::TaskManager.Task= ::(prepare) Task=3D`5683bb8f-2158-4c8f-a263-46b6e7a086da`::finished: {'2c51= d320-88ce-4f23-8215-e15f55f66906': {'delay': '0.000197083', 'lastCheck': '5= .0', 'code': 0, 'valid': True, 'version': 3}, '965ca3b6-4f9c-4e81-b6e8-5ed4= a9e58545': {'delay': '0.000197351', 'lastCheck': '1.3', 'code': 0, 'valid':= True, 'version': 3}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'delay': '0.= 000150387', 'lastCheck': '4.5', 'code': 0, 'valid': True, 'version': 0}, '6= 3041fa9-e093-4b44-b36f-f39f16d3974f': {'delay': '0.000222782', 'lastCheck':= '2.8', 'code': 0, 'valid': True, 'version': 0}, '272ec473-6041-42ee-bd1a-7= 32789dd18d4': {'delay': '0.00023204', 'lastCheck': '8.4', 'code': 0, 'valid= ': True, 'version': 3}}=0A= Thread-285261::DEBUG::2014-01-30 16:18:02,944::task::579::TaskManager.Task:= :(_updateState) Task=3D`5683bb8f-2158-4c8f-a263-46b6e7a086da`::moving from = state preparing -> state finished=0A= Thread-285261::DEBUG::2014-01-30 16:18:02,944::resourceManager::939::Resour= ceManager.Owner::(releaseAll) Owner.releaseAll requests {} resources {}=0A= Thread-285261::DEBUG::2014-01-30 16:18:02,944::resourceManager::976::Resour= ceManager.Owner::(cancelAll) Owner.cancelAll requests {}=0A= Thread-285261::DEBUG::2014-01-30 16:18:02,944::task::974::TaskManager.Task:= :(_decref) Task=3D`5683bb8f-2158-4c8f-a263-46b6e7a086da`::ref 0 aborting Fa= lse=0A= Thread-52::DEBUG::2014-01-30 16:18:04,581::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-52::DEBUG::2014-01-30 16:18:04,588::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000218219 s, 2.6 MB/s\n'; <rc> =3D 0=0A= Thread-40::DEBUG::2014-01-30 16:18:07,953::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-40::DEBUG::2014-01-30 16:18:07,959::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n645 b= ytes (645 B) copied, 0.00019818 s, 3.3 MB/s\n'; <rc> =3D 0=0A= Thread-42::DEBUG::2014-01-30 16:18:08,470::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtISO/bff3a2be-fdd9-4e37-b416-fa4ef7fafba2/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-42::DEBUG::2014-01-30 16:18:08,475::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n357 b= ytes (357 B) copied, 0.000178019 s, 2.0 MB/s\n'; <rc> =3D 0=0A= Thread-47::DEBUG::2014-01-30 16:18:10,186::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtEXP/63041fa9-e093-4b44-b36f-f39f16d3974f/dom_md/me= tadata bs=3D4096 count=3D1' (cwd None)=0A= Thread-47::DEBUG::2014-01-30 16:18:10,192::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n363 b= ytes (363 B) copied, 0.000189951 s, 1.9 MB/s\n'; <rc> =3D 0=0A= Thread-41::DEBUG::2014-01-30 16:18:11,671::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.251:_var_nas1_OVirtIB/965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-41::DEBUG::2014-01-30 16:18:11,677::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000247616 s, 2.2 MB/s\n'; <rc> =3D 0=0A= Thread-52::DEBUG::2014-01-30 16:18:14,598::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.252:_var_nas2_OVirtIB/272ec473-6041-42ee-bd1a-732789dd18d4/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-52::DEBUG::2014-01-30 16:18:14,604::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n557 b= ytes (557 B) copied, 0.000208255 s, 2.7 MB/s\n'; <rc> =3D 0=0A= Thread-40::DEBUG::2014-01-30 16:18:17,974::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) '/usr/bin/dd iflag=3Ddirect if=3D/rhev/data-center/mnt/10.= 10.30.253:_var_nas3_OVirtIB/2c51d320-88ce-4f23-8215-e15f55f66906/dom_md/met= adata bs=3D4096 count=3D1' (cwd None)=0A= Thread-40::DEBUG::2014-01-30 16:18:17,979::fileSD::239::Storage.Misc.excCmd= ::(getReadDelay) SUCCESS: <err> =3D '0+1 records in\n0+1 records out\n645 b= ytes (645 B) copied, 0.000217282 s, 3.0 MB/s\n'; <rc> =3D 0=0A= Thread-285267::DEBUG::2014-01-30 16:18:18,464::task::579::TaskManager.Task:= :(_updateState) Task=3D`1e0fc684-6d0b-4694-996c-728b66ae9fc2`::moving from = state init -> state preparing=0A= Thread-285267::INFO::2014-01-30 16:18:18,465::logUtils::44::dispatcher::(wr= apper) Run and protect: repoStats(options=3DNone)=0A= Thread-285267::INFO::2014-01-30 16:18:18,465::logUtils::47::dispatcher::(wr= apper) Run and protect: repoStats, Return response: {'2c51d320-88ce-4f23-82= 15-e15f55f66906': {'delay': '0.000217282', 'lastCheck': '0.5', 'code': 0, '= valid': True, 'version': 3}, '965ca3b6-4f9c-4e81-b6e8-5ed4a9e58545': {'dela= y': '0.000247616', 'lastCheck': '6.8', 'code': 0, 'valid': True, 'version':= 3}, 'bff3a2be-fdd9-4e37-b416-fa4ef7fafba2': {'delay': '0.000178019', 'last= Check': '10.0', 'code': 0, 'valid': True, 'version': 0}, '63041fa9-e093-4b4= 4-b36f-f39f16d3974f': {'delay': '0.000189951', 'lastCheck': '8.3', 'code': = 0, 'valid': True, 'version': 0}, '272ec473-6041-42ee-bd1a-732789dd18d4': {'= delay': '0.000208255', 'lastCheck': '3.9', 'code': 0, 'valid': True, 'versi= on': 3}}=0A= ------=_NextPartTM-000-16e476a9-dc0a-459b-91a5-33c52e66e68f Content-Type: text/plain; name="InterScan_Disclaimer.txt" Content-Transfer-Encoding: 7bit Content-Disposition: attachment; filename="InterScan_Disclaimer.txt" **************************************************************************** Diese E-Mail enthält vertrauliche und/oder rechtlich geschützte Informationen. Wenn Sie nicht der richtige Adressat sind oder diese E-Mail irrtümlich erhalten haben, informieren Sie bitte sofort den Absender und vernichten Sie diese Mail. Das unerlaubte Kopieren sowie die unbefugte Weitergabe dieser Mail ist nicht gestattet. Über das Internet versandte E-Mails können unter fremden Namen erstellt oder manipuliert werden. Deshalb ist diese als E-Mail verschickte Nachricht keine rechtsverbindliche Willenserklärung. Collogia Unternehmensberatung AG Ubierring 11 D-50678 Köln Vorstand: Kadir Akin Dr. Michael Höhnerbach Vorsitzender des Aufsichtsrates: Hans Kristian Langva Registergericht: Amtsgericht Köln Registernummer: HRB 52 497 This e-mail may contain confidential and/or privileged information. If you are not the intended recipient (or have received this e-mail in error) please notify the sender immediately and destroy this e-mail. Any unauthorized copying, disclosure or distribution of the material in this e-mail is strictly forbidden. e-mails sent over the internet may have been written under a wrong name or been manipulated. That is why this message sent as an e-mail is not a legally binding declaration of intention. Collogia Unternehmensberatung AG Ubierring 11 D-50678 Köln executive board: Kadir Akin Dr. Michael Höhnerbach President of the supervisory board: Hans Kristian Langva Registry office: district court Cologne Register number: HRB 52 497 **************************************************************************** ------=_NextPartTM-000-16e476a9-dc0a-459b-91a5-33c52e66e68f--

5 11

[Users] (quick tip) Controlling glusterfsd CPU outbreaks with cgroups
by Andrew Lau 03 Feb '14

03 Feb '14

Hi all, I've seen quite a few posts with people using similar scenarios of running gluster and ovirt on the same physical box so I think this may be relevant. After some discussions on the gluster mailing list, I put together a quick post [1] about how you can limit glusters CPU resources so when it comes to self-healing etc. your VMs will have higher priority and not crawl to a halt when glusterfsd takes all the resources. So far, I haven't been able to apply these cgroup rules without losing the dynamic ones set by libvirt so you must do this in maintenance mode followed by a full host restart after following those instructions. I'm open to suggestions and feedback. Thanks, Andre w [1] http://www.andrewklau.com/controlling-glusterfsd-cpu-outbreaks-with-cgroups/

1 0

[Users] oVirt January 2014 Updates
by Itamar Heim 03 Feb '14

03 Feb '14

1. VERSIONS - oVirt 3.3.3 in last phases http://www.ovirt.org/OVirt_3.3.3_release_notes - oVirt 3.4 with another slew of features is getting into test day, beta, etc. http://red.ht/1eo9TiS 2. WORKSHOPS - Fosdem - oVirt stand wass packed as well as a virt & IaaS devroom, with many oVirt talks. more details next time. - more oVirt talks in cfgmgmtcamp and infra.next this week, including: -- Hervé Leclerc "How we build a cloud with CentOS, oVirt, and Cisco-UCS" Wednesday 5th February in Infrastructure.Next Ghent http://bit.ly/1fjTJVC -- oVirt Node being used as a Discovery Node in The Foreman project talk at cfgmgmtcamp, february 3rd http://bit.ly/1gAnneI - oVirt Korea group meeting this Saturday in Seoul Register here http://onoffmix.com/event/23134 - Open Virtualization Workshop in Tehran (26,27 February 2014) & Isfahan (5,6 March 2014) http://t.co/9PR3BxOnpd 3. USING oVirt - More details on Wind River using ovirt http://bit.ly/1i2LtLI - New Case Study: Nieuwland Geo-Informati http://www.ovirt.org/Nieuwland_case_study - oVirt Node being used as a Discovery Node in The Foreman project talk at cfgmgmtcamp, february 3rd http://bit.ly/1gAnneI 4. Users - Double the amount of emails on users mailing list- up from 800 to 1600 this month! - Karli updated how to use spice with ovirt from OS X http://www.ovirt.org/SPICE_Remote-Viewer_on_OS_X - Opaque (spice android ovirt client) v1.1.8 beta released https://plus.google.com/communities/116099119712127782216 - how to deploy windows guest agent on windows: http://bit.ly/1kr5tJo - Andrew Lau posted on working through Hosted Engine with 3.4.0 beta http://bit.ly/1eobzZw - Deep Dive into oVirt 3.3.3 by Li Jiansheng (chinese) http://slidesha.re/1eFWQ8G - Matthew Bingham posted a series of video on setting up ovirt: Install oVirt 3.3.2 http://www.youtube.com/watch?v=GWT-m-oWSjQ Optional export nfs mount for oVirt 3.3.2 http://www.youtube.com/watch?v=MLbPln5-2jE Initial webgui oVirt 3.3.2 Steps for storage http://www.youtube.com/watch?v=dL0_03ZICw4 Download and upload client iso to ISO_DOMAIN for oVirt 3.3.2 http://www.youtube.com/watch?v=pDzTHFSmvGE

2 1

Re: [Users] Users Digest, Vol 29, Issue 20
by Juan Pablo Lorier 03 Feb '14

03 Feb '14

This is an OpenPGP/MIME signed message (RFC 4880 and 3156) --SrctK3eHuNcu9HUllglOI7BKUK26Qjgpj Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable Hi, I have to appologise as I moved the page after sending to the list. Here it is: http://www.ovirt.org/Change_network_interface_for_Gluster Matt: I don't get your post, are you suggesting me to start like that? Regards, --SrctK3eHuNcu9HUllglOI7BKUK26Qjgpj Content-Type: application/pgp-signature; name="signature.asc" Content-Description: OpenPGP digital signature Content-Disposition: attachment; filename="signature.asc" -----BEGIN PGP SIGNATURE----- Version: GnuPG v1 Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/ iQEcBAEBAgAGBQJS79RrAAoJEC5KDDg2+NMMNzMIAK3Tt5mavkFq/OE3FKyEysGP CkI8CW78sbIUF+sTQJk5T197QHmDjCqz5mkUpjebBXhqkugnSRHuBPMm4/q/64TQ MgYNFTJRw/UaEsH5jshwT9aZpDM4OPE/1/DyHti5LkLZ6mj8YOM+gj5XQKZ9+UPc STDZ4pHvQGgUihfLK1fxin79ex4Y3eu57y3GJniHozFlwR6aAKBfehgpOsJaOmzv A5Da/N/VNqLNYWyGcAY/e+W3OJlhzh3J2BCsOH/W0RQGpkv3BXxSp6mKec3jY9ps cZgsc/eW9inWul9EYIosrpxXaIx0cXdvyFhuHi2pZ5nGiL2dt+WUCh7JLrgNO7g= =+E37 -----END PGP SIGNATURE----- --SrctK3eHuNcu9HUllglOI7BKUK26Qjgpj--

1 0

[Users] oVirt 3.3.3 release
by Sandro Bonazzola 03 Feb '14

03 Feb '14

The oVirt development team is very happy to announce the general availability of oVirt 3.3.3 as of February 3rd 2013. This release solidifies oVirt as a leading KVM management application and open source alternative to VMware vSphere. oVirt is available now for Fedora 19 and Red Hat Enterprise Linux 6.5 (or similar). This release of oVirt includes numerous bug fixes. See the release notes [1] for a list of the new features and bugs fixed. IMPORTANT NOTE: If you're upgrading from a previous version, please update ovirt-release to the latest version (10.0.1-3) and verify you have the correct repositories enabled by running the following commands # yum update ovirt-release # yum repolist enabled before upgrading with the usual procedure. You should see the ovirt-3.3.3 and ovirt-stable repositories listed in the output of the repolist command. A new oVirt Node build will be available soon as well. [1] http://www.ovirt.org/OVirt_3.3.3_release_notes -- Sandro Bonazzola Better technology. Faster innovation. Powered by community collaboration. See how it works at redhat.com

1 0

[Users] ovirt-3.3.3 release postponed due to blockers
by Sandro Bonazzola 03 Feb '14

03 Feb '14

Hi, oVirt 3.3.3 release need to be postponed. A recent release of python-cpopen-1.3 is breaking dependency resolution on EL6 and F19 so vdsm can't be installed and node can't be composed. A recent change in vdsm-python-cpopen added the needed conflict against python-cpopen and removed Provides / Obsoletes on python-cpopen. But no new releases of python-cpopen is available fixing the correct Provides / Obsoletes pair. oVirt 3.3.2 / stable is affected too. Please fix Bug 1056470 - python-cpopen-1.3 is not providing obsoleted package. Bug 1056464 - python-cpopen-1.3 is not providing obsoleted package. ASAP. -- Sandro Bonazzola Better technology. Faster innovation. Powered by community collaboration. See how it works at redhat.com

11 26

[Users] I can't remove VM
by Eduardo Ramos 03 Feb '14

03 Feb '14

This is a multi-part message in MIME format. --------------090502050908090103050606 Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit Hi all! I'm having trouble on removing virtual machines. My environment run on a ISCSI domain storage. When I try remove, the SPM logs: # Start vdsm SPM log # Thread-6019517::INFO::2014-02-03 09:58:09,293::logUtils::41::dispatcher::(wrapper) Run and protect: deleteImage(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', imgUUID='57ba1906-2035-4503-acbc-5f6f077f75cc', postZero='false', force='false') Thread-6019517::INFO::2014-02-03 09:58:09,293::blockSD::816::Storage.StorageDomain::(validate) sdUUID=c332da29-ba9f-4c94-8fa9-346bb8e04e2a Thread-6019517::ERROR::2014-02-03 09:58:10,061::task::833::TaskManager.Task::(_setError) Task=`8cbf9978-ed51-488a-af52-a3db030e44ff`::Unexpected error Traceback (most recent call last): File "/usr/share/vdsm/storage/task.py", line 840, in _run return fn(*args, **kargs) File "/usr/share/vdsm/logUtils.py", line 42, in wrapper res = f(*args, **kwargs) File "/usr/share/vdsm/storage/hsm.py", line 1429, in deleteImage allVols = dom.getAllVolumes() File "/usr/share/vdsm/storage/blockSD.py", line 972, in getAllVolumes return getAllVolumes(self.sdUUID) File "/usr/share/vdsm/storage/blockSD.py", line 172, in getAllVolumes vImg not in res[vPar]['imgs']): KeyError: '63650a24-7e83-4c0a-851d-0ce9869a294d' Thread-6019517::INFO::2014-02-03 09:58:10,063::task::1134::TaskManager.Task::(prepare) Task=`8cbf9978-ed51-488a-af52-a3db030e44ff`::aborting: Task is aborted: u"'63650a24-7e83-4c0a-851d-0ce9869a294d'" - code 100 Thread-6019517::ERROR::2014-02-03 09:58:10,066::dispatcher::70::Storage.Dispatcher.Protect::(run) '63650a24-7e83-4c0a-851d-0ce9869a294d' Traceback (most recent call last): File "/usr/share/vdsm/storage/dispatcher.py", line 62, in run result = ctask.prepare(self.func, *args, **kwargs) File "/usr/share/vdsm/storage/task.py", line 1142, in prepare raise self.error KeyError: '63650a24-7e83-4c0a-851d-0ce9869a294d' Thread-6019518::INFO::2014-02-03 09:58:10,087::logUtils::41::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', options=None) Thread-6019518::INFO::2014-02-03 09:58:10,088::logUtils::44::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 14, 'spmStatus': 'SPM', 'spmLver': 64}} Thread-6019519::INFO::2014-02-03 09:58:10,100::logUtils::41::dispatcher::(wrapper) Run and protect: getAllTasksStatuses(spUUID=None, options=None) Thread-6019519::INFO::2014-02-03 09:58:10,101::logUtils::44::dispatcher::(wrapper) Run and protect: getAllTasksStatuses, Return response: {'allTasksStatus': {}} Thread-6019520::INFO::2014-02-03 09:58:10,109::logUtils::41::dispatcher::(wrapper) Run and protect: spmStop(spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', options=None) Thread-6019520::INFO::2014-02-03 09:58:10,681::clusterlock::121::SafeLease::(release) Releasing cluster lock for domain c332da29-ba9f-4c94-8fa9-346bb8e04e2a Thread-6019521::INFO::2014-02-03 09:58:11,054::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-6019521::INFO::2014-02-03 09:58:11,054::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'51eb6183-157d-4015-ae0f-1c7ffb1731c0': {'delay': '0.00799298286438', 'lastCheck': '5.3', 'code': 0, 'valid': True}, u'c332da29-ba9f-4c94-8fa9-346bb8e04e2a': {'delay': '0.0197920799255', 'lastCheck': '4.9', 'code': 0, 'valid': True}, u'0e0be898-6e04-4469-bb32-91f3cf8146d1': {'delay': '0.00803208351135', 'lastCheck': '5.3', 'code': 0, 'valid': True}} Thread-6019520::INFO::2014-02-03 09:58:11,732::logUtils::44::dispatcher::(wrapper) Run and protect: spmStop, Return response: None Thread-6019523::INFO::2014-02-03 09:58:11,835::logUtils::41::dispatcher::(wrapper) Run and protect: getAllTasksStatuses(spUUID=None, options=None) Thread-6019523::INFO::2014-02-03 09:58:11,835::logUtils::44::dispatcher::(wrapper) Run and protect: getAllTasksStatuses, Return response: {'allTasksStatus': {}} Thread-6019524::INFO::2014-02-03 09:58:11,844::logUtils::41::dispatcher::(wrapper) Run and protect: spmStop(spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', options=None) Thread-6019524::ERROR::2014-02-03 09:58:11,846::task::833::TaskManager.Task::(_setError) Task=`00df5ff7-bbf4-4a0e-b60b-1b06dcaa7683`::Unexpected error Traceback (most recent call last): File "/usr/share/vdsm/storage/task.py", line 840, in _run return fn(*args, **kargs) File "/usr/share/vdsm/logUtils.py", line 42, in wrapper res = f(*args, **kwargs) File "/usr/share/vdsm/storage/hsm.py", line 601, in spmStop pool.stopSpm() File "/usr/share/vdsm/storage/securable.py", line 66, in wrapper raise SecureError() SecureError Thread-6019524::INFO::2014-02-03 09:58:11,855::task::1134::TaskManager.Task::(prepare) Task=`00df5ff7-bbf4-4a0e-b60b-1b06dcaa7683`::aborting: Task is aborted: u'' - code 100 Thread-6019524::ERROR::2014-02-03 09:58:11,857::dispatcher::70::Storage.Dispatcher.Protect::(run) Traceback (most recent call last): File "/usr/share/vdsm/storage/dispatcher.py", line 62, in run result = ctask.prepare(self.func, *args, **kwargs) File "/usr/share/vdsm/storage/task.py", line 1142, in prepare raise self.error SecureError Dummy-6018624::INFO::2014-02-03 09:58:14,220::storage_mailbox::674::Storage.MailBox.SpmMailMonitor::(run) SPM_MailMonitor - Incoming mail monitoring thread stopped Thread-34627::INFO::2014-02-03 09:58:17,696::logUtils::41::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', imgUUID='974d9602-8fbe-485b-a12d-59b6c34826b7', volUUID='c1bcfe5c-20ab-4f50-a88b-e2e0e1184bf8', options=None) Thread-34757::INFO::2014-02-03 09:58:17,696::logUtils::41::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', imgUUID='49f65bfd-8592-42b9-9a31-91268402903f', volUUID='511e6584-4f19-426d-9379-b223d0c2d9c6', options=None) Thread-34627::INFO::2014-02-03 09:58:17,697::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '10737418240', 'apparentsize': '10737418240'} Thread-34757::INFO::2014-02-03 09:58:17,698::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '32212254720', 'apparentsize': '32212254720'} Thread-6019529::INFO::2014-02-03 09:58:21,672::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-6019529::INFO::2014-02-03 09:58:21,673::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'51eb6183-157d-4015-ae0f-1c7ffb1731c0': {'delay': '0.00730204582214', 'lastCheck': '5.9', 'code': 0, 'valid': True}, u'c332da29-ba9f-4c94-8fa9-346bb8e04e2a': {'delay': '0.0207469463348', 'lastCheck': '5.3', 'code': 0, 'valid': True}, u'0e0be898-6e04-4469-bb32-91f3cf8146d1': {'delay': '0.00734615325928', 'lastCheck': '5.9', 'code': 0, 'valid': True}} Thread-243::INFO::2014-02-03 09:58:27,800::logUtils::41::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', imgUUID='50f2c3e9-aa94-4ad1-9c3f-91b452292374', volUUID='d7cddb76-a5b7-49ed-9efe-44d92ec18d93', options=None) Thread-34590::INFO::2014-02-03 09:58:27,801::logUtils::41::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', imgUUID='c36bb1da-babd-47bd-a406-58f0cb529c00', volUUID='6ea83f9e-c614-4e11-ab57-314ed4efeeaa', options=None) Thread-243::INFO::2014-02-03 09:58:27,802::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '10737418240', 'apparentsize': '10737418240'} Thread-34590::INFO::2014-02-03 09:58:27,803::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '107374182400', 'apparentsize': '107374182400'} Thread-6019535::INFO::2014-02-03 09:58:32,337::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-6019535::INFO::2014-02-03 09:58:32,337::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'51eb6183-157d-4015-ae0f-1c7ffb1731c0': {'delay': '0.0119340419769', 'lastCheck': '6.6', 'code': 0, 'valid': True}, u'c332da29-ba9f-4c94-8fa9-346bb8e04e2a': {'delay': '0.0190720558167', 'lastCheck': '6.0', 'code': 0, 'valid': True}, u'0e0be898-6e04-4469-bb32-91f3cf8146d1': {'delay': '0.00720596313477', 'lastCheck': '6.6', 'code': 0, 'valid': True}} Thread-2017487::INFO::2014-02-03 09:58:37,692::logUtils::41::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', imgUUID='827f2d81-dc8c-414e-90d2-75e76b3250a0', volUUID='f86ec330-0815-4361-8ce7-abf3318a8939', options=None) Thread-2017487::INFO::2014-02-03 09:58:37,693::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '10737418240', 'apparentsize': '10737418240'} Thread-6019540::INFO::2014-02-03 09:58:39,118::logUtils::41::dispatcher::(wrapper) Run and protect: getAllTasksStatuses(spUUID=None, options=None) Thread-6019540::INFO::2014-02-03 09:58:39,118::logUtils::44::dispatcher::(wrapper) Run and protect: getAllTasksStatuses, Return response: {'allTasksStatus': {}} Thread-6019541::INFO::2014-02-03 09:58:39,126::logUtils::41::dispatcher::(wrapper) Run and protect: spmStop(spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', options=None) Thread-6019541::ERROR::2014-02-03 09:58:39,127::task::833::TaskManager.Task::(_setError) Task=`1f478485-401b-4b9b-b58b-1e7973cf64a2`::Unexpected error Traceback (most recent call last): File "/usr/share/vdsm/storage/task.py", line 840, in _run return fn(*args, **kargs) File "/usr/share/vdsm/logUtils.py", line 42, in wrapper res = f(*args, **kwargs) File "/usr/share/vdsm/storage/hsm.py", line 601, in spmStop pool.stopSpm() File "/usr/share/vdsm/storage/securable.py", line 66, in wrapper raise SecureError() SecureError Thread-6019541::INFO::2014-02-03 09:58:39,128::task::1134::TaskManager.Task::(prepare) Task=`1f478485-401b-4b9b-b58b-1e7973cf64a2`::aborting: Task is aborted: u'' - code 100 Thread-6019541::ERROR::2014-02-03 09:58:39,130::dispatcher::70::Storage.Dispatcher.Protect::(run) Traceback (most recent call last): File "/usr/share/vdsm/storage/dispatcher.py", line 62, in run result = ctask.prepare(self.func, *args, **kwargs) File "/usr/share/vdsm/storage/task.py", line 1142, in prepare raise self.error SecureError # End vdsm SPM log # And after, the cluster elects another SPM. The webgui shows on 'events' tab: # Start webgui events # Data Center is being initialized, please wait for initialization to complete. Failed to remove VM _12.147_postgresql_default.sir.inpe.br_apagar (User: eduardo.ramos). # End webgui events # Engine logs nothing but normal change of SPM. I would like to know how I can identify what is stuck, and if I can delete by hand, deleting entry from DB and lvremove. Thanks! --------------090502050908090103050606 Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit <html> <head> <meta http-equiv="content-type" content="text/html; charset=ISO-8859-1"> </head> <body bgcolor="#FFFFFF" text="#000000"> Hi all! I'm having trouble on removing virtual machines. My environment run on a ISCSI domain storage. When I try remove, the SPM logs: # Start vdsm SPM log # Thread-6019517::INFO::2014-02-03 09:58:09,293::logUtils::41::dispatcher::(wrapper) Run and protect: deleteImage(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', imgUUID='57ba1906-2035-4503-acbc-5f6f077f75cc', postZero='false', force='false') Thread-6019517::INFO::2014-02-03 09:58:09,293::blockSD::816::Storage.StorageDomain::(validate) sdUUID=c332da29-ba9f-4c94-8fa9-346bb8e04e2a Thread-6019517::ERROR::2014-02-03 09:58:10,061::task::833::TaskManager.Task::(_setError) Task=`8cbf9978-ed51-488a-af52-a3db030e44ff`::Unexpected error Traceback (most recent call last):   File "/usr/share/vdsm/storage/task.py", line 840, in _run     return fn(*args, **kargs)   File "/usr/share/vdsm/logUtils.py", line 42, in wrapper     res = f(*args, **kwargs)   File "/usr/share/vdsm/storage/hsm.py", line 1429, in deleteImage     allVols = dom.getAllVolumes()   File "/usr/share/vdsm/storage/blockSD.py", line 972, in getAllVolumes     return getAllVolumes(self.sdUUID)   File "/usr/share/vdsm/storage/blockSD.py", line 172, in getAllVolumes     vImg not in res[vPar]['imgs']): KeyError: '63650a24-7e83-4c0a-851d-0ce9869a294d' Thread-6019517::INFO::2014-02-03 09:58:10,063::task::1134::TaskManager.Task::(prepare) Task=`8cbf9978-ed51-488a-af52-a3db030e44ff`::aborting: Task is aborted: u"'63650a24-7e83-4c0a-851d-0ce9869a294d'" - code 100 Thread-6019517::ERROR::2014-02-03 09:58:10,066::dispatcher::70::Storage.Dispatcher.Protect::(run) '63650a24-7e83-4c0a-851d-0ce9869a294d' Traceback (most recent call last):   File "/usr/share/vdsm/storage/dispatcher.py", line 62, in run     result = ctask.prepare(self.func, *args, **kwargs)   File "/usr/share/vdsm/storage/task.py", line 1142, in prepare     raise self.error KeyError: '63650a24-7e83-4c0a-851d-0ce9869a294d' Thread-6019518::INFO::2014-02-03 09:58:10,087::logUtils::41::dispatcher::(wrapper) Run and protect: getSpmStatus(spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', options=None) Thread-6019518::INFO::2014-02-03 09:58:10,088::logUtils::44::dispatcher::(wrapper) Run and protect: getSpmStatus, Return response: {'spm_st': {'spmId': 14, 'spmStatus': 'SPM', 'spmLver': 64}} Thread-6019519::INFO::2014-02-03 09:58:10,100::logUtils::41::dispatcher::(wrapper) Run and protect: getAllTasksStatuses(spUUID=None, options=None) Thread-6019519::INFO::2014-02-03 09:58:10,101::logUtils::44::dispatcher::(wrapper) Run and protect: getAllTasksStatuses, Return response: {'allTasksStatus': {}} Thread-6019520::INFO::2014-02-03 09:58:10,109::logUtils::41::dispatcher::(wrapper) Run and protect: spmStop(spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', options=None) Thread-6019520::INFO::2014-02-03 09:58:10,681::clusterlock::121::SafeLease::(release) Releasing cluster lock for domain c332da29-ba9f-4c94-8fa9-346bb8e04e2a Thread-6019521::INFO::2014-02-03 09:58:11,054::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-6019521::INFO::2014-02-03 09:58:11,054::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'51eb6183-157d-4015-ae0f-1c7ffb1731c0': {'delay': '0.00799298286438', 'lastCheck': '5.3', 'code': 0, 'valid': True}, u'c332da29-ba9f-4c94-8fa9-346bb8e04e2a': {'delay': '0.0197920799255', 'lastCheck': '4.9', 'code': 0, 'valid': True}, u'0e0be898-6e04-4469-bb32-91f3cf8146d1': {'delay': '0.00803208351135', 'lastCheck': '5.3', 'code': 0, 'valid': True}} Thread-6019520::INFO::2014-02-03 09:58:11,732::logUtils::44::dispatcher::(wrapper) Run and protect: spmStop, Return response: None Thread-6019523::INFO::2014-02-03 09:58:11,835::logUtils::41::dispatcher::(wrapper) Run and protect: getAllTasksStatuses(spUUID=None, options=None) Thread-6019523::INFO::2014-02-03 09:58:11,835::logUtils::44::dispatcher::(wrapper) Run and protect: getAllTasksStatuses, Return response: {'allTasksStatus': {}} Thread-6019524::INFO::2014-02-03 09:58:11,844::logUtils::41::dispatcher::(wrapper) Run and protect: spmStop(spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', options=None) Thread-6019524::ERROR::2014-02-03 09:58:11,846::task::833::TaskManager.Task::(_setError) Task=`00df5ff7-bbf4-4a0e-b60b-1b06dcaa7683`::Unexpected error Traceback (most recent call last):   File "/usr/share/vdsm/storage/task.py", line 840, in _run     return fn(*args, **kargs)   File "/usr/share/vdsm/logUtils.py", line 42, in wrapper     res = f(*args, **kwargs)   File "/usr/share/vdsm/storage/hsm.py", line 601, in spmStop     pool.stopSpm()   File "/usr/share/vdsm/storage/securable.py", line 66, in wrapper     raise SecureError() SecureError Thread-6019524::INFO::2014-02-03 09:58:11,855::task::1134::TaskManager.Task::(prepare) Task=`00df5ff7-bbf4-4a0e-b60b-1b06dcaa7683`::aborting: Task is aborted: u'' - code 100 Thread-6019524::ERROR::2014-02-03 09:58:11,857::dispatcher::70::Storage.Dispatcher.Protect::(run) Traceback (most recent call last):   File "/usr/share/vdsm/storage/dispatcher.py", line 62, in run     result = ctask.prepare(self.func, *args, **kwargs)   File "/usr/share/vdsm/storage/task.py", line 1142, in prepare     raise self.error SecureError Dummy-6018624::INFO::2014-02-03 09:58:14,220::storage_<a class="moz-txt-link-freetext" href="mailbox::674::Storage.MailBox.SpmMailMonitor::(run)">mailbox::674::Storage.MailBox.SpmMailMonitor::(run)</a> SPM_MailMonitor - Incoming mail monitoring thread stopped Thread-34627::INFO::2014-02-03 09:58:17,696::logUtils::41::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', imgUUID='974d9602-8fbe-485b-a12d-59b6c34826b7', volUUID='c1bcfe5c-20ab-4f50-a88b-e2e0e1184bf8', options=None) Thread-34757::INFO::2014-02-03 09:58:17,696::logUtils::41::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', imgUUID='49f65bfd-8592-42b9-9a31-91268402903f', volUUID='511e6584-4f19-426d-9379-b223d0c2d9c6', options=None) Thread-34627::INFO::2014-02-03 09:58:17,697::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '10737418240', 'apparentsize': '10737418240'} Thread-34757::INFO::2014-02-03 09:58:17,698::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '32212254720', 'apparentsize': '32212254720'} Thread-6019529::INFO::2014-02-03 09:58:21,672::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-6019529::INFO::2014-02-03 09:58:21,673::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'51eb6183-157d-4015-ae0f-1c7ffb1731c0': {'delay': '0.00730204582214', 'lastCheck': '5.9', 'code': 0, 'valid': True}, u'c332da29-ba9f-4c94-8fa9-346bb8e04e2a': {'delay': '0.0207469463348', 'lastCheck': '5.3', 'code': 0, 'valid': True}, u'0e0be898-6e04-4469-bb32-91f3cf8146d1': {'delay': '0.00734615325928', 'lastCheck': '5.9', 'code': 0, 'valid': True}} Thread-243::INFO::2014-02-03 09:58:27,800::logUtils::41::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', imgUUID='50f2c3e9-aa94-4ad1-9c3f-91b452292374', volUUID='d7cddb76-a5b7-49ed-9efe-44d92ec18d93', options=None) Thread-34590::INFO::2014-02-03 09:58:27,801::logUtils::41::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', imgUUID='c36bb1da-babd-47bd-a406-58f0cb529c00', volUUID='6ea83f9e-c614-4e11-ab57-314ed4efeeaa', options=None) Thread-243::INFO::2014-02-03 09:58:27,802::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '10737418240', 'apparentsize': '10737418240'} Thread-34590::INFO::2014-02-03 09:58:27,803::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '107374182400', 'apparentsize': '107374182400'} Thread-6019535::INFO::2014-02-03 09:58:32,337::logUtils::41::dispatcher::(wrapper) Run and protect: repoStats(options=None) Thread-6019535::INFO::2014-02-03 09:58:32,337::logUtils::44::dispatcher::(wrapper) Run and protect: repoStats, Return response: {u'51eb6183-157d-4015-ae0f-1c7ffb1731c0': {'delay': '0.0119340419769', 'lastCheck': '6.6', 'code': 0, 'valid': True}, u'c332da29-ba9f-4c94-8fa9-346bb8e04e2a': {'delay': '0.0190720558167', 'lastCheck': '6.0', 'code': 0, 'valid': True}, u'0e0be898-6e04-4469-bb32-91f3cf8146d1': {'delay': '0.00720596313477', 'lastCheck': '6.6', 'code': 0, 'valid': True}} Thread-2017487::INFO::2014-02-03 09:58:37,692::logUtils::41::dispatcher::(wrapper) Run and protect: getVolumeSize(sdUUID='c332da29-ba9f-4c94-8fa9-346bb8e04e2a', spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', imgUUID='827f2d81-dc8c-414e-90d2-75e76b3250a0', volUUID='f86ec330-0815-4361-8ce7-abf3318a8939', options=None) Thread-2017487::INFO::2014-02-03 09:58:37,693::logUtils::44::dispatcher::(wrapper) Run and protect: getVolumeSize, Return response: {'truesize': '10737418240', 'apparentsize': '10737418240'} Thread-6019540::INFO::2014-02-03 09:58:39,118::logUtils::41::dispatcher::(wrapper) Run and protect: getAllTasksStatuses(spUUID=None, options=None) Thread-6019540::INFO::2014-02-03 09:58:39,118::logUtils::44::dispatcher::(wrapper) Run and protect: getAllTasksStatuses, Return response: {'allTasksStatus': {}} Thread-6019541::INFO::2014-02-03 09:58:39,126::logUtils::41::dispatcher::(wrapper) Run and protect: spmStop(spUUID='9dbc7bb1-c460-4202-8f10-862d2ed3ed9a', options=None) Thread-6019541::ERROR::2014-02-03 09:58:39,127::task::833::TaskManager.Task::(_setError) Task=`1f478485-401b-4b9b-b58b-1e7973cf64a2`::Unexpected error Traceback (most recent call last):   File "/usr/share/vdsm/storage/task.py", line 840, in _run     return fn(*args, **kargs)   File "/usr/share/vdsm/logUtils.py", line 42, in wrapper     res = f(*args, **kwargs)   File "/usr/share/vdsm/storage/hsm.py", line 601, in spmStop     pool.stopSpm()   File "/usr/share/vdsm/storage/securable.py", line 66, in wrapper     raise SecureError() SecureError Thread-6019541::INFO::2014-02-03 09:58:39,128::task::1134::TaskManager.Task::(prepare) Task=`1f478485-401b-4b9b-b58b-1e7973cf64a2`::aborting: Task is aborted: u'' - code 100 Thread-6019541::ERROR::2014-02-03 09:58:39,130::dispatcher::70::Storage.Dispatcher.Protect::(run) Traceback (most recent call last):   File "/usr/share/vdsm/storage/dispatcher.py", line 62, in run     result = ctask.prepare(self.func, *args, **kwargs)   File "/usr/share/vdsm/storage/task.py", line 1142, in prepare     raise self.error SecureError # End vdsm SPM log # And after, the cluster elects another SPM. The webgui shows on 'events' tab: # Start webgui events # <meta http-equiv="content-type" content="text/html; charset=ISO-8859-1"> Data Center is being initialized, please wait for initialization to complete. <meta http-equiv="content-type" content="text/html; charset=ISO-8859-1"> Failed to remove VM _12.147_postgresql_default.sir.inpe.br_apagar (User: eduardo.ramos). # End webgui events # Engine logs nothing but normal change of SPM. I would like to know how I can identify what is stuck, and if I can delete by hand, deleting entry from DB and lvremove. Thanks! </body> </html> --------------090502050908090103050606--

2 1

[Users] Hosted Engine always reports "unknown stale-data"
by Andrew Lau 03 Feb '14

03 Feb '14

Hi, I was wondering if anyone has this same notice when they run: hosted-engine --vm-status The "engine status" will always be "unknown stale-data" even when the VM is powered on and the engine is online. engine-health will actually report the correct status. eg. --== Host 1 status ==-- Status up-to-date : False Hostname : 172.16.0.11 Host ID : 1 Engine status : unknown stale-data Is it some sort of blocked port causing this or is this by design? Thanks, Andrew

3 11

[Users] Full-size display Windows vs Fedora 20 guests
by Bob Doolittle 03 Feb '14

03 Feb '14

Hi, When I select View/Full Screen on a VM running a Windows guest, the display resolution automatically adjusts to fit the new canvas. However, when I do this on a VM running Fedora 20, it doesn't. Nor do I know how to query the new canvas size so that I can issue a manual xrandr command to fit it (without doing an ssh into the system and somehow finagling xwininfo to give me the size). In the guest I am running spice-vdagent-0.15.0-1, and restarting it has no effect. Shouldn't it be the one responsible for display optimization? -Bob

3 5

[Users] changing hostname in ovirt
by Sven Kieske 03 Feb '14

03 Feb '14

Hi, maybe I should write an RFE BZ for this but there might be a technical limitation, I don't know. What I want: I have a Host in ovirt which is in status "down" and/or "maintenance". I want to change the hostname/ip ovirt uses to connect to this host. 2. RFEs: 1. This is not possible via webadmin, the address field is grayed out (there seem to be conflicting design patterns for the webadmin, other buttons which don't work don't get grayed out for some reason, instead they throw errors..) 2. make it possible to change the hostname/ip via API from what I've seen so far I have to hack the database to make this change happen in 3.3.2 Is there any technical reason why this is not possible? ovirt should be happy with the UUIDs for the host and should not bother about the hostname. Is there a way to alter the hostname/ip which I don't know? Could someone point me to the right table and how to alter it without breaking it? Thank you! -- Mit freundlichen Grüßen / Regards Sven Kieske Systemadministrator Mittwald CM Service GmbH & Co. KG Königsberger Straße 6 32339 Espelkamp T: +49-5772-293-100 F: +49-5772-293-333 https://www.mittwald.de Geschäftsführer: Robert Meyer St.Nr.: 331/5721/1033, USt-IdNr.: DE814773217, HRA 6640, AG Bad Oeynhausen Komplementärin: Robert Meyer Verwaltungs GmbH, HRB 13260, AG Bad Oeynhausen

4 9