Bug 1431517 - [HCI] Error shown in RHV-UI when migrating vm disks from one gluster storage domain to another
Summary: [HCI] Error shown in RHV-UI when migrating vm disks from one gluster storage ...
Keywords:
Status: CLOSED DUPLICATE of bug 1342550
Alias: None
Product: vdsm
Classification: oVirt
Component: Gluster
Version: ---
Hardware: x86_64
OS: Linux
medium
low
Target Milestone: ovirt-4.2.0
: ---
Assignee: Denis Chaplygin
QA Contact: SATHEESARAN
URL:
Whiteboard:
Depends On:
Blocks: Gluster-HC-3
TreeView+ depends on / blocked
 
Reported: 2017-03-13 04:26 UTC by Paul Cuzner
Modified: 2017-09-19 12:47 UTC (History)
7 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-09-19 12:47:07 UTC
oVirt Team: Gluster
Embargoed:
rule-engine: ovirt-4.2+

Attachments (Terms of Use)

Description Paul Cuzner 2017-03-13 04:26:20 UTC 
Description of problem:

In a HCI cluster (3 nodes), when migrating from a SAS 10k based storage domain to a SSD based storage domain, the copy completed but an error level message was shown in the RHV-UI from vdsm-gluster

"could not remove all image's volume"


Version-Release number of selected component (if applicable):
glusterfs 3.8.4-6
vdsm-gluster 4.18.12-1


How reproducible:
Intermittent issue - I was relocating 24 vdisks, and this occurred 3 times

Steps to Reproduce:
1. Power of the VM
2. migrate all the vdisks belonging to the vm in one 'task'
3. monitor the event log

Actual results:
The error message is intermittent 


Expected results:
I would expect storage migration to work 100%



Additional info:
This issue has also been observed during QE testing - contact Sas sasundar
Comment 2 SATHEESARAN 2017-03-13 09:58:35 UTC 
I see such an error even while removing the VM along with its disk image.

<snip>
2017-03-13 05:24:40,768-04 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-9) [20e9f567] EVENT_ID: USER_REMOVE_VM_FINISHED(113), Correlation ID: 1459a
c8d-f84a-45ed-ab9a-cdac6d3e6e59, Job ID: 7ce46a75-a6b9-45d1-90f3-f2f28a183cbe, Call Stack: null, Custom Event ID: -1, Message: VM set1_appvm11 was successfully removed.
2017-03-13 05:24:40,769-04 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-9) [20e9f567] BaseAsyncTask::startPollingTask: Starting to poll task 'd31d5cf3-ba9d-414b-ad6c-08eaf
5e6a045'.
2017-03-13 05:24:40,769-04 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (org.ovirt.thread.pool-6-thread-9) [20e9f567] BaseAsyncTask::startPollingTask: Starting to poll task 'b9131328-bf52-450f-aecb-ee655
32baab2'.
2017-03-13 05:24:43,465-04 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand] (DefaultQuartzScheduler1) [50f2768c] START, GlusterServersListVDSCommand(HostName = cambridge-nic2.lab.eng.
blr.redhat.com, VdsIdVDSCommandParametersBase:{runAsync='true', hostId='1b6faff2-70ac-4f59-88ee-82ff24e8e0b2'}), log id: 5651ca85
2017-03-13 05:24:44,746-04 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand] (DefaultQuartzScheduler1) [50f2768c] FINISH, GlusterServersListVDSCommand, return: [10.70.36.73/23:CONNECTE
D, 10.70.36.74:CONNECTED, 10.70.36.75:CONNECTED], log id: 5651ca85
2017-03-13 05:24:44,756-04 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler1) [50f2768c] START, GlusterVolumesListVDSCommand(HostName = cambridge-nic2.lab.eng.
blr.redhat.com, GlusterVolumesListVDSParameters:{runAsync='true', hostId='1b6faff2-70ac-4f59-88ee-82ff24e8e0b2'}), log id: 3c5623d2
2017-03-13 05:24:45,427-04 INFO  [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand] (DefaultQuartzScheduler1) [50f2768c] FINISH, GlusterVolumesListVDSCommand, return: {cd42c124-65ce-4544-b76e
-b551db9d859d=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@45d56991, 817f1a45-d6e6-4fc7-b117-c7abc239c378=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@2d
b8d179, d78ab625-8376-4c31-8af2-d7ae8550a6cf=org.ovirt.engine.core.common.businessentities.gluster.GlusterVolumeEntity@b590c341}, log id: 3c5623d2
2017-03-13 05:24:46,405-04 INFO  [org.ovirt.engine.core.bll.tasks.AsyncTaskManager] (DefaultQuartzScheduler10) [61988301] Polling and updating Async Tasks: 4 tasks, 4 tasks to poll now
2017-03-13 05:24:48,512-04 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (DefaultQuartzScheduler10) [61988301] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), Correlation ID: null, Call Stack: null, Custom Event ID: -1, Message: VDSM cambridge-nic2.lab.eng.blr.redhat.com command HSMGetAllTasksStatusesVDS failed: Could not remove all image's volumes
2017-03-13 05:24:48,512-04 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler10) [61988301] SPMAsyncTask::PollTask: Polling task 'b9131328-bf52-450f-aecb-ee65532baab2' (Parent Command 'RemoveVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2017-03-13 05:24:48,516-04 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler10) [61988301] BaseAsyncTask::onTaskEndSuccess: Task 'b9131328-bf52-450f-aecb-ee65532baab2' (Parent Command 'RemoveVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2017-03-13 05:24:48,517-04 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (DefaultQuartzScheduler10) [61988301] Task with DB Task ID '48affd03-bd96-4ec1-93c0-3bacd2024f74' and VDSM Task ID 'd31d5cf3-ba9d-414b-ad6c-08eaf5e6a045' is in state Polling. End action for command f16948e7-3ed9-4c00-ad41-58c9a7ce0615 will proceed when all the entity's tasks are completed.
2017-03-13 05:24:48,521-04 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler10) [61988301] BaseAsyncTask::onTaskEndSuccess: Task '1a32ddab-2cc8-489c-b95d-905d69b076ca' (Parent Command 'RemoveVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2017-03-13 05:24:48,521-04 INFO  [org.ovirt.engine.core.bll.CommandMultiAsyncTasks] (DefaultQuartzScheduler10) [61988301] Task with DB Task ID 'e3c1e4d1-9df2-450d-a2e5-cbbdcf13f341' and VDSM Task ID '8408ead2-af77-4ac5-a2fa-91bf62fca34b' is in state Polling. End action for command 82e8656b-aff8-46e9-982a-8dd6be4085b2 will proceed when all the entity's tasks are completed.
2017-03-13 05:24:48,521-04 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler10) [61988301] SPMAsyncTask::PollTask: Polling task '8408ead2-af77-4ac5-a2fa-91bf62fca34b' (Parent Command 'RemoveVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'success'.
2017-03-13 05:24:48,525-04 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler10) [61988301] BaseAsyncTask::onTaskEndSuccess: Task '8408ead2-af77-4ac5-a2fa-91bf62fca34b' (Parent Command 'RemoveVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended successfully.
2017-03-13 05:24:48,567-04 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler10) [61988301] CommandAsyncTask::endActionIfNecessary: All tasks of command '82e8656b-aff8-46e9-982a-8dd6be4085b2' has ended -> executing 'endAction'
2017-03-13 05:24:48,568-04 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (DefaultQuartzScheduler10) [61988301] CommandAsyncTask::endAction: Ending action for '2' tasks (command ID: '82e8656b-aff8-46e9-982a-8dd6be4085b2'): calling endAction '.
2017-03-13 05:24:48,568-04 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler10) [61988301] SPMAsyncTask::PollTask: Polling task 'd31d5cf3-ba9d-414b-ad6c-08eaf5e6a045' (Parent Command 'RemoveVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'cleanSuccess'.
2017-03-13 05:24:48,569-04 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-17) [61988301] CommandAsyncTask::endCommandAction [within thread] context: Attempting to endAction 'RemoveVm',
2017-03-13 05:24:48,593-04 ERROR [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler10) [61988301] BaseAsyncTask::logEndTaskFailure: Task 'd31d5cf3-ba9d-414b-ad6c-08eaf5e6a045' (Parent Command 'RemoveVm', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended with failure:
-- Result: 'cleanSuccess'
-- Message: 'VDSGenericException: VDSErrorException: Failed in vdscommand to HSMGetAllTasksStatusesVDS, error = Could not remove all image's volumes',
-- Exception: 'VDSGenericException: VDSErrorException: Failed in vdscommand to HSMGetAllTasksStatusesVDS, error = Could not remove all image's volumes'
2017-03-13 05:24:48,609-04 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand] (org.ovirt.thread.pool-6-thread-17) [61988301] Ending command 'org.ovirt.engine.core.bll.RemoveVmCommand' successfully.
2017-03-13 05:24:48,621-04 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-17) [61988301] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'RemoveVm' completed, handling the result.
2017-03-13 05:24:48,621-04 INFO  [org.ovirt.engine.core.bll.tasks.CommandAsyncTask] (org.ovirt.thread.pool-6-thread-17) [61988301] CommandAsyncTask::HandleEndActionResult [within thread]: endAction for action type 'RemoveVm' succeeded, clearing tasks.

</snip>
Comment 3 RamaKasturi 2017-03-13 10:02:13 UTC 
(In reply to SATHEESARAN from comment #2)
> I see such an error even while removing the VM along with its disk image.
> 
> <snip>
> 2017-03-13 05:24:40,768-04 INFO 
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (org.ovirt.thread.pool-6-thread-9) [20e9f567] EVENT_ID:
> USER_REMOVE_VM_FINISHED(113), Correlation ID: 1459a
> c8d-f84a-45ed-ab9a-cdac6d3e6e59, Job ID:
> 7ce46a75-a6b9-45d1-90f3-f2f28a183cbe, Call Stack: null, Custom Event ID: -1,
> Message: VM set1_appvm11 was successfully removed.
> 2017-03-13 05:24:40,769-04 INFO 
> [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
> (org.ovirt.thread.pool-6-thread-9) [20e9f567]
> BaseAsyncTask::startPollingTask: Starting to poll task
> 'd31d5cf3-ba9d-414b-ad6c-08eaf
> 5e6a045'.
> 2017-03-13 05:24:40,769-04 INFO 
> [org.ovirt.engine.core.bll.tasks.SPMAsyncTask]
> (org.ovirt.thread.pool-6-thread-9) [20e9f567]
> BaseAsyncTask::startPollingTask: Starting to poll task
> 'b9131328-bf52-450f-aecb-ee655
> 32baab2'.
> 2017-03-13 05:24:43,465-04 INFO 
> [org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
> (DefaultQuartzScheduler1) [50f2768c] START,
> GlusterServersListVDSCommand(HostName = cambridge-nic2.lab.eng.
> blr.redhat.com, VdsIdVDSCommandParametersBase:{runAsync='true',
> hostId='1b6faff2-70ac-4f59-88ee-82ff24e8e0b2'}), log id: 5651ca85
> 2017-03-13 05:24:44,746-04 INFO 
> [org.ovirt.engine.core.vdsbroker.gluster.GlusterServersListVDSCommand]
> (DefaultQuartzScheduler1) [50f2768c] FINISH, GlusterServersListVDSCommand,
> return: [10.70.36.73/23:CONNECTE
> D, 10.70.36.74:CONNECTED, 10.70.36.75:CONNECTED], log id: 5651ca85
> 2017-03-13 05:24:44,756-04 INFO 
> [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand]
> (DefaultQuartzScheduler1) [50f2768c] START,
> GlusterVolumesListVDSCommand(HostName = cambridge-nic2.lab.eng.
> blr.redhat.com, GlusterVolumesListVDSParameters:{runAsync='true',
> hostId='1b6faff2-70ac-4f59-88ee-82ff24e8e0b2'}), log id: 3c5623d2
> 2017-03-13 05:24:45,427-04 INFO 
> [org.ovirt.engine.core.vdsbroker.gluster.GlusterVolumesListVDSCommand]
> (DefaultQuartzScheduler1) [50f2768c] FINISH, GlusterVolumesListVDSCommand,
> return: {cd42c124-65ce-4544-b76e
> -b551db9d859d=org.ovirt.engine.core.common.businessentities.gluster.
> GlusterVolumeEntity@45d56991,
> 817f1a45-d6e6-4fc7-b117-c7abc239c378=org.ovirt.engine.core.common.
> businessentities.gluster.GlusterVolumeEntity@2d
> b8d179,
> d78ab625-8376-4c31-8af2-d7ae8550a6cf=org.ovirt.engine.core.common.
> businessentities.gluster.GlusterVolumeEntity@b590c341}, log id: 3c5623d2
> 2017-03-13 05:24:46,405-04 INFO 
> [org.ovirt.engine.core.bll.tasks.AsyncTaskManager]
> (DefaultQuartzScheduler10) [61988301] Polling and updating Async Tasks: 4
> tasks, 4 tasks to poll now
> 2017-03-13 05:24:48,512-04 ERROR
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (DefaultQuartzScheduler10) [61988301] EVENT_ID:
> VDS_BROKER_COMMAND_FAILURE(10,802), Correlation ID: null, Call Stack: null,
> Custom Event ID: -1, Message: VDSM cambridge-nic2.lab.eng.blr.redhat.com
> command HSMGetAllTasksStatusesVDS failed: Could not remove all image's
> volumes
> 2017-03-13 05:24:48,512-04 INFO 
> [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler10)
> [61988301] SPMAsyncTask::PollTask: Polling task
> 'b9131328-bf52-450f-aecb-ee65532baab2' (Parent Command 'RemoveVm',
> Parameters Type
> 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned
> status 'finished', result 'success'.
> 2017-03-13 05:24:48,516-04 INFO 
> [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler10)
> [61988301] BaseAsyncTask::onTaskEndSuccess: Task
> 'b9131328-bf52-450f-aecb-ee65532baab2' (Parent Command 'RemoveVm',
> Parameters Type
> 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended
> successfully.
> 2017-03-13 05:24:48,517-04 INFO 
> [org.ovirt.engine.core.bll.CommandMultiAsyncTasks]
> (DefaultQuartzScheduler10) [61988301] Task with DB Task ID
> '48affd03-bd96-4ec1-93c0-3bacd2024f74' and VDSM Task ID
> 'd31d5cf3-ba9d-414b-ad6c-08eaf5e6a045' is in state Polling. End action for
> command f16948e7-3ed9-4c00-ad41-58c9a7ce0615 will proceed when all the
> entity's tasks are completed.
> 2017-03-13 05:24:48,521-04 INFO 
> [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler10)
> [61988301] BaseAsyncTask::onTaskEndSuccess: Task
> '1a32ddab-2cc8-489c-b95d-905d69b076ca' (Parent Command 'RemoveVm',
> Parameters Type
> 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended
> successfully.
> 2017-03-13 05:24:48,521-04 INFO 
> [org.ovirt.engine.core.bll.CommandMultiAsyncTasks]
> (DefaultQuartzScheduler10) [61988301] Task with DB Task ID
> 'e3c1e4d1-9df2-450d-a2e5-cbbdcf13f341' and VDSM Task ID
> '8408ead2-af77-4ac5-a2fa-91bf62fca34b' is in state Polling. End action for
> command 82e8656b-aff8-46e9-982a-8dd6be4085b2 will proceed when all the
> entity's tasks are completed.
> 2017-03-13 05:24:48,521-04 INFO 
> [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler10)
> [61988301] SPMAsyncTask::PollTask: Polling task
> '8408ead2-af77-4ac5-a2fa-91bf62fca34b' (Parent Command 'RemoveVm',
> Parameters Type
> 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned
> status 'finished', result 'success'.
> 2017-03-13 05:24:48,525-04 INFO 
> [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler10)
> [61988301] BaseAsyncTask::onTaskEndSuccess: Task
> '8408ead2-af77-4ac5-a2fa-91bf62fca34b' (Parent Command 'RemoveVm',
> Parameters Type
> 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended
> successfully.
> 2017-03-13 05:24:48,567-04 INFO 
> [org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
> (DefaultQuartzScheduler10) [61988301]
> CommandAsyncTask::endActionIfNecessary: All tasks of command
> '82e8656b-aff8-46e9-982a-8dd6be4085b2' has ended -> executing 'endAction'
> 2017-03-13 05:24:48,568-04 INFO 
> [org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
> (DefaultQuartzScheduler10) [61988301] CommandAsyncTask::endAction: Ending
> action for '2' tasks (command ID: '82e8656b-aff8-46e9-982a-8dd6be4085b2'):
> calling endAction '.
> 2017-03-13 05:24:48,568-04 INFO 
> [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler10)
> [61988301] SPMAsyncTask::PollTask: Polling task
> 'd31d5cf3-ba9d-414b-ad6c-08eaf5e6a045' (Parent Command 'RemoveVm',
> Parameters Type
> 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned
> status 'finished', result 'cleanSuccess'.
> 2017-03-13 05:24:48,569-04 INFO 
> [org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
> (org.ovirt.thread.pool-6-thread-17) [61988301]
> CommandAsyncTask::endCommandAction [within thread] context: Attempting to
> endAction 'RemoveVm',
> 2017-03-13 05:24:48,593-04 ERROR
> [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (DefaultQuartzScheduler10)
> [61988301] BaseAsyncTask::logEndTaskFailure: Task
> 'd31d5cf3-ba9d-414b-ad6c-08eaf5e6a045' (Parent Command 'RemoveVm',
> Parameters Type
> 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended with
> failure:
> -- Result: 'cleanSuccess'
> -- Message: 'VDSGenericException: VDSErrorException: Failed in vdscommand to
> HSMGetAllTasksStatusesVDS, error = Could not remove all image's volumes',
> -- Exception: 'VDSGenericException: VDSErrorException: Failed in vdscommand
> to HSMGetAllTasksStatusesVDS, error = Could not remove all image's volumes'
> 2017-03-13 05:24:48,609-04 INFO  [org.ovirt.engine.core.bll.RemoveVmCommand]
> (org.ovirt.thread.pool-6-thread-17) [61988301] Ending command
> 'org.ovirt.engine.core.bll.RemoveVmCommand' successfully.
> 2017-03-13 05:24:48,621-04 INFO 
> [org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
> (org.ovirt.thread.pool-6-thread-17) [61988301]
> CommandAsyncTask::HandleEndActionResult [within thread]: endAction for
> action type 'RemoveVm' completed, handling the result.
> 2017-03-13 05:24:48,621-04 INFO 
> [org.ovirt.engine.core.bll.tasks.CommandAsyncTask]
> (org.ovirt.thread.pool-6-thread-17) [61988301]
> CommandAsyncTask::HandleEndActionResult [within thread]: endAction for
> action type 'RemoveVm' succeeded, clearing tasks.
> 
> </snip>

There is a bug [1] filed for this issue.

[1] https://bugzilla.redhat.com/show_bug.cgi?id=1342550
Comment 4 Denis Chaplygin 2017-09-19 12:47:07 UTC 

*** This bug has been marked as a duplicate of bug 1342550 ***
Note You need to log in before you can comment on or make changes to this bug.