8:29 a.m.
Hi Gianluca,
Can you try to reproduce it with FC? Maybe it's somehow related to that.
Did you try to lvremove the old lv's, or are they still in use?
Trying to do this from the SPM should be ok. What do you mean synchronize
the information at the other node side?
In any case, this is a disk that you don't need anymore, isn't it? You said
that the copy part of the move operation went well.
Regards,
Idan
On Thu, Oct 19, 2017 at 10:47 AM, Gianluca Cecchi <gianluca.cecchi(a)gmail.com
wrote:
> On Thu, Oct 19, 2017 at 7:36 AM, Idan Shaby <ishaby(a)redhat.com wrote:
>
>> Hi Gianluca,
>>
>> This sounds like a bug to me.
>> Can you please attach engine and vdsm logs?
>>
>>
>> Thanks,
>> Idan
>>
>
> Hi Idan,
> I have not at hand the full files right now, but these were the snippets I
> cut from vdsm log and engine.log yesterday around the time of the first
> error after sending the first e-mail
> It seems vdsm reports that the logical volume is still in use while trying
> to remove it....
> I have tried to replicate on another environment also based on block
> storage, but now iSCSI and not FC and I was not able to get the error: the
> move disk operation of the powered off vm always completed successfully.
> Both tests were done trying to move preallocated disks if that matters
>
> vdsm.log of host1
>
> 2017-10-18 14:59:28,907+0200 ERROR (libvirt/events)
> [storage.TaskManager.Task] (Task='6331ec00-b75b-465e-8d9c-04d465c09ea1')
> Unexpected error (task:872)
> Traceback (most recent call last):
> File "/usr/share/vdsm/storage/task.py", line 879, in _run
> return fn(*args, **kargs)
> File "<string>", line 2, in teardownImage
> File "/usr/lib/python2.7/site-packages/vdsm/common/api.py", line 48, in
> method
> ret = func(*args, **kwargs)
> File "/usr/share/vdsm/storage/hsm.py", line 3189, in teardownImage
> dom.deactivateImage(imgUUID)
> File "/usr/share/vdsm/storage/blockSD.py", line 1289, in deactivateImage
> lvm.deactivateLVs(self.sdUUID, volUUIDs)
> File "/usr/share/vdsm/storage/lvm.py", line 1304, in deactivateLVs
> _setLVAvailability(vgName, toDeactivate, "n")
> File "/usr/share/vdsm/storage/lvm.py", line 843, in _setLVAvailability
> raise error(str(e))
> CannotDeactivateLogicalVolume: Cannot deactivate Logical Volume: ('General
> Storage Exception: ("5 [] [\' Logical volume c5d360f5-cd90-4b3e-bdef-
> 924649bfbc5f/eff58f10-12bf-412f-a5db-944bfb10904d is used by another
> device.\']\\nc5d360f5-cd90-4b3e-bdef-924649bfbc5f/[\'
> eff58f10-12bf-412f-a5db-944bfb10904d\']",)',)
> 2017-10-18 14:59:28,907+0200 INFO (libvirt/events)
> [storage.TaskManager.Task] (Task='6331ec00-b75b-465e-8d9c-04d465c09ea1')
> aborting: Task is aborted: 'Cannot deactivate Logical Volume: (\'General
> Storage Exception: ("5 [] [\\\' Logical volume c5d360f5-cd90-4b3e-bdef-
> 924649bfbc5f/eff58f10-12bf-412f-a5db-944bfb10904d is used by another
> device.\\\']\\\\nc5d360f5-cd90-4b3e-bdef-924649bfbc5f/[\
> \\'eff58f10-12bf-412f-a5db-944bfb10904d\\\']",)\',)' - code 552
> (task:1177)
> 2017-10-18 14:59:28,908+0200 ERROR (libvirt/events) [storage.Dispatcher]
> FINISH teardownImage error=Cannot deactivate Logical Volume: ('General
> Storage Exception: ("5 [] [\' Logical volume c5d360f5-cd90-4b3e-bdef-
> 924649bfbc5f/eff58f10-12bf-412f-a5db-944bfb10904d is used by another
> device.\']\\nc5d360f5-cd90-4b3e-bdef-924649bfbc5f/[\'
> eff58f10-12bf-412f-a5db-944bfb10904d\']",)',) (dispatcher:81)
>
> engine.log
> 2017-10-18 15:01:53,097+02 INFO [org.ovirt.engine.core.dal.
> dbbroker.auditloghandling.AuditLogDirector] (D
> efaultQuartzScheduler6) [] EVENT_ID: USER_MOVED_DISK_FINISHED_SUCCESS(2,010),
> Correlation ID: a8948cbf-80a
> 2-462d-8805-91da94868c6e, Job ID: ffba7504-a324-43ca-ab4c-481610c1098b,
> Call Stack: null, Custom ID: null,
> Custom Event ID: -1, Message: User gcecchi@internal-authz finished
> moving disk padora1_u01 to domain SATA
> _ALLBCK.
> 2017-10-18 15:01:54,029+02 ERROR [org.ovirt.engine.core.dal.
> dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler5)
> [394f8568] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), Correlation ID:
> null, Call Stack: null, Custom ID: null, Custom Event ID: -1, Message: VDSM
> host1 command HSMGetAllTasksStatusesVDS failed: Cannot remove Logical
> Volume: (['Cannot remove Logical Volume:
(u\'c5d360f5-cd90-4b3e-bdef-924649bfbc5f\',
> "[\'2255c544-165b-4126-86ee-70e6d1edef9a\']")'],)
> 2017-10-18 15:01:54,029+02 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
> (DefaultQuartzScheduler5) [394f8568] SPMAsyncTask::PollTask: Polling task
> '8446a883-9bb0-40a5-b1eb-8a919defe4c0' (Parent Command
'RemoveImage',
> Parameters Type
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters')
> returned status 'finished', result 'cleanSuccess'.
> 2017-10-18 15:01:54,029+02 ERROR [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
> (DefaultQuartzScheduler5) [394f8568] BaseAsyncTask::logEndTaskFailure:
> Task '8446a883-9bb0-40a5-b1eb-8a919defe4c0' (Parent Command
> 'RemoveImage', Parameters Type
'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters')
> ended with failure:
> -- Result: 'cleanSuccess'
> -- Message: 'VDSGenericException: VDSErrorException: Failed in vdscommand
> to HSMGetAllTasksStatusesVDS, error = Cannot remove Logical Volume:
> (['Cannot remove Logical Volume:
(u\'c5d360f5-cd90-4b3e-bdef-924649bfbc5f\',
> "[\'2255c544-165b-4126-86ee-70e6d1edef9a\']")'],)',
> -- Exception: 'VDSGenericException: VDSErrorException: Failed in
> vdscommand to HSMGetAllTasksStatusesVDS, error = Cannot remove Logical
> Volume: (['Cannot remove Logical Volume:
(u\'c5d360f5-cd90-4b3e-bdef-924649bfbc5f\',
> "[\'2255c544-165b-4126-86ee-70e6d1edef9a\']")'],)'
>
> Is there any command I can run to consistently remove the stale LVs?
> As oVirt doesn't use clvmd I don't think it is sufficient to issue the
> remove lv from the SPM node.. How will "synchronize" the information at
the
> other node side?
>
> Thanks,
> Gianluca
>
>
8:59 a.m.
New subject: move disk and lv not removed
On Tue, Oct 24, 2017 at 8:29 AM, Idan Shaby <ishaby(a)redhat.com> wrote:
Hi Gianluca,
Can you try to reproduce it with FC? Maybe it's somehow related to that.
Just to make it clear - I know that bug originally occurred on FC, and it
will be helpful to have the full logs if we want to understand the root
cause for this.
Did you try to lvremove the old lv's, or are they still in use?
Trying to do this from the SPM should be ok. What do you mean synchronize
the information at the other node side?
In any case, this is a disk that you don't need anymore, isn't it? You
said that the copy part of the move operation went well.
Thanks,
Idan
On Thu, Oct 19, 2017 at 10:47 AM, Gianluca Cecchi <
gianluca.cecchi(a)gmail.com> wrote:
> On Thu, Oct 19, 2017 at 7:36 AM, Idan Shaby <ishaby(a)redhat.com> wrote:
>
>> Hi Gianluca,
>>
>> This sounds like a bug to me.
>> Can you please attach engine and vdsm logs?
>>
>>
>> Thanks,
>> Idan
>>
>
> Hi Idan,
> I have not at hand the full files right now, but these were the snippets
> I cut from vdsm log and engine.log yesterday around the time of the first
> error after sending the first e-mail
> It seems vdsm reports that the logical volume is still in use while
> trying to remove it....
> I have tried to replicate on another environment also based on block
> storage, but now iSCSI and not FC and I was not able to get the error: the
> move disk operation of the powered off vm always completed successfully.
> Both tests were done trying to move preallocated disks if that matters
>
> vdsm.log of host1
>
> 2017-10-18 14:59:28,907+0200 ERROR (libvirt/events)
> [storage.TaskManager.Task] (Task='6331ec00-b75b-465e-8d9c-04d465c09ea1')
> Unexpected error (task:872)
> Traceback (most recent call last):
> File "/usr/share/vdsm/storage/task.py", line 879, in _run
> return fn(*args, **kargs)
> File "<string>", line 2, in teardownImage
> File "/usr/lib/python2.7/site-packages/vdsm/common/api.py", line 48,
> in method
> ret = func(*args, **kwargs)
> File "/usr/share/vdsm/storage/hsm.py", line 3189, in teardownImage
> dom.deactivateImage(imgUUID)
> File "/usr/share/vdsm/storage/blockSD.py", line 1289, in
> deactivateImage
> lvm.deactivateLVs(self.sdUUID, volUUIDs)
> File "/usr/share/vdsm/storage/lvm.py", line 1304, in deactivateLVs
> _setLVAvailability(vgName, toDeactivate, "n")
> File "/usr/share/vdsm/storage/lvm.py", line 843, in _setLVAvailability
> raise error(str(e))
> CannotDeactivateLogicalVolume: Cannot deactivate Logical Volume:
> ('General Storage Exception: ("5 [] [\' Logical volume
> c5d360f5-cd90-4b3e-bdef-924649bfbc5f/eff58f10-12bf-412f-a5db-944bfb10904d
> is used by another device.\']\\nc5d360f5-cd90-4b3
>
e-bdef-924649bfbc5f/[\'eff58f10-12bf-412f-a5db-944bfb10904d\']",)',)
> 2017-10-18 14:59:28,907+0200 INFO (libvirt/events)
> [storage.TaskManager.Task] (Task='6331ec00-b75b-465e-8d9c-04d465c09ea1')
> aborting: Task is aborted: 'Cannot deactivate Logical Volume: (\'General
> Storage Exception: ("5 [] [\\\' Logical volume
> c5d360f5-cd90-4b3e-bdef-924649bfbc5f/eff58f10-12bf-412f-a5db-944bfb10904d
> is used by another device.\\\']\\\\nc5d360f5-cd90
>
-4b3e-bdef-924649bfbc5f/[\\\'eff58f10-12bf-412f-a5db-944bfb10904d\\\']",)\',)'
> - code 552 (task:1177)
> 2017-10-18 14:59:28,908+0200 ERROR (libvirt/events) [storage.Dispatcher]
> FINISH teardownImage error=Cannot deactivate Logical Volume: ('General
> Storage Exception: ("5 [] [\' Logical volume
c5d360f5-cd90-4b3e-bdef-924649
> bfbc5f/eff58f10-12bf-412f-a5db-944bfb10904d is used by another
> device.\']\\nc5d360f5-cd90-4b3e-bdef-924649bfbc5f/[\'eff58f1
> 0-12bf-412f-a5db-944bfb10904d\']",)',) (dispatcher:81)
>
> engine.log
> 2017-10-18 15:01:53,097+02 INFO [org.ovirt.engine.core.dal.dbb
> roker.auditloghandling.AuditLogDirector] (D
> efaultQuartzScheduler6) [] EVENT_ID: USER_MOVED_DISK_FINISHED_SUCCESS(2,010),
> Correlation ID: a8948cbf-80a
> 2-462d-8805-91da94868c6e, Job ID: ffba7504-a324-43ca-ab4c-481610c1098b,
> Call Stack: null, Custom ID: null,
> Custom Event ID: -1, Message: User gcecchi@internal-authz finished
> moving disk padora1_u01 to domain SATA
> _ALLBCK.
> 2017-10-18 15:01:54,029+02 ERROR [org.ovirt.engine.core.dal.dbb
> roker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler5)
> [394f8568] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), Correlation ID:
> null, Call Stack: null, Custom ID: null, Custom Event ID: -1, Message: VDSM
> host1 command HSMGetAllTasksStatusesVDS failed: Cannot remove Logical
> Volume: (['Cannot remove Logical Volume:
(u\'c5d360f5-cd90-4b3e-bdef-924649bfbc5f\',
> "[\'2255c544-165b-4126-86ee-70e6d1edef9a\']")'],)
> 2017-10-18 15:01:54,029+02 INFO [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
> (DefaultQuartzScheduler5) [394f8568] SPMAsyncTask::PollTask: Polling task
> '8446a883-9bb0-40a5-b1eb-8a919defe4c0' (Parent Command
'RemoveImage',
> Parameters Type 'org.ovirt.engine.core.common.
> asynctasks.AsyncTaskParameters') returned status 'finished', result
> 'cleanSuccess'.
> 2017-10-18 15:01:54,029+02 ERROR [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
> (DefaultQuartzScheduler5) [394f8568] BaseAsyncTask::logEndTaskFailure:
> Task '8446a883-9bb0-40a5-b1eb-8a919defe4c0' (Parent Command
> 'RemoveImage', Parameters Type 'org.ovirt.engine.core.common.
> asynctasks.AsyncTaskParameters') ended with failure:
> -- Result: 'cleanSuccess'
> -- Message: 'VDSGenericException: VDSErrorException: Failed in vdscommand
> to HSMGetAllTasksStatusesVDS, error = Cannot remove Logical Volume:
> (['Cannot remove Logical Volume:
(u\'c5d360f5-cd90-4b3e-bdef-924649bfbc5f\',
> "[\'2255c544-165b-4126-86ee-70e6d1edef9a\']")'],)',
> -- Exception: 'VDSGenericException: VDSErrorException: Failed in
> vdscommand to HSMGetAllTasksStatusesVDS, error = Cannot remove Logical
> Volume: (['Cannot remove Logical Volume:
(u\'c5d360f5-cd90-4b3e-bdef-924649bfbc5f\',
> "[\'2255c544-165b-4126-86ee-70e6d1edef9a\']")'],)'
>
> Is there any command I can run to consistently remove the stale LVs?
> As oVirt doesn't use clvmd I don't think it is sufficient to issue the
> remove lv from the SPM node.. How will "synchronize" the information at
the
> other node side?
>
> Thanks,
> Gianluca
>
>
10:35 a.m.
New subject: move disk and lv not removed
On Tue, Oct 24, 2017 at 7:29 AM, Idan Shaby <ishaby(a)redhat.com> wrote:
Hi Gianluca,
Can you try to reproduce it with FC? Maybe it's somehow related to that.
Did you try to lvremove the old lv's, or are they still in use?
Do you mean directly from OS using lvremove command?
Trying to do this from the SPM should be ok.
OK. I can try it on SPM node if you confirm
What do you mean synchronize the information at the other node side?
I mean that in the past I worked with RHCS clusters, in both kinds of LVM
configurations: 1) CLVMD and 2) HA-LVM
In 1) I have the LVM layer that is cluster aware so if I run commands that
modify metadata information for LVM (such as adding, removing, extending
LV) I'm confident.
In 2), as LVM itself is not cluster aware, it is dangerous to do LVM
metadata operations with both nodes accessing the shared volumes.
So in this case I typically executed these steps:
- relocate the services so that they are all on one node
- power down the other one
- execute the required LVM changes
- power on the second node to have it join the cluster again
- eventually relocate back part of the cluster services to the second node
If I run "lvs" command on both oVirt nodes, they now both show the
information regarding the not-removed LV.
How does oVirt manage synchronization and coherence of LVM metadata between
nodes?
This is what I meant with my question...
In any case, this is a disk that you don't need anymore,
isn't it? You
said that the copy part of the move operation went well.
Regards,
Idan
Yes. the move operation succeeded and I'm usingthe target LV, that indeed
is marked with "open" (o) while the source not (-)
Gianluca
7:28 a.m.
New subject: move disk and lv not removed
On Tue, Oct 24, 2017 at 10:35 AM, Gianluca Cecchi <gianluca.cecchi(a)gmail.com
wrote:
> On Tue, Oct 24, 2017 at 7:29 AM, Idan Shaby <ishaby(a)redhat.com wrote:
>
>> Hi Gianluca,
>>
>> Can you try to reproduce it with FC? Maybe it's somehow related to that.
>> Did you try to lvremove the old lv's, or are they still in use?
>>
>
> Do you mean directly from OS using lvremove command?
>
Yes
> Trying to do this from the SPM should be ok.
>
OK. I can try it on SPM node if you confirm
Sure, go ahead.
> What do you mean synchronize the information at the other node side?
>
I mean that in the past I worked with RHCS clusters, in both kinds of LVM
configurations: 1) CLVMD and 2) HA-LVM
In 1) I have the LVM layer that is cluster aware so if I run commands that
modify metadata information for LVM (such as adding, removing, extending
LV) I'm confident.
In 2), as LVM itself is not cluster aware, it is dangerous to do LVM
metadata operations with both nodes accessing the shared volumes.
So in this case I typically executed these steps:
- relocate the services so that they are all on one node
- power down the other one
- execute the required LVM changes
- power on the second node to have it join the cluster again
- eventually relocate back part of the cluster services to the second node
If I run "lvs" command on both oVirt nodes, they now both
show the
information regarding the not-removed LV.
How does oVirt manage synchronization and coherence of LVM metadata
between nodes?
oVirt (vdsm, to be precise) uses SANLock [1] to achieve that goal.
This is what I meant with my question...
Thanks for the explanation!
Generally you're right. We do have to make sure that metadata operations on
a logical volume are done by only one host, because we're indeed not using
clvm.
However, here we're talking about a stale lv that no one should access
anymore, and that we don't have interest in anymore.
In that case, we can just go and lvremove it.
Regarding the bug itself, if you are able to reproduce it in any way,
please send the full logs so we can understand its cause.
> In any case, this is a disk that you don't need anymore, isn't it? You
> said that the copy part of the move operation went well.
>
>
> Regards,
> Idan
>
>
Yes. the move operation succeeded and I'm usingthe target LV, that indeed
is marked with "open" (o) while the source not (-)
Gianluca
[1] https://www.ovirt.org/develop/developer-guide/vdsm/sanlock/
2585
days inactive
2586
days old
3 comments
2 participants
participants (2)
-
Gianluca Cecchi -
Idan Shaby