[
https://issues.apache.org/jira/browse/CLOUDSTACK-4905?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Sailaja Mada closed CLOUDSTACK-4905.
------------------------------------
Resolution: Invalid
Secondary storage was seeded with wrong template. After seeding correct
template, System VM's got started. Hence closing it as invalid.
> [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.<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)
