You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "prashant kumar mishra (JIRA)" <ji...@apache.org> on 2014/02/10 12:36:20 UTC
[jira] [Closed] (CLOUDSTACK-5749) volume live migration is failing
;org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed
to migrate volume"}
[ https://issues.apache.org/jira/browse/CLOUDSTACK-5749?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
prashant kumar mishra closed CLOUDSTACK-5749.
---------------------------------------------
checked on xen setup did not see this issue
> volume live migration is failing ;org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed to migrate volume"}
> ------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-5749
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5749
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: Volumes
> Affects Versions: 4.3.0
> Environment: hyp:xen6.2
> Reporter: prashant kumar mishra
> Assignee: Kelven Yang
> Priority: Critical
> Fix For: 4.3.0
>
> Attachments: Log_DB_ssvm.rar
>
>
> I saw this error in upgraded setup not sure if it exist in fresh CS-4.3 setup also.
> Steps to reproduce
> ===============
> 1-preapre a ACS 4.2 setup with xen6.2
> 2-upgrade it to CS4.3
> 3-deploy a vm using default template
> 4-add a primary storage
> 5-crate a volume
> 6-add volume to instance created in step 3
> 7-try to migrate volume to newly added primary storage
> Expected
> ===========
> volume migration should be successful
> Actual
> =====
> volume migration is failing
> Log:
> ===
> 2014-01-03 07:17:00,618 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-18:ctx-1353ad92 ctx-c2dcabd7) submit async job-78, details: AsyncJobVO {id:78, userId: 2, accountId: 2, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.user.volume.MigrateVolumeCmd, cmdInfo: {"response":"json","sessionkey":"iB7oDA5zlPV6nT97WFR8vxIjZi8\u003d","cmdEventType":"VOLUME.MIGRATE","ctxUserId":"2","storageid":"61944541-60c3-3d79-999b-db96ab0e7dc6","livemigrate":"true","httpmethod":"GET","_":"1388732216160","volumeid":"8117d17f-3b83-4685-99fd-a64205b32732","ctxAccountId":"2","ctxStartEventId":"175"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 7145449848920, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2014-01-03 07:17:00,621 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-1353ad92 ctx-c2dcabd7) ===END=== 10.252.192.25 -- GET command=migrateVolume&livemigrate=true&storageid=61944541-60c3-3d79-999b-db96ab0e7dc6&volumeid=8117d17f-3b83-4685-99fd-a64205b32732&response=json&sessionkey=iB7oDA5zlPV6nT97WFR8vxIjZi8%3D&_=1388732216160
> 2014-01-03 07:17:00,623 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-56:ctx-ac65175b) Add job-78 into job monitoring
> 2014-01-03 07:17:00,624 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-56:ctx-ac65175b) Executing AsyncJobVO {id:78, userId: 2, accountId: 2, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.user.volume.MigrateVolumeCmd, cmdInfo: {"response":"json","sessionkey":"iB7oDA5zlPV6nT97WFR8vxIjZi8\u003d","cmdEventType":"VOLUME.MIGRATE","ctxUserId":"2","storageid":"61944541-60c3-3d79-999b-db96ab0e7dc6","livemigrate":"true","httpmethod":"GET","_":"1388732216160","volumeid":"8117d17f-3b83-4685-99fd-a64205b32732","ctxAccountId":"2","ctxStartEventId":"175"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 7145449848920, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2014-01-03 07:17:00,661 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-56:ctx-ac65175b ctx-c2dcabd7) Sync job-79 execution on object VmWorkJobQueue.3
> 2014-01-03 07:17:01,860 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-8f61216d) Execute sync-queue item: SyncQueueItemVO {id:23, queueId: 17, contentType: AsyncJob, contentId: 79, lastProcessMsid: null, lastprocessNumber: null, lastProcessTime: null, created: Fri Jan 03 07:17:00 EST 2014}
> 2014-01-03 07:17:01,863 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-8f61216d) Schedule queued job-79
> 2014-01-03 07:17:01,879 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-57:ctx-da52aa8b) Add job-79 into job monitoring
> 2014-01-03 07:17:01,880 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-57:ctx-da52aa8b) Executing AsyncJobVO {id:79, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.storage.VmWorkMigrateVolume, cmdInfo: rO0ABXNyACVjb20uY2xvdWQuc3RvcmFnZS5WbVdvcmtNaWdyYXRlVm9sdW1l-CXzb7zvU-YCAANKAApkZXN0UG9vbElkWgALbGl2ZU1pZ3JhdGVKAAh2b2x1bWVJZHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAA3QAFFZvbHVtZUFwaVNlcnZpY2VJbXBsAAAAAAAAAAMBAAAAAAAAAA0, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 7145449848920, completeMsid: null, lastUpdated: null, lastPolled: null, created: Fri Jan 03 07:17:00 EST 2014}
> 2014-01-03 07:17:01,880 DEBUG [c.c.v.VmWorkJobDispatcher] (Job-Executor-57:ctx-da52aa8b) Run VM work job: com.cloud.storage.VmWorkMigrateVolume
> 2014-01-03 07:17:01,883 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Job-Executor-57:ctx-da52aa8b ctx-c2dcabd7) Execute VM work job: com.cloud.storage.VmWorkMigrateVolume{"volumeId":13,"destPoolId":3,"liveMigrate":true,"userId":2,"accountId":2,"vmId":3,"handlerName":"VolumeApiServiceImpl"}
> 2014-01-03 07:17:01,926 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (Job-Executor-57:ctx-da52aa8b ctx-c2dcabd7) copyAsync inspecting src type VOLUME copyAsync inspecting dest type VOLUME
> 2014-01-03 07:17:01,942 DEBUG [c.c.a.t.Request] (Job-Executor-57:ctx-da52aa8b ctx-c2dcabd7) Seq 1-1202260987: Sending { Cmd , MgmtId: 7145449848920, via: 1(Rack1Pod1Host7), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.storage.MigrateVolumeCommand":{"volumeId":13,"volumePath":"862cb6b1-6ebf-4bc6-890d-16b4fb0c2e16","pool":{"id":3,"uuid":"61944541-60c3-3d79-999b-db96ab0e7dc6","host":"10.147.28.7","path":"/export/home/prashant/pm5","port":2049,"type":"NetworkFilesystem"},"attachedVmName":"i-2-3-VM","wait":0}}] }
> 2014-01-03 07:17:01,942 DEBUG [c.c.a.t.Request] (Job-Executor-57:ctx-da52aa8b ctx-c2dcabd7) Seq 1-1202260987: Executing: { Cmd , MgmtId: 7145449848920, via: 1(Rack1Pod1Host7), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.storage.MigrateVolumeCommand":{"volumeId":13,"volumePath":"862cb6b1-6ebf-4bc6-890d-16b4fb0c2e16","pool":{"id":3,"uuid":"61944541-60c3-3d79-999b-db96ab0e7dc6","host":"10.147.28.7","path":"/export/home/prashant/pm5","port":2049,"type":"NetworkFilesystem"},"attachedVmName":"i-2-3-VM","wait":0}}] }
> 2014-01-03 07:17:01,943 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-5:ctx-a33a0520) Seq 1-1202260987: Executing request
> 2014-01-03 07:17:02,023 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-5:ctx-a33a0520) SR retrieved for 61944541-60c3-3d79-999b-db96ab0e7dc6
> 2014-01-03 07:17:02,029 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-5:ctx-a33a0520) Checking 61944541-60c3-3d79-999b-db96ab0e7dc6 or SR 1e690f5f-907f-d577-4d26-1f5f7d5a1d34 on XS[f05b3338-a1f5-44a4-ba38-46c8076ac9da-10.147.40.7]
> 2014-01-03 07:17:02,522 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-13:null) SeqA 5-10237: Processing Seq 5-10237: { Cmd , MgmtId: -1, via: 5, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":6,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
> 2014-01-03 07:17:02,533 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-13:null) SeqA 5-10237: Sending Seq 5-10237: { Ans: , MgmtId: 7145449848920, via: 5, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2014-01-03 07:17:03,713 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-1a1cce2a) ===START=== 10.252.192.25 -- GET command=queryAsyncJobResult&jobId=d7d713dc-abf2-4179-ada3-be3360e574dd&response=json&sessionkey=iB7oDA5zlPV6nT97WFR8vxIjZi8%3D&_=1388732219342
> 2014-01-03 07:17:03,750 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-1a1cce2a ctx-227e65f6) ===END=== 10.252.192.25 -- GET command=queryAsyncJobResult&jobId=d7d713dc-abf2-4179-ada3-be3360e574dd&response=json&sessionkey=iB7oDA5zlPV6nT97WFR8vxIjZi8%3D&_=1388732219342
> 2014-01-03 07:17:06,713 DEBUG [c.c.a.ApiServlet] (catalina-exec-15:ctx-15d4c521) ===START=== 10.252.192.25 -- GET command=queryAsyncJobResult&jobId=d7d713dc-abf2-4179-ada3-be3360e574dd&response=json&sessionkey=iB7oDA5zlPV6nT97WFR8vxIjZi8%3D&_=1388732222341
> 2014-01-03 07:17:06,745 DEBUG [c.c.a.ApiServlet] (catalina-exec-15:ctx-15d4c521 ctx-0d12e5e7) ===END=== 10.252.192.25 -- GET command=queryAsyncJobResult&jobId=d7d713dc-abf2-4179-ada3-be3360e574dd&response=json&sessionkey=iB7oDA5zlPV6nT97WFR8vxIjZi8%3D&_=1388732222341
> 2014-01-03 07:17:07,084 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-3680a2d9) HostStatsCollector is running...
> 2014-01-03 07:17:07,100 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-372:ctx-cd43b296) Seq 1-1202260988: Executing request
> 2014-01-03 07:17:07,331 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-372:ctx-cd43b296) Seq 1-1202260988: Response Received:
> 2014-01-03 07:17:07,331 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-3680a2d9) Seq 1-1202260988: Received: { Ans: , MgmtId: 7145449848920, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-01-03 07:17:07,345 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-246:ctx-19a3a3b0) Seq 4-107285370: Executing request
> 2014-01-03 07:17:07,522 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-15:null) SeqA 5-10238: Processing Seq 5-10238: { Cmd , MgmtId: -1, via: 5, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":6,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
> 2014-01-03 07:17:07,534 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-15:null) SeqA 5-10238: Sending Seq 5-10238: { Ans: , MgmtId: 7145449848920, via: 5, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2014-01-03 07:17:07,594 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-246:ctx-19a3a3b0) Seq 4-107285370: Response Received:
> 2014-01-03 07:17:07,594 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-3680a2d9) Seq 4-107285370: Received: { Ans: , MgmtId: 7145449848920, via: 4, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-01-03 07:17:09,711 DEBUG [c.c.a.ApiServlet] (catalina-exec-9:ctx-d76d1337) ===START=== 10.252.192.25 -- GET command=queryAsyncJobResult&jobId=d7d713dc-abf2-4179-ada3-be3360e574dd&response=json&sessionkey=iB7oDA5zlPV6nT97WFR8vxIjZi8%3D&_=1388732225340
> 2014-01-03 07:17:09,746 DEBUG [c.c.a.ApiServlet] (catalina-exec-9:ctx-d76d1337 ctx-8c30aba1) ===END=== 10.252.192.25 -- GET command=queryAsyncJobResult&jobId=d7d713dc-abf2-4179-ada3-be3360e574dd&response=json&sessionkey=iB7oDA5zlPV6nT97WFR8vxIjZi8%3D&_=1388732225340
> 2014-01-03 07:17:12,797 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-0789980d) ===START=== 10.252.192.25 -- GET command=queryAsyncJobResult&jobId=d7d713dc-abf2-4179-ada3-be3360e574dd&response=json&sessionkey=iB7oDA5zlPV6nT97WFR8vxIjZi8%3D&_=1388732228341
> 2014-01-03 07:17:12,834 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-0789980d ctx-84f418d8) ===END=== 10.252.192.25 -- GET command=queryAsyncJobResult&jobId=d7d713dc-abf2-4179-ada3-be3360e574dd&response=json&sessionkey=iB7oDA5zlPV6nT97WFR8vxIjZi8%3D&_=1388732228341
> 2014-01-03 07:17:13,101 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-5:ctx-a33a0520) Seq 1-1202260987: Response Received:
> 2014-01-03 07:17:13,101 DEBUG [c.c.a.t.Request] (DirectAgent-5:ctx-a33a0520) Seq 1-1202260987: Processing: { Ans: , MgmtId: 7145449848920, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.storage.MigrateVolumeAnswer":{"volumePath":"ad96447d-d8c5-42d8-9da6-fe46b64b6599","result":true,"wait":0}}] }
> 2014-01-03 07:17:13,102 DEBUG [c.c.a.t.Request] (Job-Executor-57:ctx-da52aa8b ctx-c2dcabd7) Seq 1-1202260987: Received: { Ans: , MgmtId: 7145449848920, via: 1, Ver: v1, Flags: 110, { MigrateVolumeAnswer } }
> 2014-01-03 07:17:13,106 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-5:ctx-a33a0520) Seq 1-1202260987: No more commands found
> 2014-01-03 07:17:13,130 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Job-Executor-57:ctx-da52aa8b ctx-c2dcabd7) Done executing VM work job: com.cloud.storage.VmWorkMigrateVolume{"volumeId":13,"destPoolId":3,"liveMigrate":true,"userId":2,"accountId":2,"vmId":3,"handlerName":"VolumeApiServiceImpl"}
> 2014-01-03 07:17:13,130 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-57:ctx-da52aa8b ctx-c2dcabd7) Complete async job-79, jobStatus: SUCCEEDED, resultCode: 0, result: rO0ABXNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgABSgAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAAAAAAAAADQ
> 2014-01-03 07:17:13,149 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-57:ctx-da52aa8b) Done executing com.cloud.storage.VmWorkMigrateVolume for job-79
> 2014-01-03 07:17:13,157 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-58:ctx-911cda61) Add job-78 into job monitoring
> 2014-01-03 07:17:13,160 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-58:ctx-911cda61) Executing AsyncJobVO {id:78, userId: 2, accountId: 2, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.user.volume.MigrateVolumeCmd, cmdInfo: {"response":"json","sessionkey":"iB7oDA5zlPV6nT97WFR8vxIjZi8\u003d","cmdEventType":"VOLUME.MIGRATE","ctxUserId":"2","storageid":"61944541-60c3-3d79-999b-db96ab0e7dc6","livemigrate":"true","httpmethod":"GET","_":"1388732216160","volumeid":"8117d17f-3b83-4685-99fd-a64205b32732","ctxAccountId":"2","ctxStartEventId":"175"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 7145449848920, completeMsid: null, lastUpdated: null, lastPolled: Fri Jan 03 07:17:12 EST 2014, created: Fri Jan 03 07:17:00 EST 2014}
> 2014-01-03 07:17:13,200 WARN [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-58:ctx-911cda61) job-78 is scheduled for wakeup run, but there is no joining info anymore
> 2014-01-03 07:17:13,203 ERROR [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-58:ctx-911cda61) Unable to find a wakeup dispatcher from the joined job: AsyncJobVO {id:78, userId: 2, accountId: 2, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.user.volume.MigrateVolumeCmd, cmdInfo: {"response":"json","sessionkey":"iB7oDA5zlPV6nT97WFR8vxIjZi8\u003d","cmdEventType":"VOLUME.MIGRATE","ctxUserId":"2","storageid":"61944541-60c3-3d79-999b-db96ab0e7dc6","livemigrate":"true","httpmethod":"GET","_":"1388732216160","volumeid":"8117d17f-3b83-4685-99fd-a64205b32732","ctxAccountId":"2","ctxStartEventId":"175"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 7145449848920, completeMsid: null, lastUpdated: null, lastPolled: Fri Jan 03 07:17:12 EST 2014, created: Fri Jan 03 07:17:00 EST 2014}
> 2014-01-03 07:17:13,204 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-58:ctx-911cda61) Done executing org.apache.cloudstack.api.command.user.volume.MigrateVolumeCmd for job-78
> 2014-01-03 07:17:13,201 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-56:ctx-ac65175b) Complete async job-78, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed to migrate volume"}
--
This message was sent by Atlassian JIRA
(v6.1.5#6160)