[Users] Unable to remove Vdisk and Ovirt UI spams finished messages
Aslam, Usman
Usman.Aslam at tufts.edu
Tue Oct 15 23:27:44 UTC 2013
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!
###*** 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
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ovirt.org/pipermail/users/attachments/20131015/8e0b9338/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image001.png
Type: image/png
Size: 27288 bytes
Desc: image001.png
URL: <http://lists.ovirt.org/pipermail/users/attachments/20131015/8e0b9338/attachment-0001.png>
More information about the Users
mailing list