[ https://issues.apache.org/jira/browse/CLOUDSTACK-6442?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Anthony Xu resolved CLOUDSTACK-6442. ------------------------------------ Resolution: Fixed commit 33c0d6c7bbb2e85f87935dee64dccbe2ee7f264c Author: Anthony Xu <anthony...@citrix.com> Date: Wed Apr 23 15:30:36 2014 -0700 CLOUDSTACK-6438 CLOUDSTACK-6442 XAPI plugins must be copied to XS master first. > [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 > Assignee: Anthony Xu > 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)