[Users] Unable to remove Vdisk and Ovirt UI spams finished messages
Itamar Heim
iheim at redhat.com
Thu Oct 17 08:29:57 EDT 2013
On 10/16/2013 05:45 PM, Aslam, Usman wrote:
> The version Im using is
> oVirt Engine Version: 3.1.0-3.26.3.el6.centos.alt
>
> It is the latest available from this repo "http://dev.centos.org/centos/6/ovirt/x86_64/"
>
> Which stable repo can I use for upgrades? Would it be safe to yum update from 3.1 to 3.3?
http://resources.ovirt.org/releases and then the right version.
(not sure who maintained the centos repos to newer versions)
>
> Vdsm version I'm using
>
> vdsm-python-4.10.3-10.el6.centos.alt.x86_64
> vdsm-xmlrpc-4.10.3-10.el6.centos.alt.noarch
> vdsm-cli-4.10.3-10.el6.centos.alt.noarch
> vdsm-4.10.3-10.el6.centos.alt.x86_64
>
> repo for upgrades? Safe to just do yum update?
for vdsm, should be safe to update. you should do it via engine. via
host you may need to restart to reconfigure libvirt (note the message on
vdsm start if it fails).
for engine, 3.2.1 was the first version we had .el6 in ovirt. previous
versions were maintained by dreyou.
we usually tests upgrades only from one version to the next, not
directly skipping more than a single version, which is what i recommend
trying.
(or back it up and try to go the full way, just do it in morning hours
for more support if needed...)
>
> Thanks,
> Usman
>
> -----Original Message-----
> From: Daniel Erez [mailto:derez at redhat.com]
> Sent: Wednesday, October 16, 2013 10:10 AM
> To: Aslam, Usman
> Cc: users at ovirt.org
> Subject: Re: [Users] Unable to remove Vdisk and Ovirt UI spams finished messages
>
>
>
> ----- Original Message -----
>> From: "Usman Aslam" <Usman.Aslam at tufts.edu>
>> To: "Daniel Erez" <derez at redhat.com>
>> Cc: users at ovirt.org
>> Sent: Wednesday, October 16, 2013 2:27:44 AM
>> Subject: RE: [Users] Unable to remove Vdisk and Ovirt UI spams
>> finished messages
>>
>> Daniel,
>>
>>
>>
>> I did manage to remove the lock on disk by change the value in the
>> images table.
>>
>> The spam messages have since I first reported the issue have gone away.
>> However, I am still unable to remove the VM or its Disks.
>>
>>
>>
>> On the SPM the suggested getAllTasks comes back with a blank line (I
>> assume no active tasks). The db table " async_task" also has not data in it.
>>
>> But as shown in the screenshot below. The Ovirt Web UI shows 0 tasks
>> but also shows a week old task on still trying to remove that vdisk.
>>
>>
>>
>> [cid:image001.png at 01CEC9DB.F3296440]
>>
>>
>>
>> Furthermore, below are logs of ovirt engine and vdsm (from SPM) for
>> period when I try to first remove the VM (it fails) and then the two
>> vdisks (which also fail) similar to the above screenshot.
>>
>>
>>
>> Please let me know if there is any more info I can send over. Thanks!
>
> You may encountered bug 884635 [1] which has already been resolved and integrated to oVirt 3.3. Are you using the latest source code or an older release?
>
> [1]
> http://bugzilla.redhat.com/show_bug.cgi?id=884635
>
>>
>>
>>
>> ###*** vdsm.log ***###
>>
>>
>>
>> 2013-10-15 19:23:50,174 INFO
>> [org.ovirt.engine.core.bll.RemoveVmCommand]
>> (ajp--127.0.0.1-8702-4) Lock Acquired to object EngineLock
>> [exclusiveLocks=
>> key: f0462ff5-d22b-49d0-b308-af4a4381b93d value: VM
>>
>> , sharedLocks= ]
>>
>> 2013-10-15 19:23:50,188 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
>> (ajp--127.0.0.1-8702-4) START, IsValidVDSCommand( storagePoolId =
>> 430cd986-6488-403b-8d46-29abbc3eba38, ignoreFailoverLimit = false,
>> compatabilityVersion = null), log id: 18c4d4ab
>>
>> 2013-10-15 19:23:50,194 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
>> (ajp--127.0.0.1-8702-4) FINISH, IsValidVDSCommand, return: true, log id:
>> 18c4d4ab
>>
>> 2013-10-15 19:23:50,280 INFO
>> [org.ovirt.engine.core.bll.RemoveVmCommand]
>> (pool-3-thread-49) [36218b4b] Running command: RemoveVmCommand internal:
>> false. Entities affected : ID: f0462ff5-d22b-49d0-b308-af4a4381b93d Type:
>> VM
>>
>> 2013-10-15 19:23:50,286 INFO
>> [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand]
>> (pool-3-thread-49) [36218b4b] START, SetVmStatusVDSCommand( vmId =
>> f0462ff5-d22b-49d0-b308-af4a4381b93d, status = ImageLocked), log id:
>> 59fc9345
>>
>> 2013-10-15 19:23:50,296 INFO
>> [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand]
>> (pool-3-thread-49) [36218b4b] FINISH, SetVmStatusVDSCommand, log id:
>> 59fc9345
>>
>> 2013-10-15 19:23:50,301 INFO
>> [org.ovirt.engine.core.bll.RemoveVmCommand]
>> (pool-3-thread-49) [36218b4b] Lock freed to object EngineLock
>> [exclusiveLocks= key: f0462ff5-d22b-49d0-b308-af4a4381b93d value: VM
>>
>> , sharedLocks= ]
>>
>> 2013-10-15 19:23:50,304 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.RemoveVMVDSCommand]
>> (pool-3-thread-49) [36218b4b] START, RemoveVMVDSCommand( storagePoolId
>> = 430cd986-6488-403b-8d46-29abbc3eba38, ignoreFailoverLimit = false,
>> compatabilityVersion = null, storageDomainId =
>> 00000000-0000-0000-0000-000000000000, vmGuid =
>> f0462ff5-d22b-49d0-b308-af4a4381b93d), log id: 13c7a395
>>
>> 2013-10-15 19:23:50,323 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.RemoveVMVDSCommand]
>> (pool-3-thread-49) [36218b4b] FINISH, RemoveVMVDSCommand, log id:
>> 13c7a395
>>
>> 2013-10-15 19:23:50,346 INFO
>> [org.ovirt.engine.core.bll.RemoveAllVmImagesCommand]
>> (pool-3-thread-49) [148b1174] Running command: RemoveAllVmImagesCommand internal: true.
>> Entities affected : ID: f0462ff5-d22b-49d0-b308-af4a4381b93d Type: VM
>>
>> 2013-10-15 19:23:50,377 INFO
>> [org.ovirt.engine.core.bll.RemoveImageCommand]
>> (pool-3-thread-49) [183aa7b5] Running command: RemoveImageCommand internal:
>> true. Entities affected : ID: 00000000-0000-0000-0000-000000000000 Type:
>> Storage
>>
>> 2013-10-15 19:23:50,382 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand]
>> (pool-3-thread-49) [183aa7b5] START, DeleteImageGroupVDSCommand(
>> storagePoolId = 430cd986-6488-403b-8d46-29abbc3eba38,
>> ignoreFailoverLimit = false, compatabilityVersion = 3.2,
>> storageDomainId = fa3279ec-2912-45ac-b7bc-9fe89151ed99, imageGroupId =
>> bcb77522-8cac-45a7-a5a6-b3c1f55614b8, postZeros = false, forceDelete =
>> false), log id: 52c1a1fe
>>
>> 2013-10-15 19:23:50,489 ERROR
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
>> (pool-3-thread-49) [183aa7b5] IrsBroker::Failed::DeleteImageGroupVDS due to:
>> IrsOperationFailedNoFailoverException: IRSGenericException:
>> IRSErrorException: Image does not exist in domain:
>> 'image=bcb77522-8cac-45a7-a5a6-b3c1f55614b8,
>> domain=fa3279ec-2912-45ac-b7bc-9fe89151ed99'
>>
>> 2013-10-15 19:23:50,495 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand]
>> (pool-3-thread-49) [183aa7b5] FINISH, DeleteImageGroupVDSCommand, log id:
>> 52c1a1fe
>>
>> 2013-10-15 19:23:50,499 ERROR
>> [org.ovirt.engine.core.bll.RemoveImageCommand]
>> (pool-3-thread-49) [183aa7b5] Command
>> org.ovirt.engine.core.bll.RemoveImageCommand throw Vdc Bll exception.
>> With error message VdcBLLException:
>> org.ovirt.engine.core.vdsbroker.irsbroker.IrsOperationFailedNoFailoverException:
>> IRSGenericException: IRSErrorException: Image does not exist in domain:
>> 'image=bcb77522-8cac-45a7-a5a6-b3c1f55614b8,
>> domain=fa3279ec-2912-45ac-b7bc-9fe89151ed99'
>>
>> 2013-10-15 19:23:50,520 INFO
>> [org.ovirt.engine.core.bll.RemoveVmCommand]
>> (pool-3-thread-49) [183aa7b5] Command
>> [id=1ae3c964-48ab-474d-b6e9-64947510be1b]: Compensating
>> CHANGED_STATUS_ONLY of org.ovirt.engine.core.common.businessentities.VmDynamic; snapshot:
>> EntityStatusSnapshot [id=f0462ff5-d22b-49d0-b308-af4a4381b93d, status=Down].
>>
>> 2013-10-15 19:23:55,404 INFO
>> [org.ovirt.engine.core.bll.RemoveDiskCommand]
>> (ajp--127.0.0.1-8702-6) Lock Acquired to object EngineLock
>> [exclusiveLocks=
>> key: a9ffc7b8-6e64-4dc4-81b8-e52425cbae00 value: DISK
>>
>> , sharedLocks= key: f0462ff5-d22b-49d0-b308-af4a4381b93d value: VM
>>
>> ]
>>
>> 2013-10-15 19:23:55,415 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
>> (ajp--127.0.0.1-8702-6) START, IsValidVDSCommand( storagePoolId =
>> 430cd986-6488-403b-8d46-29abbc3eba38, ignoreFailoverLimit = false,
>> compatabilityVersion = null), log id: 288b190f
>>
>> 2013-10-15 19:23:55,421 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
>> (ajp--127.0.0.1-8702-6) FINISH, IsValidVDSCommand, return: true, log id:
>> 288b190f
>>
>> 2013-10-15 19:23:55,489 INFO
>> [org.ovirt.engine.core.bll.RemoveDiskCommand]
>> (pool-3-thread-49) [12886b63] Running command: RemoveDiskCommand internal:
>> false. Entities affected : ID: a9ffc7b8-6e64-4dc4-81b8-e52425cbae00 Type:
>> Disk
>>
>> 2013-10-15 19:23:55,501 INFO
>> [org.ovirt.engine.core.bll.RemoveImageCommand]
>> (pool-3-thread-49) [68af83cd] Running command: RemoveImageCommand internal:
>> true. Entities affected : ID: fa3279ec-2912-45ac-b7bc-9fe89151ed99 Type:
>> Storage
>>
>> 2013-10-15 19:23:55,506 INFO
>> [org.ovirt.engine.core.bll.RemoveImageCommand]
>> (pool-3-thread-49) [68af83cd] Lock freed to object EngineLock
>> [exclusiveLocks= key: a9ffc7b8-6e64-4dc4-81b8-e52425cbae00 value: DISK
>>
>> , sharedLocks= key: f0462ff5-d22b-49d0-b308-af4a4381b93d value: VM
>>
>> ]
>>
>> 2013-10-15 19:23:55,511 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand]
>> (pool-3-thread-49) [68af83cd] START, DeleteImageGroupVDSCommand(
>> storagePoolId = 430cd986-6488-403b-8d46-29abbc3eba38,
>> ignoreFailoverLimit = false, compatabilityVersion = 3.2,
>> storageDomainId = fa3279ec-2912-45ac-b7bc-9fe89151ed99, imageGroupId =
>> a9ffc7b8-6e64-4dc4-81b8-e52425cbae00, postZeros = false, forceDelete =
>> false), log id: 70e20b2f
>>
>> 2013-10-15 19:23:55,576 ERROR
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
>> (pool-3-thread-49) [68af83cd] IrsBroker::Failed::DeleteImageGroupVDS due to:
>> IrsOperationFailedNoFailoverException: IRSGenericException:
>> IRSErrorException: Image does not exist in domain:
>> 'image=a9ffc7b8-6e64-4dc4-81b8-e52425cbae00,
>> domain=fa3279ec-2912-45ac-b7bc-9fe89151ed99'
>>
>> 2013-10-15 19:23:55,582 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand]
>> (pool-3-thread-49) [68af83cd] FINISH, DeleteImageGroupVDSCommand, log id:
>> 70e20b2f
>>
>> 2013-10-15 19:23:55,588 ERROR
>> [org.ovirt.engine.core.bll.RemoveImageCommand]
>> (pool-3-thread-49) [68af83cd] Command
>> org.ovirt.engine.core.bll.RemoveImageCommand throw Vdc Bll exception.
>> With error message VdcBLLException:
>> org.ovirt.engine.core.vdsbroker.irsbroker.IrsOperationFailedNoFailoverException:
>> IRSGenericException: IRSErrorException: Image does not exist in domain:
>> 'image=a9ffc7b8-6e64-4dc4-81b8-e52425cbae00,
>> domain=fa3279ec-2912-45ac-b7bc-9fe89151ed99'
>>
>> 2013-10-15 19:24:03,992 INFO
>> [org.ovirt.engine.core.bll.RemoveDiskCommand]
>> (ajp--127.0.0.1-8702-6) Lock Acquired to object EngineLock
>> [exclusiveLocks=
>> key: bcb77522-8cac-45a7-a5a6-b3c1f55614b8 value: DISK
>>
>> , sharedLocks= key: f0462ff5-d22b-49d0-b308-af4a4381b93d value: VM
>>
>> ]
>>
>> 2013-10-15 19:24:04,006 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
>> (ajp--127.0.0.1-8702-6) START, IsValidVDSCommand( storagePoolId =
>> 430cd986-6488-403b-8d46-29abbc3eba38, ignoreFailoverLimit = false,
>> compatabilityVersion = null), log id: 67c54350
>>
>> 2013-10-15 19:24:04,013 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
>> (ajp--127.0.0.1-8702-6) FINISH, IsValidVDSCommand, return: true, log id:
>> 67c54350
>>
>> 2013-10-15 19:24:04,036 INFO
>> [org.ovirt.engine.core.bll.RemoveDiskCommand]
>> (pool-3-thread-46) [3d055b94] Running command: RemoveDiskCommand internal:
>> false. Entities affected : ID: bcb77522-8cac-45a7-a5a6-b3c1f55614b8 Type:
>> Disk
>>
>> 2013-10-15 19:24:04,044 INFO
>> [org.ovirt.engine.core.bll.RemoveImageCommand]
>> (pool-3-thread-46) [2fa6b13] Running command: RemoveImageCommand internal:
>> true. Entities affected : ID: fa3279ec-2912-45ac-b7bc-9fe89151ed99 Type:
>> Storage
>>
>> 2013-10-15 19:24:04,050 INFO
>> [org.ovirt.engine.core.bll.RemoveImageCommand]
>> (pool-3-thread-46) [2fa6b13] Lock freed to object EngineLock
>> [exclusiveLocks= key: bcb77522-8cac-45a7-a5a6-b3c1f55614b8 value: DISK
>>
>> , sharedLocks= key: f0462ff5-d22b-49d0-b308-af4a4381b93d value: VM
>>
>> ]
>>
>> 2013-10-15 19:24:04,056 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand]
>> (pool-3-thread-46) [2fa6b13] START, DeleteImageGroupVDSCommand(
>> storagePoolId = 430cd986-6488-403b-8d46-29abbc3eba38,
>> ignoreFailoverLimit = false, compatabilityVersion = 3.2,
>> storageDomainId = fa3279ec-2912-45ac-b7bc-9fe89151ed99, imageGroupId =
>> bcb77522-8cac-45a7-a5a6-b3c1f55614b8, postZeros = false, forceDelete =
>> false), log id: 54e25ce0
>>
>> 2013-10-15 19:24:04,147 ERROR
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
>> (pool-3-thread-46) [2fa6b13] IrsBroker::Failed::DeleteImageGroupVDS due to:
>> IrsOperationFailedNoFailoverException: IRSGenericException:
>> IRSErrorException: Image does not exist in domain:
>> 'image=bcb77522-8cac-45a7-a5a6-b3c1f55614b8,
>> domain=fa3279ec-2912-45ac-b7bc-9fe89151ed99'
>>
>> 2013-10-15 19:24:04,149 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand]
>> (pool-3-thread-46) [2fa6b13] FINISH, DeleteImageGroupVDSCommand, log id:
>> 54e25ce0
>>
>> 2013-10-15 19:24:04,152 ERROR
>> [org.ovirt.engine.core.bll.RemoveImageCommand]
>> (pool-3-thread-46) [2fa6b13] Command
>> org.ovirt.engine.core.bll.RemoveImageCommand throw Vdc Bll exception.
>> With error message VdcBLLException:
>> org.ovirt.engine.core.vdsbroker.irsbroker.IrsOperationFailedNoFailoverException:
>> IRSGenericException: IRSErrorException: Image does not exist in domain:
>> 'image=bcb77522-8cac-45a7-a5a6-b3c1f55614b8,
>> domain=fa3279ec-2912-45ac-b7bc-9fe89151ed99'
>>
>> 2013-10-15 19:24:18,376 INFO
>> [org.ovirt.engine.core.bll.RemoveVmCommand]
>> (ajp--127.0.0.1-8702-8) Lock Acquired to object EngineLock
>> [exclusiveLocks=
>> key: f0462ff5-d22b-49d0-b308-af4a4381b93d value: VM
>>
>> , sharedLocks= ]
>>
>> 2013-10-15 19:24:18,408 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
>> (ajp--127.0.0.1-8702-8) START, IsValidVDSCommand( storagePoolId =
>> 430cd986-6488-403b-8d46-29abbc3eba38, ignoreFailoverLimit = false,
>> compatabilityVersion = null), log id: 733f30f5
>>
>> 2013-10-15 19:24:18,410 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
>> (ajp--127.0.0.1-8702-8) FINISH, IsValidVDSCommand, return: true, log id:
>> 733f30f5
>>
>> 2013-10-15 19:24:18,445 INFO
>> [org.ovirt.engine.core.bll.RemoveVmCommand]
>> (pool-3-thread-46) [26fd8426] Running command: RemoveVmCommand internal:
>> false. Entities affected : ID: f0462ff5-d22b-49d0-b308-af4a4381b93d Type:
>> VM
>>
>> 2013-10-15 19:24:18,451 INFO
>> [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand]
>> (pool-3-thread-46) [26fd8426] START, SetVmStatusVDSCommand( vmId =
>> f0462ff5-d22b-49d0-b308-af4a4381b93d, status = ImageLocked), log id:
>> 34c97c50
>>
>> 2013-10-15 19:24:18,456 INFO
>> [org.ovirt.engine.core.vdsbroker.SetVmStatusVDSCommand]
>> (pool-3-thread-46) [26fd8426] FINISH, SetVmStatusVDSCommand, log id:
>> 34c97c50
>>
>> 2013-10-15 19:24:18,458 INFO
>> [org.ovirt.engine.core.bll.RemoveVmCommand]
>> (pool-3-thread-46) [26fd8426] Lock freed to object EngineLock
>> [exclusiveLocks= key: f0462ff5-d22b-49d0-b308-af4a4381b93d value: VM
>>
>> , sharedLocks= ]
>>
>> 2013-10-15 19:24:18,459 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.RemoveVMVDSCommand]
>> (pool-3-thread-46) [26fd8426] START, RemoveVMVDSCommand( storagePoolId
>> = 430cd986-6488-403b-8d46-29abbc3eba38, ignoreFailoverLimit = false,
>> compatabilityVersion = null, storageDomainId =
>> 00000000-0000-0000-0000-000000000000, vmGuid =
>> f0462ff5-d22b-49d0-b308-af4a4381b93d), log id: 91998d2
>>
>> 2013-10-15 19:24:18,475 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.RemoveVMVDSCommand]
>> (pool-3-thread-46) [26fd8426] FINISH, RemoveVMVDSCommand, log id:
>> 91998d2
>>
>> 2013-10-15 19:24:18,496 INFO
>> [org.ovirt.engine.core.bll.RemoveAllVmImagesCommand]
>> (pool-3-thread-46) [7178d46f] Running command: RemoveAllVmImagesCommand internal: true.
>> Entities affected : ID: f0462ff5-d22b-49d0-b308-af4a4381b93d Type: VM
>>
>> 2013-10-15 19:24:18,507 INFO
>> [org.ovirt.engine.core.bll.RemoveImageCommand]
>> (pool-3-thread-46) [da18cdc] Running command: RemoveImageCommand internal:
>> true. Entities affected : ID: 00000000-0000-0000-0000-000000000000 Type:
>> Storage
>>
>> 2013-10-15 19:24:18,510 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand]
>> (pool-3-thread-46) [da18cdc] START, DeleteImageGroupVDSCommand(
>> storagePoolId = 430cd986-6488-403b-8d46-29abbc3eba38,
>> ignoreFailoverLimit = false, compatabilityVersion = 3.2,
>> storageDomainId = fa3279ec-2912-45ac-b7bc-9fe89151ed99, imageGroupId =
>> bcb77522-8cac-45a7-a5a6-b3c1f55614b8, postZeros = false, forceDelete =
>> false), log id: 1f803250
>>
>> 2013-10-15 19:24:18,574 ERROR
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
>> (pool-3-thread-46) [da18cdc] IrsBroker::Failed::DeleteImageGroupVDS due to:
>> IrsOperationFailedNoFailoverException: IRSGenericException:
>> IRSErrorException: Image does not exist in domain:
>> 'image=bcb77522-8cac-45a7-a5a6-b3c1f55614b8,
>> domain=fa3279ec-2912-45ac-b7bc-9fe89151ed99'
>>
>> 2013-10-15 19:24:18,578 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand]
>> (pool-3-thread-46) [da18cdc] FINISH, DeleteImageGroupVDSCommand, log id:
>> 1f803250
>>
>> 2013-10-15 19:24:18,582 ERROR
>> [org.ovirt.engine.core.bll.RemoveImageCommand]
>> (pool-3-thread-46) [da18cdc] Command
>> org.ovirt.engine.core.bll.RemoveImageCommand throw Vdc Bll exception.
>> With error message VdcBLLException:
>> org.ovirt.engine.core.vdsbroker.irsbroker.IrsOperationFailedNoFailoverException:
>> IRSGenericException: IRSErrorException: Image does not exist in domain:
>> 'image=bcb77522-8cac-45a7-a5a6-b3c1f55614b8,
>> domain=fa3279ec-2912-45ac-b7bc-9fe89151ed99'
>>
>> 2013-10-15 19:24:18,597 INFO
>> [org.ovirt.engine.core.bll.RemoveVmCommand]
>> (pool-3-thread-46) [da18cdc] Command
>> [id=00574670-3db7-4758-b68e-98b54d8ff42d]: Compensating
>> CHANGED_STATUS_ONLY of org.ovirt.engine.core.common.businessentities.VmDynamic; snapshot:
>> EntityStatusSnapshot [id=f0462ff5-d22b-49d0-b308-af4a4381b93d, status=Down].
>>
>> 2013-10-15 19:24:29,383 WARN
>> [org.ovirt.engine.core.bll.DetachDiskFromVmCommand]
>> (ajp--127.0.0.1-8702-9) CanDoAction of action DetachDiskFromVm failed.
>> Reasons:VAR__ACTION__DETACH_ACTION_TO,VAR__TYPE__VM_DISK,ERROR_CANNOT_
>> DETACH_DISK_WITH_SNAPSHOT
>>
>> 2013-10-15 19:24:35,371 INFO
>> [org.ovirt.engine.core.bll.RemoveDiskCommand]
>> (ajp--127.0.0.1-8702-4) Lock Acquired to object EngineLock
>> [exclusiveLocks=
>> key: a9ffc7b8-6e64-4dc4-81b8-e52425cbae00 value: DISK
>>
>> , sharedLocks= key: f0462ff5-d22b-49d0-b308-af4a4381b93d value: VM
>>
>> ]
>>
>> 2013-10-15 19:24:35,379 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
>> (ajp--127.0.0.1-8702-4) START, IsValidVDSCommand( storagePoolId =
>> 430cd986-6488-403b-8d46-29abbc3eba38, ignoreFailoverLimit = false,
>> compatabilityVersion = null), log id: 4b0926da
>>
>> 2013-10-15 19:24:35,382 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IsValidVDSCommand]
>> (ajp--127.0.0.1-8702-4) FINISH, IsValidVDSCommand, return: true, log id:
>> 4b0926da
>>
>> 2013-10-15 19:24:35,420 INFO
>> [org.ovirt.engine.core.bll.RemoveDiskCommand]
>> (pool-3-thread-46) [3f8a0b7d] Running command: RemoveDiskCommand internal:
>> false. Entities affected : ID: a9ffc7b8-6e64-4dc4-81b8-e52425cbae00 Type:
>> Disk
>>
>> 2013-10-15 19:24:35,430 INFO
>> [org.ovirt.engine.core.bll.RemoveImageCommand]
>> (pool-3-thread-46) [617a9b78] Running command: RemoveImageCommand internal:
>> true. Entities affected : ID: fa3279ec-2912-45ac-b7bc-9fe89151ed99 Type:
>> Storage
>>
>> 2013-10-15 19:24:35,432 INFO
>> [org.ovirt.engine.core.bll.RemoveImageCommand]
>> (pool-3-thread-46) [617a9b78] Lock freed to object EngineLock
>> [exclusiveLocks= key: a9ffc7b8-6e64-4dc4-81b8-e52425cbae00 value: DISK
>>
>> , sharedLocks= key: f0462ff5-d22b-49d0-b308-af4a4381b93d value: VM
>>
>> ]
>>
>> 2013-10-15 19:24:35,435 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand]
>> (pool-3-thread-46) [617a9b78] START, DeleteImageGroupVDSCommand(
>> storagePoolId = 430cd986-6488-403b-8d46-29abbc3eba38,
>> ignoreFailoverLimit = false, compatabilityVersion = 3.2,
>> storageDomainId = fa3279ec-2912-45ac-b7bc-9fe89151ed99, imageGroupId =
>> a9ffc7b8-6e64-4dc4-81b8-e52425cbae00, postZeros = false, forceDelete =
>> false), log id: 6993df94
>>
>> 2013-10-15 19:24:35,496 ERROR
>> [org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand]
>> (pool-3-thread-46) [617a9b78] IrsBroker::Failed::DeleteImageGroupVDS due to:
>> IrsOperationFailedNoFailoverException: IRSGenericException:
>> IRSErrorException: Image does not exist in domain:
>> 'image=a9ffc7b8-6e64-4dc4-81b8-e52425cbae00,
>> domain=fa3279ec-2912-45ac-b7bc-9fe89151ed99'
>>
>> 2013-10-15 19:24:35,504 INFO
>> [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand]
>> (pool-3-thread-46) [617a9b78] FINISH, DeleteImageGroupVDSCommand, log id:
>> 6993df94
>>
>> 2013-10-15 19:24:35,506 ERROR
>> [org.ovirt.engine.core.bll.RemoveImageCommand]
>> (pool-3-thread-46) [617a9b78] Command
>> org.ovirt.engine.core.bll.RemoveImageCommand throw Vdc Bll exception.
>> With error message VdcBLLException:
>> org.ovirt.engine.core.vdsbroker.irsbroker.IrsOperationFailedNoFailoverException:
>> IRSGenericException: IRSErrorException: Image does not exist in domain:
>> 'image=a9ffc7b8-6e64-4dc4-81b8-e52425cbae00,
>> domain=fa3279ec-2912-45ac-b7bc-9fe89151ed99'
>>
>> 2013-10-15 19:25:00,001 INFO
>> [org.ovirt.engine.core.bll.AutoRecoveryManager]
>> (QuartzScheduler_Worker-52) Autorecovering hosts is disabled, skipping
>>
>> 2013-10-15 19:25:00,002 INFO
>> [org.ovirt.engine.core.bll.AutoRecoveryManager]
>> (QuartzScheduler_Worker-52) Autorecovering storage domains is
>> disabled, skipping
>>
>>
>>
>> ###*** vdsm.log ***###
>>
>>
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:23:48,075::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 93.
>>
>> Thread-363707::DEBUG::2013-10-15
>> 19:23:51,861::task::568::TaskManager.Task::(_updateState)
>> Task=`502bf2d7-ba12-47b2-aba2-8f9ae401b77d`::moving from state init ->
>> state preparing
>>
>> Thread-363707::INFO::2013-10-15
>> 19:23:51,861::logUtils::41::dispatcher::(wrapper) Run and protect:
>> repoStats(options=None)
>>
>> Thread-363707::INFO::2013-10-15
>> 19:23:51,862::logUtils::44::dispatcher::(wrapper) Run and protect:
>> repoStats, Return response: {'fa3279ec-2912-45ac-b7bc-9fe89151ed99':
>> {'delay': '0.00687623023987', 'lastCheck': '6.4', 'code': 0, 'valid':
>> True},
>> 'ee2ae498-6e45-448d-8f91-0efca377dcf6': {'delay': '0.00651216506958',
>> 'lastCheck': '9.3', 'code': 0, 'valid': True}}
>>
>> Thread-363707::DEBUG::2013-10-15
>> 19:23:51,862::task::1151::TaskManager.Task::(prepare)
>> Task=`502bf2d7-ba12-47b2-aba2-8f9ae401b77d`::finished:
>> {'fa3279ec-2912-45ac-b7bc-9fe89151ed99': {'delay': '0.00687623023987',
>> 'lastCheck': '6.4', 'code': 0, 'valid': True},
>> 'ee2ae498-6e45-448d-8f91-0efca377dcf6': {'delay': '0.00651216506958',
>> 'lastCheck': '9.3', 'code': 0, 'valid': True}}
>>
>> Thread-363707::DEBUG::2013-10-15
>> 19:23:51,863::task::568::TaskManager.Task::(_updateState)
>> Task=`502bf2d7-ba12-47b2-aba2-8f9ae401b77d`::moving from state
>> preparing -> state finished
>>
>> Thread-363707::DEBUG::2013-10-15
>> 19:23:51,863::resourceManager::830::ResourceManager.Owner::(releaseAll
>> ) Owner.releaseAll requests {} resources {}
>>
>> Thread-363707::DEBUG::2013-10-15
>> 19:23:51,863::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>>
>> Thread-363707::DEBUG::2013-10-15
>> 19:23:51,864::task::957::TaskManager.Task::(_decref)
>> Task=`502bf2d7-ba12-47b2-aba2-8f9ae401b77d`::ref 0 aborting False
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:23:56,083::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 20.
>>
>> Thread-1841::DEBUG::2013-10-15
>> 19:23:56,725::task::568::TaskManager.Task::(_updateState)
>> Task=`f0184ed3-d107-41aa-a468-4c29b5e0ac0a`::moving from state init ->
>> state preparing
>>
>> Thread-1841::INFO::2013-10-15
>> 19:23:56,725::logUtils::41::dispatcher::(wrapper) Run and protect:
>> getVolumeSize(sdUUID='fa3279ec-2912-45ac-b7bc-9fe89151ed99',
>> spUUID='430cd986-6488-403b-8d46-29abbc3eba38',
>> imgUUID='0941095c-7a1f-410c-8453-361be8f8adbc',
>> volUUID='45bd040f-e8c7-493c-b8f2-a5dbeb32c56d', options=None)
>>
>> Thread-2173::DEBUG::2013-10-15
>> 19:23:56,730::task::568::TaskManager.Task::(_updateState)
>> Task=`272090f3-d569-440a-b249-386cb5ed9c0f`::moving from state init ->
>> state preparing
>>
>> Thread-2173::INFO::2013-10-15
>> 19:23:56,734::logUtils::41::dispatcher::(wrapper) Run and protect:
>> getVolumeSize(sdUUID='fa3279ec-2912-45ac-b7bc-9fe89151ed99',
>> spUUID='430cd986-6488-403b-8d46-29abbc3eba38',
>> imgUUID='c2f279d6-14df-4f60-b9ae-d51559c59013',
>> volUUID='f17d3d6d-4324-4e4a-bfd8-28f62cf3753f', options=None)
>>
>> Thread-1841::DEBUG::2013-10-15
>> 19:23:56,740::fileVolume::561::Storage.Volume::(validateVolumePath)
>> validate path for 45bd040f-e8c7-493c-b8f2-a5dbeb32c56d
>>
>> Thread-2173::DEBUG::2013-10-15
>> 19:23:56,750::fileVolume::561::Storage.Volume::(validateVolumePath)
>> validate path for f17d3d6d-4324-4e4a-bfd8-28f62cf3753f
>>
>> Thread-1841::INFO::2013-10-15
>> 19:23:56,750::logUtils::44::dispatcher::(wrapper) Run and protect:
>> getVolumeSize, Return response: {'truesize': '13492871168', 'apparentsize':
>> '53687091200'}
>>
>> Thread-1841::DEBUG::2013-10-15
>> 19:23:56,752::task::1151::TaskManager.Task::(prepare)
>> Task=`f0184ed3-d107-41aa-a468-4c29b5e0ac0a`::finished: {'truesize':
>> '13492871168', 'apparentsize': '53687091200'}
>>
>> Thread-1841::DEBUG::2013-10-15
>> 19:23:56,753::task::568::TaskManager.Task::(_updateState)
>> Task=`f0184ed3-d107-41aa-a468-4c29b5e0ac0a`::moving from state
>> preparing -> state finished
>>
>> Thread-1841::DEBUG::2013-10-15
>> 19:23:56,755::resourceManager::830::ResourceManager.Owner::(releaseAll
>> ) Owner.releaseAll requests {} resources {}
>>
>> Thread-1841::DEBUG::2013-10-15
>> 19:23:56,755::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>>
>> Thread-1841::DEBUG::2013-10-15
>> 19:23:56,756::task::957::TaskManager.Task::(_decref)
>> Task=`f0184ed3-d107-41aa-a468-4c29b5e0ac0a`::ref 0 aborting False
>>
>> Thread-2173::INFO::2013-10-15
>> 19:23:56,757::logUtils::44::dispatcher::(wrapper) Run and protect:
>> getVolumeSize, Return response: {'truesize': '10940887040', 'apparentsize':
>> '53687091200'}
>>
>> Thread-2173::DEBUG::2013-10-15
>> 19:23:56,758::task::1151::TaskManager.Task::(prepare)
>> Task=`272090f3-d569-440a-b249-386cb5ed9c0f`::finished: {'truesize':
>> '10940887040', 'apparentsize': '53687091200'}
>>
>> Thread-2173::DEBUG::2013-10-15
>> 19:23:56,758::task::568::TaskManager.Task::(_updateState)
>> Task=`272090f3-d569-440a-b249-386cb5ed9c0f`::moving from state
>> preparing -> state finished
>>
>> Thread-2173::DEBUG::2013-10-15
>> 19:23:56,758::resourceManager::830::ResourceManager.Owner::(releaseAll
>> ) Owner.releaseAll requests {} resources {}
>>
>> Thread-2173::DEBUG::2013-10-15
>> 19:23:56,759::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>>
>> Thread-2173::DEBUG::2013-10-15
>> 19:23:56,759::task::957::TaskManager.Task::(_decref)
>> Task=`272090f3-d569-440a-b249-386cb5ed9c0f`::ref 0 aborting False
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:23:59,085::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 83.
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:24:02,088::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 60.
>>
>> Thread-363713::DEBUG::2013-10-15
>> 19:24:02,156::task::568::TaskManager.Task::(_updateState)
>> Task=`74b2ce46-dccd-44a6-9b7b-f61dbfe60045`::moving from state init ->
>> state preparing
>>
>> Thread-363713::INFO::2013-10-15
>> 19:24:02,156::logUtils::41::dispatcher::(wrapper) Run and protect:
>> repoStats(options=None)
>>
>> Thread-363713::INFO::2013-10-15
>> 19:24:02,156::logUtils::44::dispatcher::(wrapper) Run and protect:
>> repoStats, Return response: {'fa3279ec-2912-45ac-b7bc-9fe89151ed99':
>> {'delay': '0.00695705413818', 'lastCheck': '6.7', 'code': 0, 'valid':
>> True},
>> 'ee2ae498-6e45-448d-8f91-0efca377dcf6': {'delay': '0.00702095031738',
>> 'lastCheck': '9.6', 'code': 0, 'valid': True}}
>>
>> Thread-363713::DEBUG::2013-10-15
>> 19:24:02,157::task::1151::TaskManager.Task::(prepare)
>> Task=`74b2ce46-dccd-44a6-9b7b-f61dbfe60045`::finished:
>> {'fa3279ec-2912-45ac-b7bc-9fe89151ed99': {'delay': '0.00695705413818',
>> 'lastCheck': '6.7', 'code': 0, 'valid': True},
>> 'ee2ae498-6e45-448d-8f91-0efca377dcf6': {'delay': '0.00702095031738',
>> 'lastCheck': '9.6', 'code': 0, 'valid': True}}
>>
>> Thread-363713::DEBUG::2013-10-15
>> 19:24:02,157::task::568::TaskManager.Task::(_updateState)
>> Task=`74b2ce46-dccd-44a6-9b7b-f61dbfe60045`::moving from state
>> preparing -> state finished
>>
>> Thread-363713::DEBUG::2013-10-15
>> 19:24:02,157::resourceManager::830::ResourceManager.Owner::(releaseAll
>> ) Owner.releaseAll requests {} resources {}
>>
>> Thread-363713::DEBUG::2013-10-15
>> 19:24:02,158::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>>
>> Thread-363713::DEBUG::2013-10-15
>> 19:24:02,158::task::957::TaskManager.Task::(_decref)
>> Task=`74b2ce46-dccd-44a6-9b7b-f61dbfe60045`::ref 0 aborting False
>>
>> Thread-1696::DEBUG::2013-10-15
>> 19:24:02,196::task::568::TaskManager.Task::(_updateState)
>> Task=`b2f2abe6-13de-443e-a5a7-d2a63f422cef`::moving from state init ->
>> state preparing
>>
>> Thread-1696::INFO::2013-10-15
>> 19:24:02,197::logUtils::41::dispatcher::(wrapper) Run and protect:
>> getVolumeSize(sdUUID='fa3279ec-2912-45ac-b7bc-9fe89151ed99',
>> spUUID='430cd986-6488-403b-8d46-29abbc3eba38',
>> imgUUID='96312a42-8407-44ef-9aad-60c6778a3ae6',
>> volUUID='01474eea-fcb8-4294-b58b-b6134cadc3e2', options=None)
>>
>> Thread-1696::DEBUG::2013-10-15
>> 19:24:02,200::fileVolume::561::Storage.Volume::(validateVolumePath)
>> validate path for 01474eea-fcb8-4294-b58b-b6134cadc3e2
>>
>> Thread-1696::INFO::2013-10-15
>> 19:24:02,203::logUtils::44::dispatcher::(wrapper) Run and protect:
>> getVolumeSize, Return response: {'truesize': '1945018368', 'apparentsize':
>> '1937506304'}
>>
>> Thread-1696::DEBUG::2013-10-15
>> 19:24:02,203::task::1151::TaskManager.Task::(prepare)
>> Task=`b2f2abe6-13de-443e-a5a7-d2a63f422cef`::finished: {'truesize':
>> '1945018368', 'apparentsize': '1937506304'}
>>
>> Thread-1696::DEBUG::2013-10-15
>> 19:24:02,204::task::568::TaskManager.Task::(_updateState)
>> Task=`b2f2abe6-13de-443e-a5a7-d2a63f422cef`::moving from state
>> preparing -> state finished
>>
>> Thread-1696::DEBUG::2013-10-15
>> 19:24:02,204::resourceManager::830::ResourceManager.Owner::(releaseAll
>> ) Owner.releaseAll requests {} resources {}
>>
>> Thread-1696::DEBUG::2013-10-15
>> 19:24:02,204::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>>
>> Thread-1696::DEBUG::2013-10-15
>> 19:24:02,204::task::957::TaskManager.Task::(_decref)
>> Task=`b2f2abe6-13de-443e-a5a7-d2a63f422cef`::ref 0 aborting False
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:24:04,090::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 86.
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:24:05,092::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 65.
>>
>> Thread-363719::DEBUG::2013-10-15
>> 19:24:12,487::task::568::TaskManager.Task::(_updateState)
>> Task=`cb5f0f17-fe04-44b9-8fcb-7643e0ed0a11`::moving from state init ->
>> state preparing
>>
>> Thread-363719::INFO::2013-10-15
>> 19:24:12,488::logUtils::41::dispatcher::(wrapper) Run and protect:
>> repoStats(options=None)
>>
>> Thread-363719::INFO::2013-10-15
>> 19:24:12,489::logUtils::44::dispatcher::(wrapper) Run and protect:
>> repoStats, Return response: {'fa3279ec-2912-45ac-b7bc-9fe89151ed99':
>> {'delay': '0.00698399543762', 'lastCheck': '7.0', 'code': 0, 'valid':
>> True},
>> 'ee2ae498-6e45-448d-8f91-0efca377dcf6': {'delay': '0.00687909126282',
>> 'lastCheck': '9.9', 'code': 0, 'valid': True}}
>>
>> Thread-363719::DEBUG::2013-10-15
>> 19:24:12,489::task::1151::TaskManager.Task::(prepare)
>> Task=`cb5f0f17-fe04-44b9-8fcb-7643e0ed0a11`::finished:
>> {'fa3279ec-2912-45ac-b7bc-9fe89151ed99': {'delay': '0.00698399543762',
>> 'lastCheck': '7.0', 'code': 0, 'valid': True},
>> 'ee2ae498-6e45-448d-8f91-0efca377dcf6': {'delay': '0.00687909126282',
>> 'lastCheck': '9.9', 'code': 0, 'valid': True}}
>>
>> Thread-363719::DEBUG::2013-10-15
>> 19:24:12,489::task::568::TaskManager.Task::(_updateState)
>> Task=`cb5f0f17-fe04-44b9-8fcb-7643e0ed0a11`::moving from state
>> preparing -> state finished
>>
>> Thread-363719::DEBUG::2013-10-15
>> 19:24:12,490::resourceManager::830::ResourceManager.Owner::(releaseAll
>> ) Owner.releaseAll requests {} resources {}
>>
>> Thread-363719::DEBUG::2013-10-15
>> 19:24:12,490::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>>
>> Thread-363719::DEBUG::2013-10-15
>> 19:24:12,490::task::957::TaskManager.Task::(_decref)
>> Task=`cb5f0f17-fe04-44b9-8fcb-7643e0ed0a11`::ref 0 aborting False
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:24:13,099::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 78.
>>
>> Thread-89621::DEBUG::2013-10-15
>> 19:24:15,235::task::568::TaskManager.Task::(_updateState)
>> Task=`9a53f6e1-7fa3-4b09-bded-7f692c9ac8fd`::moving from state init ->
>> state preparing
>>
>> Thread-89621::INFO::2013-10-15
>> 19:24:15,235::logUtils::41::dispatcher::(wrapper) Run and protect:
>> getVolumeSize(sdUUID='fa3279ec-2912-45ac-b7bc-9fe89151ed99',
>> spUUID='430cd986-6488-403b-8d46-29abbc3eba38',
>> imgUUID='86fd8e9f-dba9-4f74-90b1-b6db5b89f2d3',
>> volUUID='ec6af89e-c1bd-4158-a792-53db7ecb530c', options=None)
>>
>> Thread-89621::DEBUG::2013-10-15
>> 19:24:15,239::fileVolume::561::Storage.Volume::(validateVolumePath)
>> validate path for ec6af89e-c1bd-4158-a792-53db7ecb530c
>>
>> Thread-89621::INFO::2013-10-15
>> 19:24:15,242::logUtils::44::dispatcher::(wrapper) Run and protect:
>> getVolumeSize, Return response: {'truesize': '43427708928', 'apparentsize':
>> '53687091200'}
>>
>> Thread-89621::DEBUG::2013-10-15
>> 19:24:15,242::task::1151::TaskManager.Task::(prepare)
>> Task=`9a53f6e1-7fa3-4b09-bded-7f692c9ac8fd`::finished: {'truesize':
>> '43427708928', 'apparentsize': '53687091200'}
>>
>> Thread-89621::DEBUG::2013-10-15
>> 19:24:15,242::task::568::TaskManager.Task::(_updateState)
>> Task=`9a53f6e1-7fa3-4b09-bded-7f692c9ac8fd`::moving from state
>> preparing -> state finished
>>
>> Thread-89621::DEBUG::2013-10-15
>> 19:24:15,243::resourceManager::830::ResourceManager.Owner::(releaseAll
>> ) Owner.releaseAll requests {} resources {}
>>
>> Thread-89621::DEBUG::2013-10-15
>> 19:24:15,243::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>>
>> Thread-89621::DEBUG::2013-10-15
>> 19:24:15,243::task::957::TaskManager.Task::(_decref)
>> Task=`9a53f6e1-7fa3-4b09-bded-7f692c9ac8fd`::ref 0 aborting False
>>
>> Thread-89621::DEBUG::2013-10-15
>> 19:24:15,244::task::568::TaskManager.Task::(_updateState)
>> Task=`f38a9b5b-f5cf-4bb2-b0aa-3d61a6091ef6`::moving from state init ->
>> state preparing
>>
>> Thread-89621::INFO::2013-10-15
>> 19:24:15,244::logUtils::41::dispatcher::(wrapper) Run and protect:
>> getVolumeSize(sdUUID='fa3279ec-2912-45ac-b7bc-9fe89151ed99',
>> spUUID='430cd986-6488-403b-8d46-29abbc3eba38',
>> imgUUID='253d7bfc-c3b3-4ab2-bc48-0ea06dfea662',
>> volUUID='f347ea5a-db1e-42e6-8761-ae4dbb7fe3bd', options=None)
>>
>> Thread-89621::DEBUG::2013-10-15
>> 19:24:15,248::fileVolume::561::Storage.Volume::(validateVolumePath)
>> validate path for f347ea5a-db1e-42e6-8761-ae4dbb7fe3bd
>>
>> Thread-89621::INFO::2013-10-15
>> 19:24:15,251::logUtils::44::dispatcher::(wrapper) Run and protect:
>> getVolumeSize, Return response: {'truesize': '201092349952', 'apparentsize':
>> '214748364800'}
>>
>> Thread-89621::DEBUG::2013-10-15
>> 19:24:15,251::task::1151::TaskManager.Task::(prepare)
>> Task=`f38a9b5b-f5cf-4bb2-b0aa-3d61a6091ef6`::finished: {'truesize':
>> '201092349952', 'apparentsize': '214748364800'}
>>
>> Thread-89621::DEBUG::2013-10-15
>> 19:24:15,251::task::568::TaskManager.Task::(_updateState)
>> Task=`f38a9b5b-f5cf-4bb2-b0aa-3d61a6091ef6`::moving from state
>> preparing -> state finished
>>
>> Thread-89621::DEBUG::2013-10-15
>> 19:24:15,251::resourceManager::830::ResourceManager.Owner::(releaseAll
>> ) Owner.releaseAll requests {} resources {}
>>
>> Thread-89621::DEBUG::2013-10-15
>> 19:24:15,252::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>>
>> Thread-89621::DEBUG::2013-10-15
>> 19:24:15,252::task::957::TaskManager.Task::(_decref)
>> Task=`f38a9b5b-f5cf-4bb2-b0aa-3d61a6091ef6`::ref 0 aborting False
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:24:18,103::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 93.
>>
>> Thread-3186::DEBUG::2013-10-15
>> 19:24:20,579::task::568::TaskManager.Task::(_updateState)
>> Task=`26d73e84-3fb2-4e6f-aaeb-1907eeba0383`::moving from state init ->
>> state preparing
>>
>> Thread-3186::INFO::2013-10-15
>> 19:24:20,580::logUtils::41::dispatcher::(wrapper) Run and protect:
>> getVolumeSize(sdUUID='fa3279ec-2912-45ac-b7bc-9fe89151ed99',
>> spUUID='430cd986-6488-403b-8d46-29abbc3eba38',
>> imgUUID='9025469e-78c7-4c22-affa-fefc04558cc1',
>> volUUID='4f275b5a-bb0c-46da-8fc1-36cb21c982f1', options=None)
>>
>> Thread-3197::DEBUG::2013-10-15
>> 19:24:20,580::task::568::TaskManager.Task::(_updateState)
>> Task=`6d3441fa-a343-4e83-a8d7-ba029eaf3854`::moving from state init ->
>> state preparing
>>
>> Thread-3197::INFO::2013-10-15
>> 19:24:20,581::logUtils::41::dispatcher::(wrapper) Run and protect:
>> getVolumeSize(sdUUID='fa3279ec-2912-45ac-b7bc-9fe89151ed99',
>> spUUID='430cd986-6488-403b-8d46-29abbc3eba38',
>> imgUUID='add15d07-5c94-428d-affe-d4d6e0c8b9b0',
>> volUUID='066c921f-d9cc-4d4d-8283-dde22138a9f6', options=None)
>>
>> Thread-3304::DEBUG::2013-10-15
>> 19:24:20,584::task::568::TaskManager.Task::(_updateState)
>> Task=`de16904a-b59f-41f9-b48c-860cbc43f5ba`::moving from state init ->
>> state preparing
>>
>> Thread-3304::INFO::2013-10-15
>> 19:24:20,584::logUtils::41::dispatcher::(wrapper) Run and protect:
>> getVolumeSize(sdUUID='fa3279ec-2912-45ac-b7bc-9fe89151ed99',
>> spUUID='430cd986-6488-403b-8d46-29abbc3eba38',
>> imgUUID='3f580639-d72a-464f-8ed3-2453cbf9196a',
>> volUUID='e2b2c6a3-38c8-4a97-9747-fc508f985448', options=None)
>>
>> Thread-3186::DEBUG::2013-10-15
>> 19:24:20,586::fileVolume::561::Storage.Volume::(validateVolumePath)
>> validate path for 4f275b5a-bb0c-46da-8fc1-36cb21c982f1
>>
>> Thread-3197::DEBUG::2013-10-15
>> 19:24:20,588::fileVolume::561::Storage.Volume::(validateVolumePath)
>> validate path for 066c921f-d9cc-4d4d-8283-dde22138a9f6
>>
>> Thread-3186::INFO::2013-10-15
>> 19:24:20,592::logUtils::44::dispatcher::(wrapper) Run and protect:
>> getVolumeSize, Return response: {'truesize': '3157008384', 'apparentsize':
>> '3144744960'}
>>
>> Thread-3304::DEBUG::2013-10-15
>> 19:24:20,592::fileVolume::561::Storage.Volume::(validateVolumePath)
>> validate path for e2b2c6a3-38c8-4a97-9747-fc508f985448
>>
>> Thread-3197::INFO::2013-10-15
>> 19:24:20,593::logUtils::44::dispatcher::(wrapper) Run and protect:
>> getVolumeSize, Return response: {'truesize': '4603097088', 'apparentsize':
>> '4585160704'}
>>
>> Thread-3186::DEBUG::2013-10-15
>> 19:24:20,593::task::1151::TaskManager.Task::(prepare)
>> Task=`26d73e84-3fb2-4e6f-aaeb-1907eeba0383`::finished: {'truesize':
>> '3157008384', 'apparentsize': '3144744960'}
>>
>> Thread-3197::DEBUG::2013-10-15
>> 19:24:20,594::task::1151::TaskManager.Task::(prepare)
>> Task=`6d3441fa-a343-4e83-a8d7-ba029eaf3854`::finished: {'truesize':
>> '4603097088', 'apparentsize': '4585160704'}
>>
>> Thread-3186::DEBUG::2013-10-15
>> 19:24:20,594::task::568::TaskManager.Task::(_updateState)
>> Task=`26d73e84-3fb2-4e6f-aaeb-1907eeba0383`::moving from state
>> preparing -> state finished
>>
>> Thread-3197::DEBUG::2013-10-15
>> 19:24:20,595::task::568::TaskManager.Task::(_updateState)
>> Task=`6d3441fa-a343-4e83-a8d7-ba029eaf3854`::moving from state
>> preparing -> state finished
>>
>> Thread-3186::DEBUG::2013-10-15
>> 19:24:20,595::resourceManager::830::ResourceManager.Owner::(releaseAll
>> ) Owner.releaseAll requests {} resources {}
>>
>> Thread-3197::DEBUG::2013-10-15
>> 19:24:20,596::resourceManager::830::ResourceManager.Owner::(releaseAll
>> ) Owner.releaseAll requests {} resources {}
>>
>> Thread-3186::DEBUG::2013-10-15
>> 19:24:20,596::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>>
>> Thread-3304::INFO::2013-10-15
>> 19:24:20,597::logUtils::44::dispatcher::(wrapper) Run and protect:
>> getVolumeSize, Return response: {'truesize': '3145695232', 'apparentsize':
>> '3133472768'}
>>
>> Thread-3197::DEBUG::2013-10-15
>> 19:24:20,597::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>>
>> Thread-3186::DEBUG::2013-10-15
>> 19:24:20,597::task::957::TaskManager.Task::(_decref)
>> Task=`26d73e84-3fb2-4e6f-aaeb-1907eeba0383`::ref 0 aborting False
>>
>> Thread-3304::DEBUG::2013-10-15
>> 19:24:20,598::task::1151::TaskManager.Task::(prepare)
>> Task=`de16904a-b59f-41f9-b48c-860cbc43f5ba`::finished: {'truesize':
>> '3145695232', 'apparentsize': '3133472768'}
>>
>> Thread-3197::DEBUG::2013-10-15
>> 19:24:20,598::task::957::TaskManager.Task::(_decref)
>> Task=`6d3441fa-a343-4e83-a8d7-ba029eaf3854`::ref 0 aborting False
>>
>> Thread-3304::DEBUG::2013-10-15
>> 19:24:20,598::task::568::TaskManager.Task::(_updateState)
>> Task=`de16904a-b59f-41f9-b48c-860cbc43f5ba`::moving from state
>> preparing -> state finished
>>
>> Thread-3304::DEBUG::2013-10-15
>> 19:24:20,599::resourceManager::830::ResourceManager.Owner::(releaseAll
>> ) Owner.releaseAll requests {} resources {}
>>
>> Thread-3304::DEBUG::2013-10-15
>> 19:24:20,599::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>>
>> Thread-3304::DEBUG::2013-10-15
>> 19:24:20,599::task::957::TaskManager.Task::(_decref)
>> Task=`de16904a-b59f-41f9-b48c-860cbc43f5ba`::ref 0 aborting False
>>
>> Thread-363725::DEBUG::2013-10-15
>> 19:24:22,791::task::568::TaskManager.Task::(_updateState)
>> Task=`f29b0787-f8a0-4ac2-be7d-153b14d77be3`::moving from state init ->
>> state preparing
>>
>> Thread-363725::INFO::2013-10-15
>> 19:24:22,792::logUtils::41::dispatcher::(wrapper) Run and protect:
>> repoStats(options=None)
>>
>> Thread-363725::INFO::2013-10-15
>> 19:24:22,792::logUtils::44::dispatcher::(wrapper) Run and protect:
>> repoStats, Return response: {'fa3279ec-2912-45ac-b7bc-9fe89151ed99':
>> {'delay': '0.00645804405212', 'lastCheck': '7.3', 'code': 0, 'valid':
>> True},
>> 'ee2ae498-6e45-448d-8f91-0efca377dcf6': {'delay': '0.00722193717957',
>> 'lastCheck': '0.2', 'code': 0, 'valid': True}}
>>
>> Thread-363725::DEBUG::2013-10-15
>> 19:24:22,792::task::1151::TaskManager.Task::(prepare)
>> Task=`f29b0787-f8a0-4ac2-be7d-153b14d77be3`::finished:
>> {'fa3279ec-2912-45ac-b7bc-9fe89151ed99': {'delay': '0.00645804405212',
>> 'lastCheck': '7.3', 'code': 0, 'valid': True},
>> 'ee2ae498-6e45-448d-8f91-0efca377dcf6': {'delay': '0.00722193717957',
>> 'lastCheck': '0.2', 'code': 0, 'valid': True}}
>>
>> Thread-363725::DEBUG::2013-10-15
>> 19:24:22,793::task::568::TaskManager.Task::(_updateState)
>> Task=`f29b0787-f8a0-4ac2-be7d-153b14d77be3`::moving from state
>> preparing -> state finished
>>
>> Thread-363725::DEBUG::2013-10-15
>> 19:24:22,793::resourceManager::830::ResourceManager.Owner::(releaseAll
>> ) Owner.releaseAll requests {} resources {}
>>
>> Thread-363725::DEBUG::2013-10-15
>> 19:24:22,793::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>>
>> Thread-363725::DEBUG::2013-10-15
>> 19:24:22,794::task::957::TaskManager.Task::(_decref)
>> Task=`f29b0787-f8a0-4ac2-be7d-153b14d77be3`::ref 0 aborting False
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:24:26,110::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 20.
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:24:29,113::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 83.
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:24:32,115::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 60.
>>
>> Thread-363731::DEBUG::2013-10-15
>> 19:24:33,081::task::568::TaskManager.Task::(_updateState)
>> Task=`f6fb70e4-5130-4ef3-8e78-603f3bf20447`::moving from state init ->
>> state preparing
>>
>> Thread-363731::INFO::2013-10-15
>> 19:24:33,081::logUtils::41::dispatcher::(wrapper) Run and protect:
>> repoStats(options=None)
>>
>> Thread-363731::INFO::2013-10-15
>> 19:24:33,082::logUtils::44::dispatcher::(wrapper) Run and protect:
>> repoStats, Return response: {'fa3279ec-2912-45ac-b7bc-9fe89151ed99':
>> {'delay': '0.00757598876953', 'lastCheck': '7.5', 'code': 0, 'valid':
>> True},
>> 'ee2ae498-6e45-448d-8f91-0efca377dcf6': {'delay': '0.00686383247375',
>> 'lastCheck': '0.4', 'code': 0, 'valid': True}}
>>
>> Thread-363731::DEBUG::2013-10-15
>> 19:24:33,082::task::1151::TaskManager.Task::(prepare)
>> Task=`f6fb70e4-5130-4ef3-8e78-603f3bf20447`::finished:
>> {'fa3279ec-2912-45ac-b7bc-9fe89151ed99': {'delay': '0.00757598876953',
>> 'lastCheck': '7.5', 'code': 0, 'valid': True},
>> 'ee2ae498-6e45-448d-8f91-0efca377dcf6': {'delay': '0.00686383247375',
>> 'lastCheck': '0.4', 'code': 0, 'valid': True}}
>>
>> Thread-363731::DEBUG::2013-10-15
>> 19:24:33,082::task::568::TaskManager.Task::(_updateState)
>> Task=`f6fb70e4-5130-4ef3-8e78-603f3bf20447`::moving from state
>> preparing -> state finished
>>
>> Thread-363731::DEBUG::2013-10-15
>> 19:24:33,082::resourceManager::830::ResourceManager.Owner::(releaseAll
>> ) Owner.releaseAll requests {} resources {}
>>
>> Thread-363731::DEBUG::2013-10-15
>> 19:24:33,083::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>>
>> Thread-363731::DEBUG::2013-10-15
>> 19:24:33,083::task::957::TaskManager.Task::(_decref)
>> Task=`f6fb70e4-5130-4ef3-8e78-603f3bf20447`::ref 0 aborting False
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:24:34,117::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 86.
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:24:35,119::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 65.
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:24:43,125::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 78.
>>
>> Thread-363737::DEBUG::2013-10-15
>> 19:24:43,372::task::568::TaskManager.Task::(_updateState)
>> Task=`576f2cb3-5299-4c0e-a0d8-08f664ce6fdb`::moving from state init ->
>> state preparing
>>
>> Thread-363737::INFO::2013-10-15
>> 19:24:43,373::logUtils::41::dispatcher::(wrapper) Run and protect:
>> repoStats(options=None)
>>
>> Thread-363737::INFO::2013-10-15
>> 19:24:43,373::logUtils::44::dispatcher::(wrapper) Run and protect:
>> repoStats, Return response: {'fa3279ec-2912-45ac-b7bc-9fe89151ed99':
>> {'delay': '0.00689101219177', 'lastCheck': '7.8', 'code': 0, 'valid':
>> True},
>> 'ee2ae498-6e45-448d-8f91-0efca377dcf6': {'delay': '0.00665497779846',
>> 'lastCheck': '0.7', 'code': 0, 'valid': True}}
>>
>> Thread-363737::DEBUG::2013-10-15
>> 19:24:43,374::task::1151::TaskManager.Task::(prepare)
>> Task=`576f2cb3-5299-4c0e-a0d8-08f664ce6fdb`::finished:
>> {'fa3279ec-2912-45ac-b7bc-9fe89151ed99': {'delay': '0.00689101219177',
>> 'lastCheck': '7.8', 'code': 0, 'valid': True},
>> 'ee2ae498-6e45-448d-8f91-0efca377dcf6': {'delay': '0.00665497779846',
>> 'lastCheck': '0.7', 'code': 0, 'valid': True}}
>>
>> Thread-363737::DEBUG::2013-10-15
>> 19:24:43,374::task::568::TaskManager.Task::(_updateState)
>> Task=`576f2cb3-5299-4c0e-a0d8-08f664ce6fdb`::moving from state
>> preparing -> state finished
>>
>> Thread-363737::DEBUG::2013-10-15
>> 19:24:43,374::resourceManager::830::ResourceManager.Owner::(releaseAll
>> ) Owner.releaseAll requests {} resources {}
>>
>> Thread-363737::DEBUG::2013-10-15
>> 19:24:43,375::resourceManager::864::ResourceManager.Owner::(cancelAll)
>> Owner.cancelAll requests {}
>>
>> Thread-363737::DEBUG::2013-10-15
>> 19:24:43,375::task::957::TaskManager.Task::(_decref)
>> Task=`576f2cb3-5299-4c0e-a0d8-08f664ce6fdb`::ref 0 aborting False
>>
>> VM Channels Listener::DEBUG::2013-10-15
>> 19:24:48,129::vmChannels::61::vds::(_handle_timeouts) Timeout on fileno 93.
>>
>>
>>
>>
>>
>>
>>
>> -----Original Message-----
>> From: Daniel Erez [mailto:derez at redhat.com]
>> Sent: Monday, October 14, 2013 2:44 PM
>> To: Aslam, Usman
>> Cc: users at ovirt.org
>> Subject: Re: [Users] Unable to remove Vdisk and Ovirt UI spams
>> finished messages
>>
>>
>>
>>
>>
>>
>>
>> ----- Original Message -----
>>
>>> From: "Usman Aslam"
>>> <Usman.Aslam at tufts.edu<mailto:Usman.Aslam at tufts.edu>>
>>
>>> To: users at ovirt.org<mailto:users at ovirt.org>
>>
>>> Sent: Wednesday, October 9, 2013 2:28:05 AM
>>
>>> Subject: [Users] Unable to remove Vdisk and Ovirt UI spams finished
>>
>>> messages
>>
>>>
>>
>>> So I removed a Vdisk from a powered off VM a few hours ago. The Disk
>>
>>> still shows it has a lock on it and the webUI keeps showing this
>>
>>> message every 10 seconds or so.
>>
>>>
>>
>>> 2013-Oct-08, 19:22:09 User <UNKNOWN> finished to remove the disk
>>
>>> tuskdb-dev-01_vdisk01_50gb from domain TSS-TUSK-DC_NFS-VM-Stor.
>>
>>> 2013-Oct-08, 19:21:59 User <UNKNOWN> finished to remove the disk
>>
>>> tuskdb-dev-01_vdisk01_50gb from domain TSS-TUSK-DC_NFS-VM-Stor.
>>
>>> 2013-Oct-08, 19:21:49 User <UNKNOWN> finished to remove the disk
>>
>>> tuskdb-dev-01_vdisk01_50gb from domain TSS-TUSK-DC_NFS-VM-Stor.
>>
>>> 2013-Oct-08, 19:21:39 User <UNKNOWN> finished to remove the disk
>>
>>> tuskdb-dev-01_vdisk01_50gb from domain TSS-TUSK-DC_NFS-VM-Stor.
>>
>>> 2013-Oct-08, 19:21:29 User <UNKNOWN> finished to remove the disk
>>
>>> tuskdb-dev-01_vdisk01_50gb from domain TSS-TUSK-DC_NFS-VM-Stor.
>>
>>>
>>
>>> I've tried restarting the SPM Hypervisor and the Ovirt Engine. Still
>>> no dice.
>>
>>> Which host would have the lock? Where should I look for log files?
>>
>>
>>
>> The logs for vdsm/engine are located at /var/log/vdsm/ and
>> /var/log/ovirt-engine/ correspondingly.
>>
>> Try to check if there's any non-cleared task at the SPM (vdsClient ->
>> getAllTasks).
>>
>> For manually clearing the task, the async_task table in the DB can be
>> manipulated.
>>
>> Disk's status resides at images tables -> imagestatus column ('1' for
>> OK/unlocked).
>>
>> Please attach vdsm/engine logs for further investigation...
>>
>>
>>
>>>
>>
>>> Thanks,
>>
>>> Usman
>>
>>> _______________________________________________
>>
>>> Users mailing list
>>
>>> Users at ovirt.org<mailto:Users at ovirt.org>
>>
>>> http://lists.ovirt.org/mailman/listinfo/users
>>
>>>
>>
> _______________________________________________
> Users mailing list
> Users at ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
>
More information about the Users
mailing list