Chandan Purushothama created CLOUDSTACK-6442:
------------------------------------------------
Summary: [Automation] Extraction of Volume failed due to the
requested plugin could not be found.
Key: CLOUDSTACK-6442
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-6442
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Automation, Management Server
Affects Versions: 4.4.0
Environment: Basic Zone
XenServer
Reporter: Chandan Purushothama
Priority: Blocker
Fix For: 4.4.0
Attachments: management-server.log.2014-04-16.gz
Use Case:
Extract Volume from the Setup
================================
The requested plugin could not be found.
================================
2014-04-16 15:59:56,332 DEBUG [c.c.a.ApiServlet] (catalina-exec-1:ctx-2bcdf669)
===START=== 10.223.240.161 -- GET
apiKey=MNQSBTYnkNvc4PCMgv7itBuPnuHpnUT_TEJRzzCOZXPL5bl9ihaz0P3TpkK3IW36icuUoFQkySLQkvQ9K6Dh0Q&zoneid=4fbc4494-e655-49b6-bda1-7ad8eb641732&command=extractVolume&mode=HTTP_DOWNLOAD&signature=yuDaizmeEsZcaxZW0QEVOGL7YK0%3D&id=b5521198-97f1-4f2c-afea-fcadf70d4249&response=json
2014-04-16 15:59:56,335 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-20:null) SeqA 4-314: Processing Seq 4-314: { Cmd ,
MgmtId: -1, via: 4, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2014-04-16 15:59:56,343 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-20:null) SeqA 4-314: Sending Seq 4-314: { Ans: , MgmtId:
112957957439171, via: 4, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2014-04-16 15:59:56,369 DEBUG [c.c.u.AccountManagerImpl]
(catalina-exec-1:ctx-2bcdf669 ctx-da1872d1 ctx-20bb4a0a) Access to
{Vol[31|vm=null|DATADISK]} granted to
Acct[ed7cd506-e810-496f-94ee-3e422b3a6449-test-TestVolumes-test_01_create_volume-7K52C0]
by RoleBasedEntityAccessChecker
2014-04-16 15:59:56,388 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(catalina-exec-1:ctx-2bcdf669 ctx-da1872d1 ctx-20bb4a0a) submit async job-169,
details: AsyncJobVO {id:169, userId: 2, accountId: 2, instanceType: Volume,
instanceId: 31, cmd:
org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd, cmdInfo:
{"response":"json","id":"b5521198-97f1-4f2c-afea-fcadf70d4249","cmdEventType":"VOLUME.EXTRACT","ctxUserId":"2","zoneid":"4fbc4494-e655-49b6-bda1-7ad8eb641732","httpmethod":"GET","uuid":"b5521198-97f1-4f2c-afea-fcadf70d4249","ctxAccountId":"2","ctxStartEventId":"441","apiKey":"MNQSBTYnkNvc4PCMgv7itBuPnuHpnUT_TEJRzzCOZXPL5bl9ihaz0P3TpkK3IW36icuUoFQkySLQkvQ9K6Dh0Q","signature":"yuDaizmeEsZcaxZW0QEVOGL7YK0\u003d","mode":"HTTP_DOWNLOAD"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 112957957439171, completeMsid: null, lastUpdated: null,
lastPolled: null, created: null}
2014-04-16 15:59:56,389 DEBUG [c.c.a.ApiServlet] (catalina-exec-1:ctx-2bcdf669
ctx-da1872d1 ctx-20bb4a0a) ===END=== 10.223.240.161 -- GET
apiKey=MNQSBTYnkNvc4PCMgv7itBuPnuHpnUT_TEJRzzCOZXPL5bl9ihaz0P3TpkK3IW36icuUoFQkySLQkvQ9K6Dh0Q&zoneid=4fbc4494-e655-49b6-bda1-7ad8eb641732&command=extractVolume&mode=HTTP_DOWNLOAD&signature=yuDaizmeEsZcaxZW0QEVOGL7YK0%3D&id=b5521198-97f1-4f2c-afea-fcadf70d4249&response=json
2014-04-16 15:59:56,394 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-76:job-169) Add job-169 into job monitoring
2014-04-16 15:59:56,394 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-76:job-169) Executing AsyncJobVO {id:169, userId: 2,
accountId: 2, instanceType: Volume, instanceId: 31, cmd:
org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd, cmdInfo:
{"response":"json","id":"b5521198-97f1-4f2c-afea-fcadf70d4249","cmdEventType":"VOLUME.EXTRACT","ctxUserId":"2","zoneid":"4fbc4494-e655-49b6-bda1-7ad8eb641732","httpmethod":"GET","uuid":"b5521198-97f1-4f2c-afea-fcadf70d4249","ctxAccountId":"2","ctxStartEventId":"441","apiKey":"MNQSBTYnkNvc4PCMgv7itBuPnuHpnUT_TEJRzzCOZXPL5bl9ihaz0P3TpkK3IW36icuUoFQkySLQkvQ9K6Dh0Q","signature":"yuDaizmeEsZcaxZW0QEVOGL7YK0\u003d","mode":"HTTP_DOWNLOAD"},
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 112957957439171, completeMsid: null, lastUpdated: null,
lastPolled: null, created: null}
2014-04-16 15:59:56,395 DEBUG [c.c.a.ApiServlet]
(catalina-exec-20:ctx-fecf5e4b) ===START=== 10.223.240.161 -- GET
signature=r5hVEIZ2lBcpC3YGWKnS1uYMwlU%3D&apiKey=MNQSBTYnkNvc4PCMgv7itBuPnuHpnUT_TEJRzzCOZXPL5bl9ihaz0P3TpkK3IW36icuUoFQkySLQkvQ9K6Dh0Q&command=queryAsyncJobResult&response=json&jobid=75dc8574-0d93-4e5d-968e-d743cad83ec2
2014-04-16 15:59:56,420 DEBUG [c.c.u.AccountManagerImpl]
(API-Job-Executor-76:job-169 ctx-d6febdc7) Access to {Vol[31|vm=null|DATADISK]}
granted to
Acct[ed7cd506-e810-496f-94ee-3e422b3a6449-test-TestVolumes-test_01_create_volume-7K52C0]
by RoleBasedEntityAccessChecker
2014-04-16 15:59:56,444 DEBUG [c.c.u.AccountManagerImpl]
(API-Job-Executor-76:job-169 ctx-d6febdc7) Root Access granted to
Acct[ee1fdc10-c5b4-11e3-8f55-66bc12ed7ec3-admin] by RoleBasedEntityAccessChecker
2014-04-16 15:59:56,445 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-fecf5e4b
ctx-04b7e493 ctx-bb0854e9) ===END=== 10.223.240.161 -- GET
signature=r5hVEIZ2lBcpC3YGWKnS1uYMwlU%3D&apiKey=MNQSBTYnkNvc4PCMgv7itBuPnuHpnUT_TEJRzzCOZXPL5bl9ihaz0P3TpkK3IW36icuUoFQkySLQkvQ9K6Dh0Q&command=queryAsyncJobResult&response=json&jobid=75dc8574-0d93-4e5d-968e-d743cad83ec2
2014-04-16 15:59:56,459 DEBUG [c.c.u.AccountManagerImpl]
(API-Job-Executor-76:job-169 ctx-d6febdc7) Access to {Vol[31|vm=null|DATADISK]}
granted to Acct[ee1fdc10-c5b4-11e3-8f55-66bc12ed7ec3-admin] by
RoleBasedEntityAccessChecker
2014-04-16 15:59:56,503 DEBUG [o.a.c.s.m.AncientDataMotionStrategy]
(API-Job-Executor-76:job-169 ctx-d6febdc7) copyAsync inspecting src type VOLUME
copyAsync inspecting dest type VOLUME
2014-04-16 15:59:56,512 DEBUG [c.c.a.t.Request] (API-Job-Executor-76:job-169
ctx-d6febdc7) Seq 2-7234469851417280595: Sending { Cmd , MgmtId:
112957957439171, via: 2(marron.lab.vmops.com), Ver: v1, Flags: 100011,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"b5521198-97f1-4f2c-afea-fcadf70d4249","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"ac0c4b04-6b72-38b1-a72f-c7fe7163d17a","id":1,"poolType":"NetworkFilesystem","host":"nfs1-ccp.citrix.com","path":"/home/common/automation/SC_QA_AUTO7/primary4","port":2049,"url":"NetworkFilesystem://nfs1-ccp.citrix.com/home/common/automation/SC_QA_AUTO7/primary4/?ROLE=Primary&STOREUUID=ac0c4b04-6b72-38b1-a72f-c7fe7163d17a"}},"name":"TestDiskServ","size":1073741824,"path":"a060d7ba-6144-44fd-a45b-e7777e8e874a","volumeId":31,"accountId":19,"format":"VHD","id":31,"hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"b5521198-97f1-4f2c-afea-fcadf70d4249","volumeType":"DATADISK","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://nfs1-ccp.citrix.com:/home/common/automation/SC_QA_AUTO7/secondary4","_role":"Image"}},"name":"TestDiskServ","size":1073741824,"path":"volumes/19/31","volumeId":31,"accountId":19,"format":"VHD","id":31,"hypervisorType":"XenServer"}},"executeInSequence":false,"options":{},"wait":10800}}]
}
2014-04-16 15:59:56,513 DEBUG [c.c.a.t.Request] (API-Job-Executor-76:job-169
ctx-d6febdc7) Seq 2-7234469851417280595: Executing: { Cmd , MgmtId:
112957957439171, via: 2(marron.lab.vmops.com), Ver: v1, Flags: 100011,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"b5521198-97f1-4f2c-afea-fcadf70d4249","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"ac0c4b04-6b72-38b1-a72f-c7fe7163d17a","id":1,"poolType":"NetworkFilesystem","host":"nfs1-ccp.citrix.com","path":"/home/common/automation/SC_QA_AUTO7/primary4","port":2049,"url":"NetworkFilesystem://nfs1-ccp.citrix.com/home/common/automation/SC_QA_AUTO7/primary4/?ROLE=Primary&STOREUUID=ac0c4b04-6b72-38b1-a72f-c7fe7163d17a"}},"name":"TestDiskServ","size":1073741824,"path":"a060d7ba-6144-44fd-a45b-e7777e8e874a","volumeId":31,"accountId":19,"format":"VHD","id":31,"hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"b5521198-97f1-4f2c-afea-fcadf70d4249","volumeType":"DATADISK","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://nfs1-ccp.citrix.com:/home/common/automation/SC_QA_AUTO7/secondary4","_role":"Image"}},"name":"TestDiskServ","size":1073741824,"path":"volumes/19/31","volumeId":31,"accountId":19,"format":"VHD","id":31,"hypervisorType":"XenServer"}},"executeInSequence":false,"options":{},"wait":10800}}]
}
2014-04-16 15:59:56,513 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-149:ctx-46eb6a8b) Seq 2-7234469851417280595: Executing request
2014-04-16 15:59:56,594 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-149:ctx-46eb6a8b) callHostPlugin failed for cmd:
create_secondary_storage_folder with args remoteMountPath:
nfs1-ccp.citrix.com:/home/common/automation/SC_QA_AUTO7/secondary4, newFolder:
volumes/19/31, due to The requested plugin could not be found.
2014-04-16 15:59:56,594 DEBUG [c.c.h.x.r.XenServerStorageProcessor]
(DirectAgent-149:ctx-46eb6a8b) Failed to copy volume to secondary:
com.cloud.utils.exception.CloudRuntimeException: callHostPlugin failed for cmd:
create_secondary_storage_folder with args remoteMountPath:
nfs1-ccp.citrix.com:/home/common/automation/SC_QA_AUTO7/secondary4, newFolder:
volumes/19/31, due to The requested plugin could not be found.
2014-04-16 15:59:56,594 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-149:ctx-46eb6a8b) Seq 2-7234469851417280595: Response Received:
2014-04-16 15:59:56,594 DEBUG [c.c.a.t.Request] (DirectAgent-149:ctx-46eb6a8b)
Seq 2-7234469851417280595: Processing: { Ans: , MgmtId: 112957957439171, via:
2, Ver: v1, Flags: 10,
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"Failed
to copy volume to secondary: com.cloud.utils.exception.CloudRuntimeException:
callHostPlugin failed for cmd: create_secondary_storage_folder with args
remoteMountPath:
nfs1-ccp.citrix.com:/home/common/automation/SC_QA_AUTO7/secondary4, newFolder:
volumes/19/31, due to The requested plugin could not be found.","wait":0}}] }
2014-04-16 15:59:56,594 DEBUG [c.c.a.t.Request] (API-Job-Executor-76:job-169
ctx-d6febdc7) Seq 2-7234469851417280595: Received: { Ans: , MgmtId:
112957957439171, via: 2, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2014-04-16 15:59:56,602 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl]
(API-Job-Executor-76:job-169 ctx-d6febdc7) Unsupported data object (VOLUME,
org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@23ebca5c), no need
to delete from object in store ref table
2014-04-16 15:59:56,625 ERROR [c.c.a.ApiAsyncJobDispatcher]
(API-Job-Executor-76:job-169) Unexpected exception while executing
org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd
com.cloud.utils.exception.CloudRuntimeException: Failed to copy the volume from
the source primary storage pool to secondary storage.
at
com.cloud.storage.VolumeApiServiceImpl.extractVolume(VolumeApiServiceImpl.java:1897)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:106)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
at
com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy181.extractVolume(Unknown Source)
at
org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd.execute(ExtractVolumeCmd.java:138)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:134)
at
com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:100)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:495)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:452)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2014-04-16 15:59:56,626 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-76:job-169) Complete async job-169, jobStatus: FAILED,
resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed
to copy the volume from the source primary storage pool to secondary storage."}
2014-04-16 15:59:56,634 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-76:job-169) Done executing
org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd for job-169
2014-04-16 15:59:56,640 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-76:job-169) Remove job-169 from job monitoring
--
This message was sent by Atlassian JIRA
(v6.2#6252)
