I will do upgrades one version at a time. I dont see an option to upgrade vsdm on hypervisors via engine.. is that a feature of a new engine? Also what whould I upgrade first, engine or vsdm on nodes? Thanks, Usman
From my Android phone on T-Mobile. The first nationwide 4G network.
-------- Original message -------- From: Itamar Heim <iheim@redhat.com> Date: 10/17/2013 8:30 AM (GMT-05:00) To: "Aslam, Usman" <Usman.Aslam@tufts.edu> Cc: Daniel Erez <derez@redhat.com>,users@ovirt.org Subject: Re: [Users] Unable to remove Vdisk and Ovirt UI spams finished messages 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@redhat.com] Sent: Wednesday, October 16, 2013 10:10 AM To: Aslam, Usman Cc: users@ovirt.org Subject: Re: [Users] Unable to remove Vdisk and Ovirt UI spams finished messages
----- Original Message -----
From: "Usman Aslam" <Usman.Aslam@tufts.edu> To: "Daniel Erez" <derez@redhat.com> Cc: users@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@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@redhat.com] Sent: Monday, October 14, 2013 2:44 PM To: Aslam, Usman Cc: users@ovirt.org Subject: Re: [Users] Unable to remove Vdisk and Ovirt UI spams finished messages
----- Original Message -----
From: "Usman Aslam" <Usman.Aslam@tufts.edu<mailto:Usman.Aslam@tufts.edu>>
To: users@ovirt.org<mailto:users@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@ovirt.org<mailto:Users@ovirt.org>
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users