Return-Path: X-Original-To: apmail-cloudstack-issues-archive@www.apache.org Delivered-To: apmail-cloudstack-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 09F0B105E9 for ; Mon, 21 Oct 2013 07:01:01 +0000 (UTC) Received: (qmail 85078 invoked by uid 500); 21 Oct 2013 07:00:54 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 85051 invoked by uid 500); 21 Oct 2013 07:00:53 -0000 Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cloudstack.apache.org Delivered-To: mailing list issues@cloudstack.apache.org Received: (qmail 84991 invoked by uid 500); 21 Oct 2013 07:00:51 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 84979 invoked by uid 99); 21 Oct 2013 07:00:50 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 21 Oct 2013 07:00:50 +0000 Date: Mon, 21 Oct 2013 07:00:50 +0000 (UTC) From: "Sailaja Mada (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Updated] (CLOUDSTACK-4905) [VMWARE]System Vm's are failing to start with permission issue while unpacking the OVA file MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-4905?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] Sailaja Mada updated CLOUDSTACK-4905: ------------------------------------- Attachment: logs.rar > [VMWARE]System Vm's are failing to start with permission issue while unpacking the OVA file > ------------------------------------------------------------------------------------------- > > Key: CLOUDSTACK-4905 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4905 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the default.) > Components: VMware > Affects Versions: 4.2.1 > Reporter: Sailaja Mada > Priority: Blocker > Fix For: 4.2.1 > > Attachments: logs.rar > > > Steps:. > 1. Install and configure Adv zone with VMWARE 5.0 ESXi server > Observation: > [VMWARE]System Vm's are failing to start with permission issue while unpacking the OVA file > 2013-10-18 17:17:54,640 INFO [storage.resource.VmwareStorageProcessor] (DirectAgent-1:10.102.192.23) Template routing-8 is not setup yet, setup template from secondary storage with uuid name: 9bf83394f9cb38b7a438edd0e0a4c019 > 2013-10-18 17:17:54,671 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Network id=202 is already implemented > 2013-10-18 17:17:54,720 INFO [storage.resource.VmwareStorageProcessor] (DirectAgent-1:10.102.192.23) Executing copyTemplateFromSecondaryToPrimary. secondaryStorage: nfs://10.102.192.100/cpg_vol/sailaja/dixonss1, templatePathAtSecondaryStorage: template/tmpl/1/8/, templateName: routing-8 > 2013-10-18 17:17:54,730 DEBUG [vmware.manager.VmwareManagerImpl] (DirectAgent-1:10.102.192.23) Executing: sudo mount -t nfs 10.102.192.100:/cpg_vol/sailaja/dixonss1 /var/cloudstack/mnt/VM/187767034175903.70267e11 > 2013-10-18 17:17:54,820 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Network id=201 is already implemented > 2013-10-18 17:17:54,979 DEBUG [network.guru.PodBasedNetworkGuru] (consoleproxy-1:null) Allocated a nic NicProfile[7-2-f701c522-8ba7-45e0-84e8-b7cece900016-10.102.195.146-null for VM[ConsoleProxy|v-2-VM] > 2013-10-18 17:17:54,992 DEBUG [cloud.storage.VolumeManagerImpl] (consoleproxy-1:null) Checking if we need to prepare 1 volumes for VM[ConsoleProxy|v-2-VM] > 2013-10-18 17:17:55,060 DEBUG [storage.image.TemplateDataFactoryImpl] (consoleproxy-1:null) template 8 is already in store:1, type:Image > 2013-10-18 17:17:55,086 DEBUG [storage.image.TemplateDataFactoryImpl] (consoleproxy-1:null) template 8 is already in store:1, type:Primary > 2013-10-18 17:17:55,094 DEBUG [storage.volume.VolumeServiceImpl] (consoleproxy-1:null) Found template routing-8 in storage pool 1 with VMTemplateStoragePool id: 1 > 2013-10-18 17:17:55,125 DEBUG [storage.volume.VolumeServiceImpl] (consoleproxy-1:null) Acquire lock on VMTemplateStoragePool 1 with timeout 3600 seconds > 2013-10-18 17:17:55,232 DEBUG [vmware.manager.VmwareManagerImpl] (DirectAgent-1:10.102.192.23) Execution is successful. > 2013-10-18 17:17:55,232 DEBUG [vmware.manager.VmwareManagerImpl] (DirectAgent-1:10.102.192.23) Executing: sudo chmod -R 777 /var/cloudstack/mnt/VM/187767034175903.70267e11 > 2013-10-18 17:17:55,289 DEBUG [vmware.manager.VmwareManagerImpl] (DirectAgent-1:10.102.192.23) Exit value is 1 > 2013-10-18 17:17:55,289 DEBUG [vmware.manager.VmwareManagerImpl] (DirectAgent-1:10.102.192.23) chmod: changing permissions of `/var/cloudstack/mnt/VM/187767034175903.70267e11/.snapshot': Read-only file system > 2013-10-18 17:17:55,289 WARN [vmware.manager.VmwareManagerImpl] (DirectAgent-1:10.102.192.23) Unable to set permissions for /var/cloudstack/mnt/VM/187767034175903.70267e11 due to chmod: changing permissions of `/var/cloudstack/mnt/VM/187767034175903.70267e11/.snapshot': Read-only file system > 2013-10-18 17:17:55,289 INFO [storage.resource.VmwareStorageProcessor] (DirectAgent-1:10.102.192.23) Secondary storage mount point: /var/cloudstack/mnt/VM/187767034175903.70267e11 > 2013-10-18 17:17:55,294 INFO [storage.resource.VmwareStorageProcessor] (DirectAgent-1:10.102.192.23) Executing command: tar --no-same-owner -xf /var/cloudstack/mnt/VM/187767034175903.70267e11/template/tmpl/1/8//routing-8.ova > 2013-10-18 17:17:55,294 DEBUG [storage.resource.VmwareStorageProcessor] (DirectAgent-1:10.102.192.23) Executing: tar --no-same-owner -xf /var/cloudstack/mnt/VM/187767034175903.70267e11/template/tmpl/1/8//routing-8.ova > 2013-10-18 17:17:55,313 WARN [storage.resource.VmwareStorageProcessor] (DirectAgent-1:10.102.192.23) Exception: tar --no-same-owner -xf /var/cloudstack/mnt/VM/187767034175903.70267e11/template/tmpl/1/8//routing-8.ova > java.io.IOException: Cannot run program "tar" (in directory "/var/cloudstack/mnt/VM/187767034175903.70267e11/template/tmpl/1/8"): java.io.IOException: error=2, No such file or directory > at java.lang.ProcessBuilder.start(ProcessBuilder.java:475) > at com.cloud.utils.script.Script.execute(Script.java:183) > at com.cloud.utils.script.Script.execute(Script.java:161) > at com.cloud.storage.resource.VmwareStorageProcessor.copyTemplateFromSecondaryToPrimary(VmwareStorageProcessor.java:148) > at com.cloud.storage.resource.VmwareStorageProcessor.copyTemplateToPrimaryStorage(VmwareStorageProcessor.java:225) > at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:70) > at com.cloud.storage.resource.VmwareStorageSubsystemCommandHandler.execute(VmwareStorageSubsystemCommandHandler.java:155) > at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49) > at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:559) > at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186) > 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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165) > at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > at java.lang.Thread.run(Thread.java:679) > Caused by: java.io.IOException: java.io.IOException: error=2, No such file or directory > at java.lang.UNIXProcess.(UNIXProcess.java:164) > at java.lang.ProcessImpl.start(ProcessImpl.java:81) > at java.lang.ProcessBuilder.start(ProcessBuilder.java:468) > ... 17 more > 2013-10-18 17:17:55,316 ERROR [storage.resource.VmwareStorageProcessor] (DirectAgent-1:10.102.192.23) Unable to unpack snapshot OVA file at: /var/cloudstack/mnt/VM/187767034175903.70267e11/template/tmpl/1/8//routing-8.ova > 2013-10-18 17:17:55,318 ERROR [storage.resource.VmwareStorageProcessor] (DirectAgent-1:10.102.192.23) Unable to copy template to primary storage due to exception:Exception: java.lang.Exception > Message: Unable to unpack snapshot OVA file at: /var/cloudstack/mnt/VM/187767034175903.70267e11/template/tmpl/1/8//routing-8.ova > java.lang.Exception: Unable to unpack snapshot OVA file at: /var/cloudstack/mnt/VM/187767034175903.70267e11/template/tmpl/1/8//routing-8.ova > at com.cloud.storage.resource.VmwareStorageProcessor.copyTemplateFromSecondaryToPrimary(VmwareStorageProcessor.java:152) > at com.cloud.storage.resource.VmwareStorageProcessor.copyTemplateToPrimaryStorage(VmwareStorageProcessor.java:225) > at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:70) > at com.cloud.storage.resource.VmwareStorageSubsystemCommandHandler.execute(VmwareStorageSubsystemCommandHandler.java:155) > at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49) > at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186) > 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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165) > at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > at java.lang.Thread.run(Thread.java:679) > 2013-10-18 17:17:55,319 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-1:null) Seq 1-187498505: Response Received: > 2013-10-18 17:17:55,320 DEBUG [agent.transport.Request] (DirectAgent-1:null) Seq 1-187498505: Processing: { Ans: , MgmtId: 187767034175903, via: 1, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"Unable to copy template to primary storage due to exception:Exception: java.lang.Exception\nMessage: Unable to unpack snapshot OVA file at: /var/cloudstack/mnt/VM/187767034175903.70267e11/template/tmpl/1/8//routing-8.ova\n","wait":0}}] } > 2013-10-18 17:17:55,320 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-187498505: Received: { Ans: , MgmtId: 187767034175903, via: 1, Ver: v1, Flags: 110, { CopyCmdAnswer } } > 2013-10-18 17:17:55,324 DEBUG [agent.manager.AgentAttache] (DirectAgent-1:null) Seq 1-187498505: No more commands found > 2013-10-18 17:17:55,342 INFO [storage.volume.VolumeServiceImpl] (secstorage-1:null) releasing lock for VMTemplateStoragePool 1 > 2013-10-18 17:17:55,343 WARN [utils.db.Merovingian2] (secstorage-1:null) Was unable to find lock for the key template_spool_ref1 and thread id 376211979 > 2013-10-18 17:17:55,343 DEBUG [cloud.storage.VolumeManagerImpl] (secstorage-1:null) Unable to create Vol[1|vm=1|ROOT]:Unable to copy template to primary storage due to exception:Exception: java.lang.Exception > Message: Unable to unpack snapshot OVA file at: /var/cloudstack/mnt/VM/187767034175903.70267e11/template/tmpl/1/8//routing-8.ova > 2013-10-18 17:17:55,344 INFO [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Unable to contact resource. > com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is unreachable: Unable to create Vol[1|vm=1|ROOT]:Unable to copy template to primary storage due to exception:Exception: java.lang.Exception > Message: Unable to unpack snapshot OVA file at: /var/cloudstack/mnt/VM/187767034175903.70267e11/template/tmpl/1/8//routing-8.ova > at com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2580) > at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2631) > at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:889) > at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578) > at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:571) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:267) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1300) > at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:123) > at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50) > at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104) > at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33) > at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81) > at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72) > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351) > at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178) > at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165) > at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > at java.lang.Thread.run(Thread.java:679) > 2013-10-18 17:17:55,363 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) Cleaning up resources for the vm VM[SecondaryStorageVm|s-1-VM] in Starting state > 2013-10-18 17:17:55,366 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-187498506: Sending { Cmd , MgmtId: 187767034175903, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"s-1-VM","wait":0}}] } > 2013-10-18 17:17:55,367 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-187498506: Executing: { Cmd , MgmtId: 187767034175903, via: 1, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"s-1-VM","wait":0}}] } > 2013-10-18 17:17:55,367 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-6:null) Seq 1-187498506: Executing request > 2013-10-18 17:17:55,367 INFO [vmware.resource.VmwareResource] (DirectAgent-6:10.102.192.23) Executing resource StopCommand: {"isProxy":false,"executeInSequence":true,"vmName":"s-1-VM","wait":0} -- This message was sent by Atlassian JIRA (v6.1#6144)