ccycv commented on issue #6270:
URL: https://github.com/apache/cloudstack/issues/6270#issuecomment-1108111255
> @ccycv from what I can see in your log this is expected behaviour, but I
assume you tested this successfully in 4.15? Maybe you can add the logs
relevant to the job starting with the line containing "===START===" that
pertains to your migration request, up to the matching "===END===" that gave
your error result.
> @ccycv from what I can see in your log this is expected behaviour, but I
assume you tested this successfully in 4.15? Maybe you can add the logs
relevant to the job starting with the line containing "===START===" that
pertains to your migration request, up to the matching "===END===" that gave
your error result.
`GET
livemigrate=false&storageid=ce27d8fc-27cf-4754-8a82-e27497c390a7&volumeid=6a456713-a75e-48ba-a7aa-e4291aeb3472&command=migrateVolume&response=json
2022-04-25 05:47:09,405 DEBUG [c.c.a.ApiServer]
(qtp515715487-873791:ctx-ee2a2ad0 ctx-a34c2a4a) (logid:87478f01) CIDRs from
which account 'Acct[8a0f55f0-1f58-11ec-b6e8-244bfeb8116f-admin] -- Account
{"id": 2, "name": "admin", "uuid": "8a0f55f0-1f58-11ec-b6e8-244bfeb8116f"}' is
allowed to perform API calls: 0.0.0.0/0,::/0
2022-04-25 05:47:09,450 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-50:ctx-61f5af27 job-3035) (logid:7b804a24) Add job-3035 into
job monitoring
2022-04-25 05:47:09,455 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(qtp515715487-873791:ctx-ee2a2ad0 ctx-a34c2a4a) (logid:87478f01) submit async
job-3035, details: AsyncJobVO: {id:3035, userId: 2, accountId: 2, instanceType:
None, instanceId: null, cmd:
org.apache.cloudstack.api.command.admin.volume.MigrateVolumeCmdByAdmin,
cmdInfo:
{"response":"json","ctxUserId":"2","volumeid":"6a456713-a75e-48ba-a7aa-e4291aeb3472","httpmethod":"GET","ctxStartEventId":"9654","ctxDetails":"{\"interface
com.cloud.storage.Volume\":\"6a456713-a75e-48ba-a7aa-e4291aeb3472\",\"interface
com.cloud.storage.StoragePool\":\"ce27d8fc-27cf-4754-8a82-e27497c390a7\"}","ctxAccountId":"2","livemigrate":"false","cmdEventType":"VOLUME.MIGRATE","storageid":"ce27d8fc-27cf-4754-8a82-e27497c390a7"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 39908814623087, completeMsid: null, lastUpdated: null,
lastPolled: null, created: null, removed: null}
2022-04-25 05:47:09,455 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-50:ctx-61f5af27 job-3035) (logid:42469f70) Executing
AsyncJobVO: {id:3035, userId: 2, accountId: 2, instanceType: None, instanceId:
null, cmd:
org.apache.cloudstack.api.command.admin.volume.MigrateVolumeCmdByAdmin,
cmdInfo:
{"response":"json","ctxUserId":"2","volumeid":"6a456713-a75e-48ba-a7aa-e4291aeb3472","httpmethod":"GET","ctxStartEventId":"9654","ctxDetails":"{\"interface
com.cloud.storage.Volume\":\"6a456713-a75e-48ba-a7aa-e4291aeb3472\",\"interface
com.cloud.storage.StoragePool\":\"ce27d8fc-27cf-4754-8a82-e27497c390a7\"}","ctxAccountId":"2","livemigrate":"false","cmdEventType":"VOLUME.MIGRATE","storageid":"ce27d8fc-27cf-4754-8a82-e27497c390a7"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 39908814623087, completeMsid: null, lastUpdated: null,
lastPolled: null, created: null, removed: null}
2022-04-25 05:47:09,456 DEBUG [c.c.a.ApiServlet]
(qtp515715487-873791:ctx-ee2a2ad0 ctx-a34c2a4a) (logid:87478f01) ===END===
79.114.3.114 -- GET
livemigrate=false&storageid=ce27d8fc-27cf-4754-8a82-e27497c390a7&volumeid=6a456713-a75e-48ba-a7aa-e4291aeb3472&command=migrateVolume&response=json
2022-04-25 05:47:09,463 DEBUG [c.c.s.StorageManagerImpl]
(API-Job-Executor-50:ctx-61f5af27 job-3035 ctx-078119b5) (logid:42469f70)
Checking pool 18 for storage, totalSize: 1912334188544, usedBytes: 99259252736,
usedPct: 0.05190476294918585, disable threshold: 0.85
2022-04-25 05:47:09,463 DEBUG [c.c.s.StorageManagerImpl]
(API-Job-Executor-50:ctx-61f5af27 job-3035 ctx-078119b5) (logid:42469f70)
Destination pool id: 18
2022-04-25 05:47:09,465 DEBUG [c.c.s.StorageManagerImpl]
(API-Job-Executor-50:ctx-61f5af27 job-3035 ctx-078119b5) (logid:42469f70) Pool
ID for the volume with ID 591 is 8
2022-04-25 05:47:09,466 DEBUG [c.c.s.StorageManagerImpl]
(API-Job-Executor-50:ctx-61f5af27 job-3035 ctx-078119b5) (logid:42469f70) Found
storage pool ldnuk003 of type VMFS with over-provisioning factor 2
2022-04-25 05:47:09,466 DEBUG [c.c.s.StorageManagerImpl]
(API-Job-Executor-50:ctx-61f5af27 job-3035 ctx-078119b5) (logid:42469f70) Total
over-provisioned capacity calculated is 2 * (1.7393 TB) 1912334188544
2022-04-25 05:47:09,466 DEBUG [c.c.s.StorageManagerImpl]
(API-Job-Executor-50:ctx-61f5af27 job-3035 ctx-078119b5) (logid:42469f70) Total
capacity of the pool ldnuk003 with ID 18 is (3.4785 TB) 3824668377088
2022-04-25 05:47:09,467 DEBUG [c.c.s.StorageManagerImpl]
(API-Job-Executor-50:ctx-61f5af27 job-3035 ctx-078119b5) (logid:42469f70)
Checking pool: 18 for storage allocation , maxSize : (3.4785 TB) 3824668377088,
totalAllocatedSize : (253.32 GB) 272004808704, askingSize : (30.00 GB)
32212254720, allocated disable threshold: 0.85
2022-04-25 05:47:09,471 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-50:ctx-61f5af27 job-3035 ctx-078119b5) (logid:42469f70) Sync
job-3036 execution on object VmWorkJobQueue.583
2022-04-25 05:47:09,519 DEBUG [c.c.a.ApiServlet]
(qtp515715487-1043626:ctx-1f70f026) (logid:f11fe8e1) ===START=== 79.114.3.114
-- GET
jobId=42469f70-df52-4d24-a889-87b09b3f68ab&command=queryAsyncJobResult&response=json
2022-04-25 05:47:09,536 DEBUG [c.c.a.ApiServer]
(qtp515715487-1043626:ctx-1f70f026 ctx-d0e32dbf) (logid:f11fe8e1) CIDRs from
which account 'Acct[8a0f55f0-1f58-11ec-b6e8-244bfeb8116f-admin] -- Account
{"id": 2, "name": "admin", "uuid": "8a0f55f0-1f58-11ec-b6e8-244bfeb8116f"}' is
allowed to perform API calls: 0.0.0.0/0,::/0
2022-04-25 05:47:09,566 DEBUG [c.c.a.ApiServlet]
(qtp515715487-1043626:ctx-1f70f026 ctx-d0e32dbf) (logid:f11fe8e1) ===END===
79.114.3.114 -- GET
jobId=42469f70-df52-4d24-a889-87b09b3f68ab&command=queryAsyncJobResult&response=json
2022-04-25 05:47:10,045 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-4:null) (logid:) SeqA 27-972134: Processing Seq
27-972134: { Cmd , MgmtId: -1, via: 27, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":"330","_loadInfo":"{
"connections": []
}","wait":"0","bypassHostMaintenance":"false"}}] }
2022-04-25 05:47:10,052 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-4:null) (logid:) SeqA 27-972134: Sending Seq 27-972134:
{ Ans: , MgmtId: 39908814623087, via: 27, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":"true","wait":"0","bypassHostMaintenance":"false"}}]
}
2022-04-25 05:47:10,642 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-ad4d2842) (logid:fa8ab096) Execute sync-queue
item: SyncQueueItemVO {id:1813, queueId: 1811, contentType: AsyncJob,
contentId: 3036, lastProcessMsid: 39908814623087, lastprocessNumber: 3,
lastProcessTime: Mon Apr 25 05:47:10 UTC 2022, created: Mon Apr 25 05:47:09 UTC
2022}
2022-04-25 05:47:10,644 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-ad4d2842) (logid:fa8ab096) Schedule queued job-3036
2022-04-25 05:47:10,653 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-50:ctx-59c546a2 job-3035/job-3036) (logid:a8098653) Add
job-3036 into job monitoring
2022-04-25 05:47:10,661 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-50:ctx-59c546a2 job-3035/job-3036) (logid:42469f70)
Executing AsyncJobVO: {id:3036, userId: 2, accountId: 2, instanceType: null,
instanceId: null, cmd: com.cloud.vm.VmWorkMigrateVolume, cmdInfo:
rO0ABXNyACBjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZVZvbHVtZfgl82-871PmAgAESgAKZGVzdFBvb2xJZFoAC2xpdmVNaWdyYXRlSgAIdm9sdW1lSWRMABFuZXdEaXNrT2ZmZXJpbmdJZHQAEExqYXZhL2xhbmcvTG9uZzt4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1ldAASTGphdmEvbGFuZy9TdHJpbmc7eHAAAAAAAAAAAgAAAAAAAAACAAAAAAAAAkd0ABRWb2x1bWVBcGlTZXJ2aWNlSW1wbAAAAAAAAAASAQAAAAAAAAJPcA,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 39908814623087, completeMsid: null, lastUpdated: null,
lastPolled: null, created: Mon Apr 25 05:47:09 UTC 2022, removed: null}
2022-04-25 05:47:10,661 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-50:ctx-59c546a2 job-3035/job-3036) (logid:42469f70) Run VM
work job: com.cloud.vm.VmWorkMigrateVolume for VM 583, job origin: 3035
2022-04-25 05:47:10,667 DEBUG [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-50:ctx-59c546a2 job-3035/job-3036 ctx-0c4feac2)
(logid:42469f70) Execute VM work job:
com.cloud.vm.VmWorkMigrateVolume{"volumeId":591,"destPoolId":18,"liveMigrate":true,"userId":2,"accountId":2,"vmId":583,"handlerName":"VolumeApiServiceImpl"}
2022-04-25 05:47:10,793 DEBUG [o.a.c.s.m.VmwareStorageMotionStrategy]
(Work-Job-Executor-50:ctx-59c546a2 job-3035/job-3036 ctx-0c4feac2)
(logid:42469f70) class
org.apache.cloudstack.storage.motion.VmwareStorageMotionStrategy can handle the
request because 591(6a456713-a75e-48ba-a7aa-e4291aeb3472) and
591(6a456713-a75e-48ba-a7aa-e4291aeb3472) share the pod
2022-04-25 05:47:10,807 DEBUG [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-50:ctx-59c546a2 job-3035/job-3036 ctx-0c4feac2)
(logid:42469f70) host id is null, using last host id 12
2022-04-25 05:47:10,879 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-50:ctx-59c546a2 job-3035/job-3036 ctx-0c4feac2)
(logid:42469f70) Seq 12-5449355549118325210: Sending { Cmd , MgmtId:
39908814623087, via: 12(ldn-uk-001.domain.tld), Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.storage.MigrateVolumeCommand":{"volumeId":"591","volumePath":"ROOT-583","chainInfo":"{"diskDeviceBusName":"scsi0:0","diskChain":["[ldnuk001]
i-2-583-VM/ROOT-583.vmdk"]}","pool":{"id":"18","uuid":"ce27d8fc-27cf-4754-8a82-e27497c390a7","host":"VMFS
datastore:
datastore-7973","path":"datastore-7973","port":"0","type":"VMFS"},"sourcePool":{"id":"8","uuid":"7eb82b52-5e50-4db1-a4c1-5a6c2d5e2680","host":"VMFS
datastore:
datastore-7190","path":"datastore-7190","port":"0","type":"VMFS"},"attachedVmName":"i-2-583-VM","volumeType":"UNKNOWN","wait":"-1","bypassHostMaintenance":"false"}}]
}
2022-04-25 05:47:10,880 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-50:ctx-59c546a2 job-3035/job-3036 ctx-0c4feac2)
(logid:42469f70) Seq 12-5449355549118325210: Executing: { Cmd , MgmtId:
39908814623087, via: 12(ldn-uk-001.domain.tld), Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.storage.MigrateVolumeCommand":{"volumeId":"591","volumePath":"ROOT-583","chainInfo":"{"diskDeviceBusName":"scsi0:0","diskChain":["[ldnuk001]
i-2-583-VM/ROOT-583.vmdk"]}","pool":{"id":"18","uuid":"ce27d8fc-27cf-4754-8a82-e27497c390a7","host":"VMFS
datastore:
datastore-7973","path":"datastore-7973","port":"0","type":"VMFS"},"sourcePool":{"id":"8","uuid":"7eb82b52-5e50-4db1-a4c1-5a6c2d5e2680","host":"VMFS
datastore:
datastore-7190","path":"datastore-7190","port":"0","type":"VMFS"},"attachedVmName":"i-2-583-VM","volumeType":"UNKNOWN","wait":"-1","bypassHostMaintenance":"false"}}]
}
2022-04-25 05:47:10,880 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-156:ctx-87c92daf) (logid:519241d4) Seq 12-5449355549118325210:
Executing request
2022-04-25 05:47:10,880 INFO [c.c.h.v.r.VmwareResource]
(DirectAgent-156:ctx-87c92daf ldn-uk-001.domain.tld, job-3035/job-3036, cmd:
MigrateVolumeCommand) (logid:42469f70) Executing resource MigrateVolumeCommand:
{"volumeId":591,"volumePath":"ROOT-583","chainInfo":"{\"diskDeviceBusName\":\"scsi0:0\",\"diskChain\":[\"[ldnuk001]
i-2-583-VM/ROOT-583.vmdk\"]}","pool":{"id":18,"uuid":"ce27d8fc-27cf-4754-8a82-e27497c390a7","host":"VMFS
datastore:
datastore-7973","path":"datastore-7973","port":0,"type":"VMFS"},"sourcePool":{"id":8,"uuid":"7eb82b52-5e50-4db1-a4c1-5a6c2d5e2680","host":"VMFS
datastore:
datastore-7190","path":"datastore-7190","port":0,"type":"VMFS"},"attachedVmName":"i-2-583-VM","volumeType":"UNKNOWN","wait":-1,"bypassHostMaintenance":false}
2022-04-25 05:47:11,977 ERROR [c.c.h.v.r.VmwareResource]
(DirectAgent-156:ctx-87c92daf ldn-uk-001.domain.tld, job-3035/job-3036, cmd:
MigrateVolumeCommand) (logid:42469f70) Unable to find the mounted datastore
with name: ce27d8fc-27cf-4754-8a82-e27497c390a7 on source host:
ldn-uk-001.domain.tld to execute MigrateVolumeCommand
2022-04-25 05:47:11,977 ERROR [c.c.h.v.r.VmwareResource]
(DirectAgent-156:ctx-87c92daf ldn-uk-001.domain.tld, job-3035/job-3036, cmd:
MigrateVolumeCommand) (logid:42469f70) Catch Exception java.lang.Exception due
to java.lang.Exception: Unable to find the mounted datastore with name:
ce27d8fc-27cf-4754-8a82-e27497c390a7 on source host: ldn-uk-001.domain.tld to
execute MigrateVolumeCommand
java.lang.Exception: Unable to find the mounted datastore with name:
ce27d8fc-27cf-4754-8a82-e27497c390a7 on source host: ldn-uk-001.domain.tld to
execute MigrateVolumeCommand
at
com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:4896)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:505)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:315)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45)
at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)
2022-04-25 05:47:11,978 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-156:ctx-87c92daf) (logid:42469f70) Seq 12-5449355549118325210:
Response Received:
2022-04-25 05:47:11,978 DEBUG [c.c.a.t.Request]
(DirectAgent-156:ctx-87c92daf) (logid:42469f70) Seq 12-5449355549118325210:
Processing: { Ans: , MgmtId: 39908814623087, via: 12(ldn-uk-001.domain.tld),
Ver: v1, Flags: 110,
[{"com.cloud.agent.api.storage.MigrateVolumeAnswer":{"result":"false","details":"Catch
Exception java.lang.Exception due to java.lang.Exception: Unable to find the
mounted datastore with name: ce27d8fc-27cf-4754-8a82-e27497c390a7 on source
host: ldn-uk-001.domain.tld to execute
MigrateVolumeCommand","wait":"0","bypassHostMaintenance":"false"}}] }
2022-04-25 05:47:11,979 DEBUG [c.c.a.m.AgentAttache]
(DirectAgent-156:ctx-87c92daf) (logid:42469f70) Seq 12-5449355549118325210: No
more commands found
2022-04-25 05:47:11,979 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-50:ctx-59c546a2 job-3035/job-3036 ctx-0c4feac2)
(logid:42469f70) Seq 12-5449355549118325210: Received: { Ans: , MgmtId:
39908814623087, via: 12(ldn-uk-001.domain.tld), Ver: v1, Flags: 110, {
MigrateVolumeAnswer } }
2022-04-25 05:47:11,979 DEBUG [c.c.a.m.AgentManagerImpl]
(Work-Job-Executor-50:ctx-59c546a2 job-3035/job-3036 ctx-0c4feac2)
(logid:42469f70) Details from executing class
com.cloud.agent.api.storage.MigrateVolumeCommand: Catch Exception
java.lang.Exception due to java.lang.Exception: Unable to find the mounted
datastore with name: ce27d8fc-27cf-4754-8a82-e27497c390a7 on source host:
ldn-uk-001.domain.tld to execute MigrateVolumeCommand
2022-04-25 05:47:11,981 DEBUG [o.a.c.s.m.VmwareStorageMotionStrategy]
(Work-Job-Executor-50:ctx-59c546a2 job-3035/job-3036 ctx-0c4feac2)
(logid:42469f70) retrieved 'null' as new path for volume(591)
`
This is how the event start when I start the volume migration.
Not sure why cloudstack is looking for destination storage on source host,
in this part "Unable to find the mounted datastore with name:
ce27d8fc-27cf-4754-8a82-e27497c390a7 on source host: ldn-uk-001.domain.tld to
execute MigrateVolumeCommand" this storage is the destination
"ce27d8fc-27cf-4754-8a82-e27497c390a7" which is on host "ldn-uk-003.domain.tld"
where I want to migrate.
This setup is only with local storage configured, the above behavior is for
shared storage, both, when I execute volume migration and migrate to another
primary storage.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
