Bug 1078095

Created attachment 876239 [details]
engine and vdsm logs

Daniel, this seems like a general issue in live snapshot, unrelated to LSM.
Can you confirm please?

Allon,
I checked the same scenario only for live snapshot. Engine poll the createVolume tasks and order vdsm to stop them in a case of a failure due to connectivity loss with storage:

2014-03-20 11:36:04,646 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-65) SPMAsyncTask::PollTask: Polling task 881b1a2a-6807-4cb1-8d0d-0e8fbdd2d6c0 (Parent Command CreateAllSnapshotsFromVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'success'.
2014-03-20 11:36:04,651 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-65) BaseAsyncTask::OnTaskEndSuccess: Task 881b1a2a-6807-4cb1-8d0d-0e8fbdd2d6c0 (Parent Command CreateAllSnapshotsFromVm, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended successfully.


 2014-03-20 11:37:04,903 ERROR [org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand] (org.ovirt.thread.pool-4-thread-24) Ending command with failure: org.ovirt.engine.core.bll.CreateAllSnapshotsFromVmCommand
2014-03-20 11:37:04,907 INFO  [org.ovirt.engine.core.bll.RemoveMemoryVolumesCommand] (org.ovirt.thread.pool-4-thread-24) [736dc00b] Running command: RemoveMemoryVolumesCommand internal: true.

The described scenario can't be reproduced on latest 3.5 build (neither in QE nor development environments). Please re-open if reproduced.

Created attachment 949970 [details]
logs-23.10

I was able to reproduce the issue. The bug seems to be reproduced after performing the steps twice.

Thread-2483::DEBUG::2014-10-23 18:01:01,212::task::1191::Storage.TaskManager.Task::(prepare) Task=`7382f113-3421-4512-9566-f6bf49511c2f`::finished: {'tasks': {'5ab731f6-ca3d-4179-a475-dd3ea37a48ce': {'code': 0, 'tag': u'spm', 'state': 'running', 'verb': 'createVolume', 'result': '', 'message': 'running job 1 of 1', 'id': '5ab731f6-ca3d-4179-a475-dd3ea37a48ce'}}}

Disk and snapshot remain in status LOCKED, createVolume task is not cleaned from SPM

Uploading the logs

Hi Elad,

On which engine build have you reproduced it?

Hi Ravi,

It seems that the task isn't being cleaned in the described scenario.
Could it be related to async tasks infrastructure changes?

If the AsyncTaskManager does not clear the task, there's nothing to trigger the storage code there, so I'm not sure how we can do anything useful here.

(In reply to Daniel Erez from comment #6)
> Hi Elad,
> 
> On which engine build have you reproduced it?

vt7
rhevm-3.5.0-0.17.beta.el6ev.noarch

(In reply to Daniel Erez from comment #7)
> Hi Ravi,
> 
> It seems that the task isn't being cleaned in the described scenario.
> Could it be related to async tasks infrastructure changes?
> 
> If the AsyncTaskManager does not clear the task, there's nothing to trigger
> the storage code there, so I'm not sure how we can do anything useful here.

Adding back needinfo on Ravi.

I was able to reproduce this. Here is what I did

1. Start VM with preallocated disk of 10GB
2. Move disk from Storage domain Data1 to Data2 while VM is running
3. Block connectivity from SPM to storage server where the target domain is located on while createVolume task is running on vdsm

Now the VM's disk remains locked until I fix the connectivity between the SPM and target storage domain. Once the connectivity is fixed the disk is unlocked, the operation is marked as failure and the async tasks table is cleared.

IMO this is the correct behavior, I don't think having a timeout for storage operations is something we need to introduce for 3.5

While the storage domain is down there is no polling or activity in the logs because the getAllTasksStatuses fails with the following vdcBLLException which is logged as debug messages

org.ovirt.engine.core.common.errors.VdcBLLException: VdcBLLException: Cannot allocate IRS server (Failed with error IRS_REPOSITORY_NOT_FOUND and code 5009)

(In reply to Ravi Nori from comment #10)
> I was able to reproduce this. Here is what I did
> 
> 1. Start VM with preallocated disk of 10GB
> 2. Move disk from Storage domain Data1 to Data2 while VM is running
> 3. Block connectivity from SPM to storage server where the target domain is
> located on while createVolume task is running on vdsm
> 
> Now the VM's disk remains locked until I fix the connectivity between the
> SPM and target storage domain. Once the connectivity is fixed the disk is
> unlocked, the operation is marked as failure and the async tasks table is
> cleared.
>  
> IMO this is the correct behavior, I don't think having a timeout for storage
> operations is something we need to introduce for 3.5
> 
> While the storage domain is down there is no polling or activity in the logs
> because the getAllTasksStatuses fails with the following vdcBLLException
> which is logged as debug messages
> 
> org.ovirt.engine.core.common.errors.VdcBLLException: VdcBLLException: Cannot
> allocate IRS server (Failed with error IRS_REPOSITORY_NOT_FOUND and code
> 5009)

Ravi, it's not the case. please try the steps written in comment #5. The connectivity between SPM and the storage was resumed. The task is not cleared from vdsm because engine doesn't poll it.

(In reply to Elad from comment #11)
> (In reply to Ravi Nori from comment #10)
> > I was able to reproduce this. Here is what I did
> > 
> > 1. Start VM with preallocated disk of 10GB
> > 2. Move disk from Storage domain Data1 to Data2 while VM is running
> > 3. Block connectivity from SPM to storage server where the target domain is
> > located on while createVolume task is running on vdsm
> > 
> > Now the VM's disk remains locked until I fix the connectivity between the
> > SPM and target storage domain. Once the connectivity is fixed the disk is
> > unlocked, the operation is marked as failure and the async tasks table is
> > cleared.
> >  
> > IMO this is the correct behavior, I don't think having a timeout for storage
> > operations is something we need to introduce for 3.5
> > 
> > While the storage domain is down there is no polling or activity in the logs
> > because the getAllTasksStatuses fails with the following vdcBLLException
> > which is logged as debug messages
> > 
> > org.ovirt.engine.core.common.errors.VdcBLLException: VdcBLLException: Cannot
> > allocate IRS server (Failed with error IRS_REPOSITORY_NOT_FOUND and code
> > 5009)
> 
> Ravi, it's not the case. please try the steps written in comment #5. The
> connectivity between SPM and the storage was resumed. The task is not
> cleared from vdsm because engine doesn't poll it.

Ravi, iiuc, the task has been properly cleared once you've restored the connectivity (btw, similarly to the behavior on my tests as well though it took quite a while for the tasks to be cleared). What do you think? Any reason for the tasks not being cleared after the connectivity is resumed?

No tasks remained stuck on the vdsm, and the disk status was set back to "OK"
Verified on VDSM vt11

RHEV-M 3.5.0 has been released, closing this bug.

RHEV-M 3.5.0 has been released, closing this bug.