Return-Path: X-Original-To: apmail-cloudstack-users-archive@www.apache.org Delivered-To: apmail-cloudstack-users-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 8300810FDF for ; Wed, 4 Dec 2013 13:25:15 +0000 (UTC) Received: (qmail 54321 invoked by uid 500); 4 Dec 2013 13:24:19 -0000 Delivered-To: apmail-cloudstack-users-archive@cloudstack.apache.org Received: (qmail 54289 invoked by uid 500); 4 Dec 2013 13:24:17 -0000 Mailing-List: contact users-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: users@cloudstack.apache.org Delivered-To: mailing list users@cloudstack.apache.org Received: (qmail 54219 invoked by uid 99); 4 Dec 2013 13:24:12 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 04 Dec 2013 13:24:12 +0000 X-ASF-Spam-Status: No, hits=-0.7 required=5.0 tests=RCVD_IN_DNSWL_LOW,SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (nike.apache.org: local policy includes SPF record at spf.trusted-forwarder.org) Received: from [209.85.223.171] (HELO mail-ie0-f171.google.com) (209.85.223.171) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 04 Dec 2013 13:24:04 +0000 Received: by mail-ie0-f171.google.com with SMTP id ar20so26546967iec.16 for ; Wed, 04 Dec 2013 05:23:43 -0800 (PST) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:content-type:mime-version:subject:from :in-reply-to:date:content-transfer-encoding:message-id:references:to; bh=9B5VMd+Q9gjCqxE6zwa2mHelSyEi6M3eJ1Rq5glkI20=; b=OAgOu4UeD8SFfczZEMN/x7Urxp7kFUdAHg/LGLuGtKaUBRht5vJUVcNSC4M6dput78 gL/VgD0TDh1x7tnr/F6OT6fMimJV2+0i65Q5hhnkyBTVEmyJX+EcfAx8UQIMivJh67YV JWqElNvz0YlNwsXywwnRq3XHMuDGt+CCk8J2qDgJsp3zHazAVYjpmIgpRpMGidq4xTLd hFriobjPGrCVeWR94+EIljsOX9YRtt/zvc9hdRULpWQCgxU4xMiJ2p//FDQR5n7lkefl JdEfTdRb5BMEHOEMyb8n2qmobCt6GIra5D0kQtr0/hTSGoH13Qi7vfPGE/k/Ju2ogDZs Wdtw== X-Gm-Message-State: ALoCoQkHMXWbaNQky/HFADIpMTHH0kPVujVAMz0jJuEoaYR8K3Dm4SVBvKCZ21tbpDfGJwPOK332 X-Received: by 10.42.84.130 with SMTP id m2mr48796324icl.16.1386163423273; Wed, 04 Dec 2013 05:23:43 -0800 (PST) Received: from [10.10.13.27] (50-80-52-210.client.mchsi.com. [50.80.52.210]) by mx.google.com with ESMTPSA id qi3sm4132214igc.8.2013.12.04.05.23.42 for (version=TLSv1 cipher=ECDHE-RSA-RC4-SHA bits=128/128); Wed, 04 Dec 2013 05:23:42 -0800 (PST) Content-Type: text/plain; charset=us-ascii Mime-Version: 1.0 (Mac OS X Mail 7.0 \(1822\)) Subject: Re: Unable to execute PrimaryStorageDownloadCommand From: John Skinner In-Reply-To: Date: Wed, 4 Dec 2013 07:23:43 -0600 Content-Transfer-Encoding: quoted-printable Message-Id: <1E883567-9856-4A4D-BB7B-D44DE9909BE0@appcore.com> References: <9E7307EB-9431-44E1-B958-A58A4904B9D1@appcore.com> To: users@cloudstack.apache.org X-Mailer: Apple Mail (2.1822) X-Virus-Checked: Checked by ClamAV on apache.org I did confirm that the template does exist in the directory. On Dec 3, 2013, at 11:05 PM, Sanjeev Neelarapu = wrote: > Hi, >=20 > Can you make sure that the template with which you are trying to = deploy a VM is present on the secondary Storage inside 244 directory? >=20 > -Sanjeev > -----Original Message----- > From: John Skinner [mailto:john.skinner@appcore.com]=20 > Sent: Wednesday, December 04, 2013 12:55 AM > To: users@cloudstack.apache.org > Subject: Unable to execute PrimaryStorageDownloadCommand >=20 > Environment running CloudStack 4.1.1 with VMware vSphere 5.1 nodes and = NFS backed Primary Storage data stores. We are currently having issues = creating VMs from a template when we have to copy the template from = secondary storage. If the template already exists on primary storage = then the VM gets created just fine. I have already checked the mount = points and vCenter has read/write access to the NFS share for secondary = storage, and the secondary storage VM has the share mounted and can = read/write to it as well. >=20 > This is the exception from the management server logs: >=20 > 2013-12-03 09:13:10,468 DEBUG [agent.manager.AgentManagerImpl] = (Job-Executor-9:job-14655) Details from executing class = com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Unable to = execute PrimaryStorageDownloadCommand due to exception > 2013-12-03 09:13:10,468 DEBUG [cloud.template.TemplateManagerImpl] = (Job-Executor-9:job-14655) Template 244 download to pool 222 failed due = to Unable to execute PrimaryStorageDownloadCommand due to exception > 2013-12-03 09:13:10,469 DEBUG [cloud.template.TemplateManagerImpl] = (Job-Executor-9:job-14655) Template 244 is not found on and can not be = downloaded to pool 222 > 2013-12-03 09:13:10,469 DEBUG [cloud.storage.StorageManagerImpl] = (Job-Executor-9:job-14655) Cannot use this pool = Pool[222|NetworkFilesystem] because we can't propagate template = Tmpl[244-OVA-244-2-0e18671b-1f2a-3b10-8b1a-7608bda5695c > 2013-12-03 09:13:10,505 DEBUG [agent.manager.AgentAttache] = (AgentManager-Handler-15:null) Seq 59-806028519: No more commands found > 2013-12-03 09:13:10,580 INFO [cloud.vm.VirtualMachineManagerImpl] = (Job-Executor-9:job-14655) Unable to contact resource. > com.cloud.exception.StorageUnavailableException: Resource = [StoragePool:222] is unreachable: Unable to create = Vol[11319|vm=3D11283|ROOT] > at = com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3488)= > at = com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerI= mpl.java:748) > at = com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.jav= a:471) > at = org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVi= rtualMachine(VMEntityManagerImpl.java:212) > at = org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.dep= loy(VirtualMachineEntityImpl.java:209) > at = com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:= 3871) > at = com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:= 3464) > at = com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:= 3450) > at = com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorD= ispatcher.intercept(ComponentInstantiationPostProcessor.java:125) > at = org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.= java:379) > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:162) > at = com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:437) > at = java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > at = java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) > at java.util.concurrent.FutureTask.run(FutureTask.java:166) > at = java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:= 1146) > at = java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java= :615) > at java.lang.Thread.run(Thread.java:679) > 2013-12-03 09:13:10,660 DEBUG [cloud.vm.VirtualMachineManagerImpl] = (Job-Executor-9:job-14655) Cleaning up resources for the vm = VM[User|OrangeTest] in Starting state >=20 > And this is the same error, however this is from the systemvm.log on = the Secondary Storage VM: >=20 > 2013-12-03 15:26:43,125 DEBUG [cloud.agent.Agent] = (agentRequest-Handler-5:) Processing command: = com.cloud.agent.api.storage.PrimaryStorageDownloadCommand > 2013-12-03 15:26:43,126 DEBUG = [storage.resource.VmwareSecondaryStorageResourceHandler] = (agentRequest-Handler-5:) Executing resource = PrimaryStorageDownloadCommand: = {"localPath":"/mnt/e2955a69-77f1-3888-a810-d2d54bd6bb0f","poolUuid":"e2955= a69-77f1-3888-a810-d2d54bd6bb0f","poolId":218,"primaryPool":{"id":218,"uui= d":"e2955a69-77f1-3888-a810-d2d54bd6bb0f","host":"10.1.100.19","path":"/vo= l/vol_aCloud_1_01_7k","port":2049,"type":"NetworkFilesystem"},"secondarySt= orageUrl":"nfs://10.1.100.20/vol/vol_aCloud_2_01_15k","primaryStorageUrl":= "nfs://10.1.100.19/vol/vol_aCloud_1_01_7k","url":"nfs://10.1.100.20/vol/vo= l_aCloud_2_01_15k/template/tmpl/2/244//b2504ba2-5b61-3cdb-887e-f52eedf6d1b= f.ova","format":"OVA","accountId":2,"name":"244-2-0e18671b-1f2a-3b10-8b1a-= 7608bda5695c","wait":10800} > 2013-12-03 15:26:43,424 WARN = [storage.resource.VmwareSecondaryStorageResourceHandler] = (agentRequest-Handler-5:) Context validation failed due to Exception: = java.lang.NullPointerException > Message: null >=20 > 2013-12-03 15:26:43,720 WARN [vmware.util.VmwareContext] = (agentRequest-Handler-5:) Unexpected exception: > com.vmware.apputils.ArgumentHandlingException: Exception running : = 10.0.50.70-10395 > at = com.vmware.apputils.version.ExtendedAppUtil.disConnect(ExtendedAppUtil.jav= a:90) > at = com.cloud.hypervisor.vmware.util.VmwareContext.close(VmwareContext.java:59= 8) > at = com.cloud.storage.resource.VmwareSecondaryStorageContextFactory.invalidate= (VmwareSecondaryStorageContextFactory.java:72) > at = com.cloud.storage.resource.VmwareSecondaryStorageResourceHandler.invalidat= eServiceContext(VmwareSecondaryStorageResourceHandler.java:203) > at = com.cloud.storage.resource.VmwareSecondaryStorageResourceHandler.getServic= eContext(VmwareSecondaryStorageResourceHandler.java:186) > at = com.cloud.hypervisor.vmware.manager.VmwareStorageManagerImpl.execute(Vmwar= eStorageManagerImpl.java:120) > at = com.cloud.storage.resource.VmwareSecondaryStorageResourceHandler.execute(V= mwareSecondaryStorageResourceHandler.java:105) > at = com.cloud.storage.resource.VmwareSecondaryStorageResourceHandler.executeRe= quest(VmwareSecondaryStorageResourceHandler.java:69) > at = com.cloud.storage.resource.PremiumSecondaryStorageResource.executeRequest(= PremiumSecondaryStorageResource.java:54) > at com.cloud.agent.Agent.processRequest(Agent.java:525) > at = com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852) > at com.cloud.utils.nio.Task.run(Task.java:83) > at = java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.= java:886) > at = java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java= :908) > at java.lang.Thread.run(Thread.java:662) > 2013-12-03 15:26:46,074 DEBUG = [storage.resource.VmwareSecondaryStorageResourceHandler] = (agentRequest-Handler-5:) Context validation succeeded. Validated via = host: 10.0.97.107, guid: HostSystem:host-3906@10.0.50.70 > 2013-12-03 15:26:47,514 INFO = [storage.resource.VmwareSecondaryStorageResourceHandler] = (agentRequest-Handler-5:) Setup firewall rule for host: 10.0.97.101 > 2013-12-03 15:26:48,408 INFO = [storage.resource.VmwareSecondaryStorageResourceHandler] = (agentRequest-Handler-5:) Setup firewall rule for host: 10.0.97.103 > 2013-12-03 15:26:49,265 INFO = [storage.resource.VmwareSecondaryStorageResourceHandler] = (agentRequest-Handler-5:) Setup firewall rule for host: 10.0.97.105 > 2013-12-03 15:26:50,138 INFO = [storage.resource.VmwareSecondaryStorageResourceHandler] = (agentRequest-Handler-5:) Setup firewall rule for host: 10.0.97.107 > 2013-12-03 15:26:50,900 INFO = [vmware.manager.VmwareStorageManagerImpl] (agentRequest-Handler-5:) = Template b2504ba2-5b61-3cdb-887e-f52eedf6d1bf is not setup yet, setup = template from secondary storage with uuid name: = 776550120fa43526a7b35637812b5db6 > 2013-12-03 15:26:51,630 INFO = [vmware.manager.VmwareStorageManagerImpl] (agentRequest-Handler-5:) = Executing copyTemplateFromSecondaryToPrimary. secondaryStorage: = nfs://10.1.100.20/vol/vol_aCloud_2_01_15k, = templatePathAtSecondaryStorage: template/tmpl/2/244/, templateName: = b2504ba2-5b61-3cdb-887e-f52eedf6d1bf > 2013-12-03 15:26:51,631 DEBUG = [storage.resource.NfsSecondaryStorageResource] (agentRequest-Handler-5:) = Executing: mount > 2013-12-03 15:26:51,634 DEBUG = [storage.resource.NfsSecondaryStorageResource] (agentRequest-Handler-5:) = Execution is successful. > 2013-12-03 15:26:51,634 INFO = [vmware.manager.VmwareStorageManagerImpl] (agentRequest-Handler-5:) = Secondary storage mount point: = /mnt/SecStorage/9df8a8d2-23c2-38d2-b0c1-eeca6a95ac96 > 2013-12-03 15:26:53,447 ERROR = [vmware.manager.VmwareStorageManagerImpl] (agentRequest-Handler-5:) = Unable to execute PrimaryStorageDownloadCommand due to exception = AxisFault > faultCode: ServerFaultCode > faultSubcode: > faultString: > Attribute xsi:nil not allowed on element spec, which is not nillable. >=20 > while parsing call information for method ImportVApp at line 1, column = 227 >=20 > while parsing SOAP body > at line 1, column 213 >=20 > while parsing SOAP envelope > at line 1, column 38 >=20 > while parsing HTTP request for method importVApp on object of type = vim.ResourcePool at line 1, column 0 > faultActor: > faultNode: > faultDetail: > {urn:vim25}InvalidRequestFault:null >=20 >=20 > Attribute xsi:nil not allowed on element spec, which is not nillable. >=20 > while parsing call information for method ImportVApp at line 1, column = 227 >=20 > while parsing SOAP body > at line 1, column 213 >=20 > while parsing SOAP envelope > at line 1, column 38 >=20 > while parsing HTTP request for method importVApp on object of type = vim.ResourcePool at line 1, column 0 > at = sun.reflect.GeneratedConstructorAccessor110.newInstance(Unknown Source) > at = sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstr= uctorAccessorImpl.java:27) > at = java.lang.reflect.Constructor.newInstance(Constructor.java:513) > at java.lang.Class.newInstance0(Class.java:355) > at java.lang.Class.newInstance(Class.java:308) > at = org.apache.axis.encoding.ser.BeanDeserializer.(BeanDeserializer.java= :104) > at = org.apache.axis.encoding.ser.BeanDeserializer.(BeanDeserializer.java= :90) > at = com.vmware.vim25.InvalidRequest.getDeserializer(InvalidRequest.java:87) > at sun.reflect.GeneratedMethodAccessor1150.invoke(Unknown = Source) > at = sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorIm= pl.java:25) > at java.lang.reflect.Method.invoke(Method.java:597) > at = org.apache.axis.encoding.ser.BaseDeserializerFactory.getSpecialized(BaseDe= serializerFactory.java:154) > at = org.apache.axis.encoding.ser.BaseDeserializerFactory.getDeserializerAs(Bas= eDeserializerFactory.java:84) > at = org.apache.axis.encoding.DeserializationContext.getDeserializer(Deserializ= ationContext.java:464) > at = org.apache.axis.encoding.DeserializationContext.getDeserializerForType(Des= erializationContext.java:547) > at = org.apache.axis.message.SOAPFaultDetailsBuilder.onStartChild(SOAPFaultDeta= ilsBuilder.java:157) > at = org.apache.axis.encoding.DeserializationContext.startElement(Deserializati= onContext.java:1035) > at = org.apache.xerces.parsers.AbstractSAXParser.startElement(Unknown Source) > at = org.apache.xerces.impl.XMLNSDocumentScannerImpl.scanStartElement(Unknown = Source) > at = org.apache.xerces.impl.XMLDocumentFragmentScannerImpl$FragmentContentDispa= tcher.dispatch(Unknown Source) > at = org.apache.xerces.impl.XMLDocumentFragmentScannerImpl.scanDocument(Unknown= Source) > at org.apache.xerces.parsers.XML11Configuration.parse(Unknown = Source) > at org.apache.xerces.parsers.XML11Configuration.parse(Unknown = Source) > at org.apache.xerces.parsers.XMLParser.parse(Unknown Source) > at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown = Source) > at javax.xml.parsers.SAXParser.parse(SAXParser.java:395) > at = org.apache.axis.encoding.DeserializationContext.parse(DeserializationConte= xt.java:227) > at = org.apache.axis.SOAPPart.getAsSOAPEnvelope(SOAPPart.java:696) > at org.apache.axis.Message.getSOAPEnvelope(Message.java:435) > at = org.apache.axis.handlers.soap.MustUnderstandChecker.invoke(MustUnderstandC= hecker.java:62) > at = org.apache.axis.client.AxisClient.invoke(AxisClient.java:206) > at org.apache.axis.client.Call.invokeEngine(Call.java:2784) > at org.apache.axis.client.Call.invoke(Call.java:2767) > at org.apache.axis.client.Call.invoke(Call.java:2443) > at org.apache.axis.client.Call.invoke(Call.java:2366) > at org.apache.axis.client.Call.invoke(Call.java:1812) > at = com.vmware.vim25.VimBindingStub.importVApp(VimBindingStub.java:46658) > at = com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.importVmFromOVF(Hyperv= isorHostHelper.java:863) > at = com.cloud.hypervisor.vmware.mo.HostMO.importVmFromOVF(HostMO.java:681) > at = com.cloud.hypervisor.vmware.manager.VmwareStorageManagerImpl.copyTemplateF= romSecondaryToPrimary(VmwareStorageManagerImpl.java:459) > at = com.cloud.hypervisor.vmware.manager.VmwareStorageManagerImpl.execute(Vmwar= eStorageManagerImpl.java:138) > at = com.cloud.storage.resource.VmwareSecondaryStorageResourceHandler.execute(V= mwareSecondaryStorageResourceHandler.java:105) > at = com.cloud.storage.resource.VmwareSecondaryStorageResourceHandler.executeRe= quest(VmwareSecondaryStorageResourceHandler.java:69) > at = com.cloud.storage.resource.PremiumSecondaryStorageResource.executeRequest(= PremiumSecondaryStorageResource.java:54) > at com.cloud.agent.Agent.processRequest(Agent.java:525) > at = com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852) > at com.cloud.utils.nio.Task.run(Task.java:83) > at = java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.= java:886) > at = java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java= :908) > at java.lang.Thread.run(Thread.java:662) > 2013-12-03 15:26:53,448 DEBUG [cloud.agent.Agent] = (agentRequest-Handler-5:) Seq 30-428286227: { Ans: , MgmtId: = 90520730734904, via: 30, Ver: v1, Flags: 110, = [{"storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":false,= "details":"Unable to execute PrimaryStorageDownloadCommand due to = exception","wait":0}}] }