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ć
