Return-Path: X-Original-To: apmail-cloudstack-issues-archive@www.apache.org Delivered-To: apmail-cloudstack-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id D286010761 for ; Tue, 7 Jan 2014 23:29:54 +0000 (UTC) Received: (qmail 3533 invoked by uid 500); 7 Jan 2014 23:29:54 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 3489 invoked by uid 500); 7 Jan 2014 23:29:54 -0000 Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cloudstack.apache.org Delivered-To: mailing list issues@cloudstack.apache.org Received: (qmail 3452 invoked by uid 500); 7 Jan 2014 23:29:54 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 3435 invoked by uid 99); 7 Jan 2014 23:29:54 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 07 Jan 2014 23:29:54 +0000 Date: Tue, 7 Jan 2014 23:29:54 +0000 (UTC) From: "Min Chen (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (CLOUDSTACK-5749) volume live migration is failing ;org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed to migrate volume"} MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-5749?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13864859#comment-13864859 ] Min Chen commented on CLOUDSTACK-5749: -------------------------------------- This seems regression from vmsync, so assign to Kelven to take a look. > 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: Min Chen > 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)