You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Sailaja Mada (JIRA)" <ji...@apache.org> on 2013/10/21 08:44:45 UTC

[jira] [Created] (CLOUDSTACK-4905) [VMWARE]System Vm's are failing to start with permission issue while unpacking the OVA file

Sailaja Mada created CLOUDSTACK-4905:
----------------------------------------

             Summary: [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


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.<init>(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)