Mike, are you using CentOS7 packages or Ubuntu?
I would delete the /systemvm/systemvm-4.14.0.0.iso file (does it actually exist?) and restart mgmt server again (permissions on the "systemvm" folder should be 644) You can also verify being able to write as a "cloud" user to the mount point/systemvm/ folders with: runuser -l cloud -c 'touch <mountpoint/systemvm/test.file>' - if this fails then you do have some permissions issue, but this is most certainly caused by the NFS server / exports etc. What you are getting is weird - there should be no issues there - and everything should work smoothly. Andrija On Thu, 2 Jul 2020 at 20:31, Corey, Mike <mike.co...@sap.com> wrote: > No upgrade - this again is the fresh install of CloudStack 4.14 with > VMware resources. Maybe I should note that I created the primary and > secondary storage via the "Advanced" setup wizard from the UI (logged in as > admin). > > I performed the ownership change you suggested so now cloud owns the > systemvm folder on the secondary storage. However, now I'm getting a new > error regarding copying the ISO. > > Should I just bag the 4.14 installation and try to get 4.13.1 running with > VMware? > > > 2020-07-02 14:19:13,314 INFO [c.c.h.v.m.VmwareManagerImpl] > (DirectAgent-10:ctx-52902ebf usphlmvesxt155.phl.global.corp.sap, > job-15/job-33, cmd: StartCommand) (logid:b8ba37d1) Copy System VM patch ISO > file to secondary storage. source ISO: > /usr/share/cloudstack-common/vms/systemvm.iso, destination: > /var/cloudstack/mnt/VM/345050029058.777ecb60/systemvm/systemvm-4.14.0.0.iso > 2020-07-02 14:19:13,320 ERROR [c.c.h.v.m.VmwareManagerImpl] > (DirectAgent-10:ctx-52902ebf usphlmvesxt155.phl.global.corp.sap, > job-15/job-33, cmd: StartCommand) (logid:b8ba37d1) Unexpected exception > java.io.FileNotFoundException: > /var/cloudstack/mnt/VM/345050029058.777ecb60/systemvm/systemvm-4.14.0.0.iso > (Permission denied) > at java.base/java.io.FileOutputStream.open0(Native Method) > at java.base/java.io > .FileOutputStream.open(FileOutputStream.java:298) > at java.base/java.io > .FileOutputStream.<init>(FileOutputStream.java:237) > at java.base/java.io > .FileOutputStream.<init>(FileOutputStream.java:187) > at org.apache.commons.io.FileUtils.doCopyFile(FileUtils.java:1123) > at org.apache.commons.io.FileUtils.copyFile(FileUtils.java:1076) > at org.apache.commons.io.FileUtils.copyFile(FileUtils.java:1028) > at com.cloud.utils.FileUtil.copyfile(FileUtil.java:30) > at > com.cloud.hypervisor.vmware.manager.VmwareManagerImpl.prepareSecondaryStorageStore(VmwareManagerImpl.java:661) > at > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native > Method) > at > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) > at > java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > at java.base/java.lang.reflect.Method.invoke(Method.java:566) > at > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) > at > org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95) > at > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) > at > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) > at com.sun.proxy.$Proxy389.prepareSecondaryStorageStore(Unknown > Source) > at > com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:1962) > at > com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:530) > at > com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:315) > 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 > 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:834) > 2020-07-02 14:19:13,321 ERROR [c.c.h.v.m.VmwareManagerImpl] > (DirectAgent-10:ctx-52902ebf usphlmvesxt155.phl.global.corp.sap, > job-15/job-33, cmd: StartCommand) (logid:b8ba37d1) Unable to copy systemvm > ISO on secondary storage. src location: > /usr/share/cloudstack-common/vms/systemvm.iso, dest location: > /var/cloudstack/mnt/VM/345050029058.777ecb60/systemvm/systemvm-4.14.0.0.iso > 2020-07-02 14:19:13,322 INFO [c.c.h.v.u.VmwareHelper] > (DirectAgent-10:ctx-52902ebf usphlmvesxt155.phl.global.corp.sap, > job-15/job-33, cmd: StartCommand) (logid:b8ba37d1) [ignored]failed to get > message for exception: Unable to copy systemvm ISO on secondary storage. > src location: /usr/share/cloudstack-common/vms/systemvm.iso, dest location: > /var/cloudstack/mnt/VM/345050029058.777ecb60/systemvm/systemvm-4.14.0.0.iso > 2020-07-02 14:19:13,323 WARN [c.c.h.v.r.VmwareResource] > (DirectAgent-10:ctx-52902ebf usphlmvesxt155.phl.global.corp.sap, > job-15/job-33, cmd: StartCommand) (logid:b8ba37d1) StartCommand failed due > to Exception: com.cloud.utils.exception.CloudRuntimeException > Message: Unable to copy systemvm ISO on secondary storage. src location: > /usr/share/cloudstack-common/vms/systemvm.iso, dest location: > /var/cloudstack/mnt/VM/345050029058.777ecb60/systemvm/systemvm-4.14.0.0.iso > > > > > -----Original Message----- > From: Andrija Panic <andrija.pa...@gmail.com> > Sent: Thursday, July 2, 2020 12:34 PM > To: users <users@cloudstack.apache.org> > Subject: Re: Initial SystemVM Creation Failing > > Hi Mike, > > Mount you secondary storage on the management server to some temp folder, > then run: chown -R cloud:cloud <MOUNTPOINT>/systemvm/ > Other folders on Secondary Storage NFS are owned by root, but the > "systemvm" should be owned by "cloud". > > I assume you got this after some ACS upgrade, or similar? > > On Thu, 2 Jul 2020 at 15:51, Corey, Mike <mike.co...@sap.com> wrote: > > > Hi, > > > > > > > > When I enable the zone, the systemvm creation begins but goes into a loop > > of creating and deleting VMs in vCenter. I see in the logs there is an > > error for creating the folder permissions on the secondary storage (see > > below). Running this CHMOD manually from inside the CSM kicks the same > > error. > > > > > > > > Please provide suggestions. > > > > > > > > 2020-07-02 09:08:39,665 DEBUG [c.c.h.v.m.VmwareManagerImpl] > > (DirectAgent-66:ctx-e15c32b2 usphlmvesxt154.phl.global.corp.sap, > > job-16/job-35, cmd: CopyCommand) (logid:1cfa64a9) Executing: sudo chmod > > 1777 /var/cloudstack/mnt/VM/345050029058.2807345c > > > > 2020-07-02 09:08:39,666 DEBUG [c.c.h.v.m.VmwareManagerImpl] > > (DirectAgent-66:ctx-e15c32b2 usphlmvesxt154.phl.global.corp.sap, > > job-16/job-35, cmd: CopyCommand) (logid:1cfa64a9) Executing while with > > timeout : 1440000 > > > > 2020-07-02 09:08:39,693 DEBUG [c.c.h.v.m.VmwareManagerImpl] > > (DirectAgent-66:ctx-e15c32b2 usphlmvesxt154.phl.global.corp.sap, > > job-16/job-35, cmd: CopyCommand) (logid:1cfa64a9) Exit value is 1 > > > > 2020-07-02 09:08:39,697 DEBUG [c.c.h.v.m.VmwareManagerImpl] > > (DirectAgent-66:ctx-e15c32b2 usphlmvesxt154.phl.global.corp.sap, > > job-16/job-35, cmd: CopyCommand) (logid:1cfa64a9) chmod: changing > > permissions of ‘/var/cloudstack/mnt/VM/345050029058.2807345c’: Operation > > not permitted > > > > 2020-07-02 09:08:39,699 WARN [c.c.h.v.m.VmwareManagerImpl] > > (DirectAgent-66:ctx-e15c32b2 usphlmvesxt154.phl.global.corp.sap, > > job-16/job-35, cmd: CopyCommand) (logid:1cfa64a9) Unable to set > permissions > > for /var/cloudstack/mnt/VM/345050029058.2807345c due to chmod: changing > > permissions of ‘/var/cloudstack/mnt/VM/345050029058.2807345c’: Operation > > not permitted > > > > > > > > Lines… > > > > > > > > 2020-07-02 09:09:00,598 DEBUG [c.c.h.v.m.HostMO] > > (DirectAgent-17:ctx-681dc524 usphlmvesxt154.phl.global.corp.sap, > > job-16/job-35, cmd: StartCommand) (logid:1cfa64a9) find VM v-2-VM on host > > > > 2020-07-02 09:09:00,598 INFO [c.c.h.v.m.HostMO] > > (DirectAgent-17:ctx-681dc524 usphlmvesxt154.phl.global.corp.sap, > > job-16/job-35, cmd: StartCommand) (logid:1cfa64a9) VM v-2-VM not found in > > host cache > > > > 2020-07-02 09:09:00,598 DEBUG [c.c.h.v.m.HostMO] > > (DirectAgent-17:ctx-681dc524 usphlmvesxt154.phl.global.corp.sap, > > job-16/job-35, cmd: StartCommand) (logid:1cfa64a9) load VM cache on host > > > > 2020-07-02 09:09:00,616 DEBUG [c.c.h.v.m.HostMO] > > (DirectAgent-17:ctx-681dc524 usphlmvesxt154.phl.global.corp.sap, > > job-16/job-35, cmd: StartCommand) (logid:1cfa64a9) find VM v-2-VM on host > > > > 2020-07-02 09:09:00,617 DEBUG [c.c.h.v.m.HostMO] > > (DirectAgent-17:ctx-681dc524 usphlmvesxt154.phl.global.corp.sap, > > job-16/job-35, cmd: StartCommand) (logid:1cfa64a9) VM v-2-VM found in > host > > cache > > > > 2020-07-02 09:09:00,799 ERROR [c.c.h.v.m.VmwareManagerImpl] > > (DirectAgent-17:ctx-681dc524 usphlmvesxt154.phl.global.corp.sap, > > job-16/job-35, cmd: StartCommand) (logid:1cfa64a9) Unable to create > > systemvm folder on secondary storage. location: > > /var/cloudstack/mnt/VM/345050029058.2807345c/systemvm > > > > 2020-07-02 09:09:00,800 INFO [c.c.h.v.u.VmwareHelper] > > (DirectAgent-17:ctx-681dc524 usphlmvesxt154.phl.global.corp.sap, > > job-16/job-35, cmd: StartCommand) (logid:1cfa64a9) [ignored]failed to get > > message for exception: Unable to create systemvm folder on secondary > > storage. location: /var/cloudstack/mnt/VM/345050029058.2807345c/systemvm > > > > 2020-07-02 09:09:00,800 WARN [c.c.h.v.r.VmwareResource] > > (DirectAgent-17:ctx-681dc524 usphlmvesxt154.phl.global.corp.sap, > > job-16/job-35, cmd: StartCommand) (logid:1cfa64a9) StartCommand failed > due > > to Exception: com.cloud.utils.exception.CloudRuntimeException > > > > Message: Unable to create systemvm folder on secondary storage. location: > > /var/cloudstack/mnt/VM/345050029058.2807345c/systemvm > > > > > > > > com.cloud.utils.exception.CloudRuntimeException: Unable to create > systemvm > > folder on secondary storage. location: > > /var/cloudstack/mnt/VM/345050029058.2807345c/systemvm > > > > at > > > com.cloud.hypervisor.vmware.manager.VmwareManagerImpl.prepareSecondaryStorageStore(VmwareManagerImpl.java:648) > > > > at > > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native > > Method) > > > > at > > > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) > > > > at > > > java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) > > > > at java.base/java.lang.reflect.Method.invoke(Method.java:566) > > > > at > > > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) > > > > at > > > org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) > > > > at > > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) > > > > at > > > org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95) > > > > at > > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) > > > > at > > > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) > > > > at > > com.sun.proxy.$Proxy389.prepareSecondaryStorageStore(Unknown Source) > > > > at > > > com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:1962) > > > > at > > > com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:530) > > > > at > > > com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:315) > > > > 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 > > > 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:834) > > > > 2020-07-02 09:09:00,804 DEBUG [c.c.a.m.DirectAgentAttache] > > (DirectAgent-17:ctx-681dc524) (logid:1cfa64a9) Seq 1-4541880224203147245: > > Cancelling because one of the answers is false and it is stop on error. > > > > 2020-07-02 09:09:00,804 DEBUG [c.c.a.m.DirectAgentAttache] > > (DirectAgent-17:ctx-681dc524) (logid:1cfa64a9) Seq 1-4541880224203147245: > > Response Received: > > > > 2020-07-02 09:09:00,805 DEBUG [c.c.a.t.Request] > > (DirectAgent-17:ctx-681dc524) (logid:1cfa64a9) Seq 1-4541880224203147245: > > Processing: { Ans: , MgmtId: 345050029058, via: > > 1(usphlmvesxt154.phl.global.corp.sap), Ver: v1, Flags: 110, > > > [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":2,"name":"v-2-VM","bootloader":"HVM","state":"Starting","type":"ConsoleProxy","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":1073741824,"maxRam":1073741824,"hostName":"v-2-VM","arch":"x86_64","os":"Other > > Linux (64-bit)","platformEmulator":"otherLinux64Guest","bootArgs":" > > template=domP type=consoleproxy host=10.4.32.163 port=8250 name=v-2-VM > > zone=1 pod=1 guid=Proxy.2 proxy_vm=2 disable_rp_filter=true > > eth2ip=10.4.42.25 eth2mask=255.255.255.192 gateway=10.4.42.1 > eth0ip=0.0.0.0 > > eth0mask=0.0.0.0 eth1ip=10.4.4.35 eth1mask=255.255.252.0 mgmtcidr= > > 10.4.32.0/24 localgw=10.4.4.1 internaldns1=10.4.202.200 > dns1=10.4.202.200 > > > dns2=10.4.12.200","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"sYnwDJYgzrMKdm3ftAO-kg","params":{"vmware.reserve.mem":"false","vmware.reserve.cpu":"false","nicAdapter":"E1000"},"uuid":"fb65df73-693d-48fb-a203-c2b5e776842a","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9a1f2ae8-6b10-4525-8a54-a175b153b789","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"50cc970f-fbe2-3b45-9cb5-b8bcdb6dbff5","id":1,"poolType":"NetworkFilesystem","host":"usphlcv300.phl.global.corp.sap","path":"/usphlmvesx_lab_cspri","port":2049,"url":"NetworkFilesystem://usphlcv300.phl.global.corp.sap/usphlmvesx_lab_cspri/?ROLE=Primary&STOREUUID=50cc970f-fbe2-3b45-9cb5-b8bcdb6dbff5","isManaged":false}},"name":"ROOT-2","size":0,"path":"ROOT-2_2","volumeId":2,"vmName":"v-2-VM","accountId":1,"format":"OVA","provisioningType":"THIN","id":2,"deviceId":0,"bytesReadRate":0,"bytesWriteRate":0,"iopsReadRate":0,"iopsWriteRate":0,"hypervisorType":"VMware","directDownload":false}},"diskSeq":0,"path":"ROOT-2_2","type":"ROOT","_details":{"storageHost":"usphlcv300.phl.global.corp.sap","managed":"false","storagePort":"2049","volumeSize":"0"}}],"nics":[{"deviceId":2,"networkRateMbps":-1,"defaultNic":true,"pxeDisable":true,"nicUuid":"ffbc1822-7907-4cdf-9e80-bb316786e04d","details":{"PromiscuousMode":"false","MacAddressChanges":"true","ForgedTransmits":"true"},"dpdkEnabled":false,"uuid":"f3a30021-a469-413d-85a8-ca1ca68ba27c","ip":"10.4.42.25","netmask":"255.255.255.192","gateway":"10.4.42.1","mac":"1e:00:e3:00:00:19","dns1":"10.4.202.200","dns2":"10.4.12.200","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://untagged","isolationUri":"vlan://untagged","isSecurityGroupEnabled":false,"name":"vSwitch0,134,vmwaresvs"},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"d6521be0-85b8-4836-bf8b-8461afdf593a","details":{"PromiscuousMode":"false","MacAddressChanges":"true","ForgedTransmits":"true"},"dpdkEnabled":false,"uuid":"eda0ae3d-d15d-4f91-b8db-a719cf5a94bf","mac":"02:00:31:71:00:02","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false,"name":"vSwitch0,146,vmwaresvs"},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true,"nicUuid":"4e6201ad-91c0-4cab-bf53-9e2440025245","details":{"PromiscuousMode":"false","MacAddressChanges":"true","ForgedTransmits":"true"},"dpdkEnabled":false,"uuid":"ce88b030-c04c-4437-b60d-9910c2cc376f","ip":"10.4.4.35","netmask":"255.255.252.0","gateway":"10.4.4.1","mac":"1e:00:6b:00:00:27","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"vSwitch0,146,vmwaresvs"}],"guestOsDetails":{},"extraConfig":{}},"result":false,"details":"StartCommand > > failed due to Exception: > > com.cloud.utils.exception.CloudRuntimeException\nMessage: Unable to > create > > systemvm folder on secondary storage. location: > > /var/cloudstack/mnt/VM/345050029058.2807345c/systemvm\n","wait":0}}] } > > > > 2020-07-02 09:09:00,805 DEBUG [c.c.a.m.AgentAttache] > > (DirectAgent-17:ctx-681dc524) (logid:1cfa64a9) Seq 1-4541880224203147245: > > No more commands found > > > > 2020-07-02 09:09:00,806 DEBUG [c.c.a.t.Request] > > (Work-Job-Executor-2:ctx-9aa38618 job-16/job-35 ctx-7ebd1b78) > > (logid:1cfa64a9) Seq 1-4541880224203147245: Received: { Ans: , MgmtId: > > 345050029058, via: 1(usphlmvesxt154.phl.global.corp.sap), Ver: v1, Flags: > > 110, { StartAnswer } } > > > > 2020-07-02 09:09:00,816 INFO [c.c.v.VirtualMachineManagerImpl] > > (Work-Job-Executor-2:ctx-9aa38618 job-16/job-35 ctx-7ebd1b78) > > (logid:1cfa64a9) Unable to start VM on Host[-1-Routing] due to > StartCommand > > failed due to Exception: com.cloud.utils.exception.CloudRuntimeException > > > > Message: Unable to create systemvm folder on secondary storage. location: > > /var/cloudstack/mnt/VM/345050029058.2807345c/systemvm > > > > > > > > *Mike Corey* > > > > > > Technology Senior Consultant, IT CS CTW Operation & Virtualization > Service > > US > > > > > > *SAP AMERICA, INC.* 3999 West Chester Pike, Newtown Square, 19073 United > > States > > > > > > T +1 610 661 0905, M +1 484 274 2658, E mike.co...@sap.com > > > > > > > > > > > > > > > > > -- > > Andrija Panić > -- Andrija Panić