From users-return-34624-archive-asf-public=cust-asf.ponee.io@cloudstack.apache.org Fri Jul 10 16:30:21 2020 Return-Path: X-Original-To: archive-asf-public@cust-asf.ponee.io Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [207.244.88.153]) by mx-eu-01.ponee.io (Postfix) with SMTP id 08F6218065B for ; Fri, 10 Jul 2020 18:30:20 +0200 (CEST) Received: (qmail 83249 invoked by uid 500); 10 Jul 2020 16:30:20 -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 83232 invoked by uid 99); 10 Jul 2020 16:30:19 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd3-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 10 Jul 2020 16:30:19 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd3-us-west.apache.org (ASF Mail Server at spamd3-us-west.apache.org) with ESMTP id 780EA181404 for ; Fri, 10 Jul 2020 16:30:18 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd3-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: 0.973 X-Spam-Level: X-Spam-Status: No, score=0.973 tagged_above=-999 required=6.31 tests=[DKIM_SIGNED=0.1, DKIM_VALID=-0.1, RCVD_IN_DNSWL_NONE=-0.0001, RCVD_IN_MSPIKE_H2=-0.001, SPF_HELO_NONE=0.001, SPF_SOFTFAIL=0.972, URIBL_BLOCKED=0.001] autolearn=disabled Authentication-Results: spamd3-us-west.apache.org (amavisd-new); dkim=pass (2048-bit key) header.d=istream-today.20150623.gappssmtp.com Received: from mx1-ec2-va.apache.org ([10.40.0.8]) by localhost (spamd3-us-west.apache.org [10.40.0.10]) (amavisd-new, port 10024) with ESMTP id X5M8GAs3oypU for ; Fri, 10 Jul 2020 16:30:15 +0000 (UTC) Received-SPF: Softfail (mailfrom) identity=mailfrom; client-ip=209.85.208.43; helo=mail-ed1-f43.google.com; envelope-from=cristian.c@istream.today; receiver= Received: from mail-ed1-f43.google.com (mail-ed1-f43.google.com [209.85.208.43]) by mx1-ec2-va.apache.org (ASF Mail Server at mx1-ec2-va.apache.org) with ESMTPS id 689D1BE304 for ; Fri, 10 Jul 2020 16:30:14 +0000 (UTC) Received: by mail-ed1-f43.google.com with SMTP id n2so5149924edr.5 for ; Fri, 10 Jul 2020 09:30:14 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=istream-today.20150623.gappssmtp.com; s=20150623; h=from:to:references:in-reply-to:subject:date:message-id:mime-version :content-transfer-encoding:thread-index:content-language; bh=Kf2V3piTQyjCICLiTtSdJ6QLnGFX5y+U0lwgURK+6t4=; b=OFx3UOZsBw+UyKi+oc8oAfSG8eR6ODE4KRF4zqopib4RX/4gprON+U5AgZ04J50uKe 6NHBZw4eyBmqZ1I2HjawYUIHdzmneg1bmxc7ms64X30cBI6N4eX4gEFrMq8xF1UODrDU QP7ay5JPCeRkv/oA1OlysHeg/ask9sN+dwg0u3/GXZJwOSt1u/k+0gu0ikAAaYiCa3nW Hi/zVwnR2rRxxvaiyqyEY8FLmECcaxBFRwIo4lEVnxzAe7iAkxXSnLdXz4LDbXdulmX8 0kihNzZouTrI3n4DAhBUnrF/xOWIDaS88pkYCo/uRderI04FuYo3VQN75++Qx7k4JHe5 zFlg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:from:to:references:in-reply-to:subject:date :message-id:mime-version:content-transfer-encoding:thread-index :content-language; bh=Kf2V3piTQyjCICLiTtSdJ6QLnGFX5y+U0lwgURK+6t4=; b=h/e9A8bD0vZVFviPPWFwarCvn4cdyQoVg7XXwGW6owFrFt4ZEiltOQFr1WZXpi0GnE tv/iEFdmXgdnKIsUqJqaxyRKupQTQ8B5H1DSmRngUXjf+mRQ3i06VBBaoYdhcm+84TNm iQejF4xqvrth5ykGNM0kD5XNVkqqzVqbg36VYosyq16q4NhCimCM9ioOIg79y8LiW34N qugqrUAovdUWYOw4kyc4q5ovGrlBR+uYDBPWmwGdk9kMQUC6+k5/nMwcBCIRtLaDYfVf 1e45R7zoInGmLOLzfn7zVU7yfEkPa7Lzd69rrfKmX9CpfUxNSjDSKVKlNgLRDNRbIQBY G+6A== X-Gm-Message-State: AOAM5338il6LgiQkH4nvGFSV4DtnFdbSYx16IAkFNnyktxIhiX9gMQps Jt5QioyJM8qaD76uJVVfU7qwCUVEDRIcZg== X-Google-Smtp-Source: ABdhPJxlqTbnvYFbarJRuuFO+BHWNAROeUONlX38P4OdUbXSrUEbAupPALF+SDkRNcmoFyEUrcF42g== X-Received: by 2002:a05:6402:1d97:: with SMTP id dk23mr79607266edb.1.1594398607309; Fri, 10 Jul 2020 09:30:07 -0700 (PDT) Received: from DESKTOPHPDKODH ([79.113.72.62]) by smtp.gmail.com with ESMTPSA id rv16sm3984916ejb.60.2020.07.10.09.30.06 for (version=TLS1_2 cipher=ECDHE-ECDSA-AES128-GCM-SHA256 bits=128/128); Fri, 10 Jul 2020 09:30:06 -0700 (PDT) From: To: References: In-Reply-To: Subject: RE: Initial SystemVM Creation Failing Date: Fri, 10 Jul 2020 19:30:04 +0300 Message-ID: <010f01d656d7$5e248f60$1a6dae20$@istream.today> MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: quoted-printable X-Mailer: Microsoft Outlook 16.0 Thread-Index: AQJHD62zt4ud/TCgVBK4afz+XnV1PAJ1sPQyAWby7OgBo1d0vgIB8lESAZz3QcGn1pessA== Content-Language: en-us Hello If you check your NFS configuration you will see that somewhere you = have : /etc/idmapd.conf "nobody" Regards, Cristian =20 -----Original Message----- From: Corey, Mike =20 Sent: Friday, July 10, 2020 7:01 PM To: users@cloudstack.apache.org Subject: RE: Initial SystemVM Creation Failing The system VM folder is being created as owner & permissions = nobody:nobody. I have to believe that is NOT SUPPOSED to be the case. Because the directory /var/cloudstack/mnt/VM/345050029058.4f87a734 is = locked down, no other steps in the systemvm creation can continue. I need help figuring out WHY the systemVM folder in the above directory = is being created as nobody:nobody. =20 I can't chown that directory once CloudStack creates it during the zone = enablement. I can't modify the permissions to that directory once = CloudStack creates it during the zone enablement. I can't copy files to = that directory once CloudStack creates it during the zone enablement. Please identify what is occurring during the creation of the systemvm = directory that would cause the ownership to be set as nobody:nobody. Mike 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.4f87a734/systemvm/systemvm-4.14.0.0.i= so [root@usphlmvcsmt01 VM]# pwd /var/cloudstack/mnt/VM [root@usphlmvcsmt01 VM]# ls -al total 80864 drwxr-xr-x. 3 cloud cloud 55 Jul 10 11:46 . drwxrwx---. 3 root cloud 16 Jul 9 14:40 .. drwxr-xr-x. 5 nobody nobody 4096 Jul 10 11:31 345050029058.4f87a734 -rw-r--r--. 1 cloud cloud 82800640 Jul 10 11:43 systemvm.iso -----Original Message----- From: Cristian Ciobanu Sent: Friday, July 10, 2020 5:26 AM To: users@cloudstack.apache.org Subject: Re: Initial SystemVM Creation Failing Just try to execute the command manually, copy the system.iso from = source to the destination. I had a similar issue but is was caused by = the NFS permissions. On Wed, 8 Jul 2020, 21:44 Corey, Mike, wrote: > Gone over the installation now twice (reverted to snapshot of CentOS=20 > VM) and still getting weird storage/permission type issues. > > The permissions and ownership of the systemvm folder looks correct. > [root@ ~]# ls -al /mnt/secondary/ > total 16 > drwxr-xr-x. 4 root root 4096 Jul 8 11:15 . > drwxr-xr-x. 4 root root 38 Jul 8 11:15 .. > drwxrwxrwx. 12 root root 4096 Jul 8 11:05 .snapshot > drwxrwxr-x. 2 cloud cloud 4096 Jul 8 10:58 systemvm > drwxr-xr-x. 3 root root 4096 Jul 8 11:15 template > > However, I'm still seeing the copy iso error and the VMs keep creating = > and deleting with the log suggesting the vmx file of the VM doesn't=20 > exist on the datastore (can create files/folder on datastore=20 > identified in errror from vCenter). > > 2020-07-08 14:22:36,486 INFO [c.c.h.v.m.DatastoreMO] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Folder v-6-VM does=20 > not exist on datastore > 2020-07-08 14:22:36,494 INFO [c.c.h.v.m.DatastoreMO] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Search file=20 > v-6-VM.vmx on [50cc970ffbe23b459cb5b8bcdb6dbff5] > 2020-07-08 14:22:36,522 INFO [c.c.h.v.m.DatastoreMO] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) File=20 > [50cc970ffbe23b459cb5b8bcdb6dbff5] v-6-VM.vmx does not exist on=20 > datastore > 2020-07-08 14:22:36,522 INFO [c.c.h.v.m.DatastoreMO] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Searching file=20 > v-6-VM.vmx in [50cc970ffbe23b459cb5b8bcdb6dbff5] > 2020-07-08 14:22:36,641 INFO [c.c.h.v.m.HypervisorHostHelper] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Create blank VM. > cpuCount: 1, cpuSpeed(MHz): 500, mem(Mb): 1024 > 2020-07-08 14:22:36,692 DEBUG [c.c.h.v.m.ClusterMO] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Retrieved=20 > recommended disk controller for guest OS : otherLinux64Guest in = cluster PHL-CSM01 : > VirtualLsiLogicController > 2020-07-08 14:22:37,115 DEBUG [c.c.h.v.m.HostMO] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) find VM v-6-VM on=20 > host > 2020-07-08 14:22:37,115 INFO [c.c.h.v.m.HostMO] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) VM v-6-VM not found=20 > in host cache > 2020-07-08 14:22:37,115 DEBUG [c.c.h.v.m.HostMO] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) load VM cache on=20 > host > 2020-07-08 14:22:37,155 DEBUG [c.c.h.v.m.HostMO] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) find VM v-6-VM on=20 > host > 2020-07-08 14:22:37,155 DEBUG [c.c.h.v.m.HostMO] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) VM v-6-VM found in=20 > host cache > 2020-07-08 14:22:37,375 INFO [c.c.h.v.m.VmwareManagerImpl] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Inject SSH key pairs = > before copying systemvm.iso into secondary storage > 2020-07-08 14:22:37,377 INFO [c.c.s.ConfigurationServerImpl] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Processing=20 > updateKeyPairs > 2020-07-08 14:22:37,377 INFO [c.c.s.ConfigurationServerImpl] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Keypairs already in=20 > database, updating local copy > 2020-07-08 14:22:37,381 INFO [c.c.s.ConfigurationServerImpl] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Going to update=20 > systemvm iso with generated keypairs if needed > 2020-07-08 14:22:37,381 INFO [c.c.s.ConfigurationServerImpl] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Trying to inject=20 > public and private keys into systemvm iso > 2020-07-08 14:22:37,381 DEBUG [c.c.u.s.Script] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Looking for=20 > scripts/vm/systemvm/injectkeys.sh in the classpath > 2020-07-08 14:22:37,381 DEBUG [c.c.u.s.Script] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) System resource: > file:/usr/share/cloudstack-common/scripts/vm/systemvm/injectkeys.sh > 2020-07-08 14:22:37,381 DEBUG [c.c.u.s.Script] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Absolute path =3D=20 > /usr/share/cloudstack-common/scripts/vm/systemvm/injectkeys.sh > 2020-07-08 14:22:37,381 DEBUG [c.c.u.s.Script] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Looking for=20 > vms/systemvm.iso in the classpath > 2020-07-08 14:22:37,381 DEBUG [c.c.u.s.Script] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) System resource: > file:/usr/share/cloudstack-common/vms/systemvm.iso > 2020-07-08 14:22:37,381 DEBUG [c.c.u.s.Script] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Absolute path =3D=20 > /usr/share/cloudstack-common/vms/systemvm.iso > 2020-07-08 14:22:37,381 DEBUG [c.c.s.ConfigurationServerImpl] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Executing: /bin/bash = > /usr/share/cloudstack-common/scripts/vm/systemvm/injectkeys.sh > /var/cloudstack/management/.ssh/id_rsa.pub > /var/cloudstack/management/.ssh/id_rsa > /usr/share/cloudstack-common/vms/systemvm.iso > 2020-07-08 14:22:37,384 DEBUG [c.c.s.ConfigurationServerImpl] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Executing while with = > timeout : 3600000 > 2020-07-08 14:22:37,487 DEBUG [c.c.s.ConfigurationServerImpl] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Execution is = successful. > 2020-07-08 14:22:37,494 DEBUG [c.c.s.ConfigurationServerImpl] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) mount: /dev/loop0 is = > write-protected, mounting read-only New public key is the same as the=20 > one in the systemvm.iso, not injecting it, not modifying systemvm.iso > > 2020-07-08 14:22:37,494 INFO [c.c.s.ConfigurationServerImpl] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) The script=20 > injectkeys.sh was run with result : null > 2020-07-08 14:22:37,494 INFO [c.c.h.v.m.VmwareManagerImpl] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Copy System VM patch = > ISO file to secondary storage. source ISO: > /usr/share/cloudstack-common/vms/systemvm.iso, destination: > /var/cloudstack/mnt/VM/345050029058.1f7af2bf/systemvm/systemvm-4.14.0. > 0.iso > 2020-07-08 14:22:37,495 ERROR [c.c.h.v.m.VmwareManagerImpl] > (DirectAgent-51:ctx-7e6d5dc9 usphlmvesxt155.phl.global.corp.sap, > job-6/job-37, cmd: StartCommand) (logid:b828ac16) Unexpected exception > java.io.FileNotFoundException: > /var/cloudstack/mnt/VM/345050029058.1f7af2bf/systemvm/systemvm-4.14.0. > 0.iso > (Permission denied) > > But, the ownership/permissions look okay on that destination directory = too. > > [root@ ~]# ls -al /var/cloudstack/mnt/VM/345050029058.1f7af2bf > total 12 > drwxr-xr-x. 4 nobody nobody 4096 Jul 8 11:15 . > drwxr-xr-x. 3 cloud cloud 35 Jul 8 14:06 .. > drwxrwxr-x. 2 cloud cloud 4096 Jul 8 10:58 systemvm drwxr-xr-x. 3=20 > nobody nobody 4096 Jul 8 11:15 template > [root@usphlmvcsmt01 ~]# > > > Any ideas? > > > -----Original Message----- > From: Corey, Mike > Sent: Thursday, July 2, 2020 2:31 PM > To: users@cloudstack.apache.org > Subject: RE: Initial SystemVM Creation Failing > > No upgrade - this again is the fresh install of CloudStack 4.14 with=20 > VMware resources. Maybe I should note that I created the primary and=20 > secondary storage via the "Advanced" setup wizard from the UI (logged=20 > in as admin). > > I performed the ownership change you suggested so now cloud owns the=20 > systemvm folder on the secondary storage. However, now I'm getting a=20 > new error regarding copying the ISO. > > Should I just bag the 4.14 installation and try to get 4.13.1 running=20 > with VMware? > > > 2020-07-02 14:19:13,314 INFO [c.c.h.v.m.VmwareManagerImpl]=20 > (DirectAgent-10:ctx-52902ebf usphlmvesxt155.phl.global.corp.sap, > job-15/job-33, cmd: StartCommand) (logid:b8ba37d1) Copy System VM=20 > 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]=20 > (DirectAgent-10:ctx-52902ebf usphlmvesxt155.phl.global.corp.sap, > job-15/job-33, cmd: StartCommand) (logid:b8ba37d1) Unexpected=20 > 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.(FileOutputStream.java:237) > at java.base/java.io > .FileOutputStream.(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.prepareSecondarySto= rageStore(VmwareManagerImpl.java:661) > at > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native > Method) > at > = java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMeth= odAccessorImpl.java:62) > at > = java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Delega= tingMethodAccessorImpl.java:43) > at java.base/java.lang.reflect.Method.invoke(Method.java:566) > at > = org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(A= opUtils.java:344) > at > = org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpo= int(ReflectiveMethodInvocation.java:198) > at > = org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Refl= ectiveMethodInvocation.java:163) > at > = org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(Ex= poseInvocationInterceptor.java:95) > at > = org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(Refl= ectiveMethodInvocation.java:186) > at > = org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAop= Proxy.java:212) > at=20 > com.sun.proxy.$Proxy389.prepareSecondaryStorageStore(Unknown > Source) > at > = com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResourc= e.java:1962) > at > = com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(Vmware= Resource.java:530) > at > = com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentA= ttache.java:315) > at > = org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Manage= dContextRunnable.java:49) > at > = org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(D= efaultManagedContext.java:56) > at > = org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWith= Context(DefaultManagedContext.java:103) > at > = org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithC= ontext(DefaultManagedContext.java:53) > at > = org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedC= ontextRunnable.java:46) > at > = java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.j= ava:515) > at > java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) > at > = java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutur= eTask.run(ScheduledThreadPoolExecutor.java:304) > at > = java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExe= cutor.java:1128) > at > = java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolEx= ecutor.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]=20 > (DirectAgent-10:ctx-52902ebf usphlmvesxt155.phl.global.corp.sap, > job-15/job-33, cmd: StartCommand) (logid:b8ba37d1) Unable to copy=20 > 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]=20 > (DirectAgent-10:ctx-52902ebf usphlmvesxt155.phl.global.corp.sap, > job-15/job-33, cmd: StartCommand) (logid:b8ba37d1) [ignored]failed to=20 > 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]=20 > (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 > Sent: Thursday, July 2, 2020 12:34 PM > To: users > 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 /systemvm/ > Other folders on Secondary Storage NFS are owned by root, but the=20 > "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 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=20 > > there is an error for creating the folder permissions on the=20 > > secondary storage (see below). Running this CHMOD manually from=20 > > 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=20 > > 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=20 > > 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=20 > > permissions of = =E2=80=98/var/cloudstack/mnt/VM/345050029058.2807345c=E2=80=99:=20 > > 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:=20 > > changing permissions of=20 > > =E2=80=98/var/cloudstack/mnt/VM/345050029058.2807345c=E2=80=99: = Operation not=20 > > permitted > > > > > > > > Lines=E2=80=A6 > > > > > > > > 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=20 > > 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=20 > > 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=20 > > 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=20 > > 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=20 > > to get message for exception: Unable to create systemvm folder on=20 > > secondary storage. location:=20 > > /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=20 > > 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.prepareSecondary > StorageStore(VmwareManagerImpl.java:648) > > > > at > > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Nati > > ve > > Method) > > > > at > > > java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeM > ethodAccessorImpl.java:62) > > > > at > > > java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Del > egatingMethodAccessorImpl.java:43) > > > > at=20 > > java.base/java.lang.reflect.Method.invoke(Method.java:566) > > > > at > > > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflectio > n(AopUtils.java:344) > > > > at > > > org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoi > npoint(ReflectiveMethodInvocation.java:198) > > > > at > > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(R > eflectiveMethodInvocation.java:163) > > > > at > > > org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke > (ExposeInvocationInterceptor.java:95) > > > > at > > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(R > eflectiveMethodInvocation.java:186) > > > > at > > > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamic > AopProxy.java:212) > > > > at > > com.sun.proxy.$Proxy389.prepareSecondaryStorageStore(Unknown Source) > > > > at > > > com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareReso > urce.java:1962) > > > > at > > > com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(Vmw > areResource.java:530) > > > > at > > > com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAge > ntAttache.java:315) > > > > at > > > org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(Man > agedContextRunnable.java:49) > > > > at > > > org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.cal > l(DefaultManagedContext.java:56) > > > > at > > > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callW > ithContext(DefaultManagedContext.java:103) > > > > at > > > org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWi > thContext(DefaultManagedContext.java:53) > > > > at > > > org.apache.cloudstack.managed.context.ManagedContextRunnable.run(Manag > edContextRunnable.java:46) > > > > at > > > java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executor > s.java:515) > > > > at > > java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) > > > > at > > > java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu > tureTask.run(ScheduledThreadPoolExecutor.java:304) > > > > at > > > java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool > Executor.java:1128) > > > > at > > > java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo > lExecutor.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","boo > tloader":"HVM","state":"Starting","type":"ConsoleProxy","cpus":1,"minS > peed":500,"maxSpeed":500,"minRam":1073741824,"maxRam":1073741824,"host > Name":"v-2-VM","arch":"x86_64","os":"Other > > Linux (64-bit)","platformEmulator":"otherLinux64Guest","bootArgs":" > > template=3DdomP type=3Dconsoleproxy host=3D10.4.32.163 port=3D8250=20 > > name=3Dv-2-VM > > zone=3D1 pod=3D1 guid=3DProxy.2 proxy_vm=3D2 = disable_rp_filter=3Dtrue > > eth2ip=3D10.4.42.25 eth2mask=3D255.255.255.192 gateway=3D10.4.42.1 > eth0ip=3D0.0.0.0 > > eth0mask=3D0.0.0.0 eth1ip=3D10.4.4.35 eth1mask=3D255.255.252.0 = mgmtcidr=3D > > 10.4.32.0/24 localgw=3D10.4.4.1 internaldns1=3D10.4.202.200 > dns1=3D10.4.202.200 > > > = dns2=3D10.4.12.200","enableHA":false,"limitCpuUse":false,"enableDynamica > llyScaleVm":false,"vncPassword":"sYnwDJYgzrMKdm3ftAO-kg","params":{"vm > ware.reserve.mem":"false","vmware.reserve.cpu":"false","nicAdapter":"E > 1000"},"uuid":"fb65df73-693d-48fb-a203-c2b5e776842a","disks":[{"data": > {"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9a1f2ae8-6 > b10-4525-8a54-a175b153b789","volumeType":"ROOT","dataStore":{"org.apac > he.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"50cc970f-fbe2-3b > 45-9cb5-b8bcdb6dbff5","id":1,"poolType":"NetworkFilesystem","host":"us > phlcv300.phl.global.corp.sap","path":"/usphlmvesx_lab_cspri","port":20 > 49,"url":"NetworkFilesystem://usphlcv300.phl.global.corp.sap/usphlmves > = x_lab_cspri/?ROLE=3DPrimary&STOREUUID=3D50cc970f-fbe2-3b45-9cb5-b8bcdb6db= f > f5","isManaged":false}},"name":"ROOT-2","size":0,"path":"ROOT-2_2","vo > lumeId":2,"vmName":"v-2-VM","accountId":1,"format":"OVA","provisioning > Type":"THIN","id":2,"deviceId":0,"bytesReadRate":0,"bytesWriteRate":0, > "iopsReadRate":0,"iopsWriteRate":0,"hypervisorType":"VMware","directDo > wnload":false}},"diskSeq":0,"path":"ROOT-2_2","type":"ROOT","_details" > :{"storageHost":"usphlcv300.phl.global.corp.sap","managed":"false","st > oragePort":"2049","volumeSize":"0"}}],"nics":[{"deviceId":2,"networkRa > teMbps":-1,"defaultNic":true,"pxeDisable":true,"nicUuid":"ffbc1822-790 > 7-4cdf-9e80-bb316786e04d","details":{"PromiscuousMode":"false","MacAdd > ressChanges":"true","ForgedTransmits":"true"},"dpdkEnabled":false,"uui > d":"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","dns > 1":"10.4.202.200","dns2":"10.4.12.200","broadcastType":"Vlan","type":" > Public","broadcastUri":"vlan://untagged","isolationUri":"vlan://untagg > ed","isSecurityGroupEnabled":false,"name":"vSwitch0,134,vmwaresvs"},{" > deviceId":0,"networkRateMbps":-1,"defaultNic":false,"pxeDisable":true, > "nicUuid":"d6521be0-85b8-4836-bf8b-8461afdf593a","details":{"Promiscuo > usMode":"false","MacAddressChanges":"true","ForgedTransmits":"true"}," > dpdkEnabled":false,"uuid":"eda0ae3d-d15d-4f91-b8db-a719cf5a94bf","mac" > :"02:00:31:71:00:02","broadcastType":"LinkLocal","type":"Control","isS > ecurityGroupEnabled":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"},"dpdkEnab > led":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","isSecurityGroupEn > abled":false,"name":"vSwitch0,146,vmwaresvs"}],"guestOsDetails":{},"ex > traConfig":{}},"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:=20 > > 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=20 > > United States > > > > > > T +1 610 661 0905, M +1 484 274 2658, E mike.corey@sap.com > > > > > > > > > > > > > > > > > -- > > Andrija Pani=C4=87 >