Abhinav Roy created CLOUDSTACK-4555:
---------------------------------------
Summary: [Upgrade from 3.0.6 to 4.2][vmware] After upgrade the
system vms fail to come up because "Secondary storage mount point" is pointing
to a wrong location
Key: CLOUDSTACK-4555
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4555
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Management Server, Upgrade, VMware
Affects Versions: 4.2.0
Environment: upgrade from 3.0.6 to 4.2
host : esx 4.1 and esx 5.0
Reporter: Abhinav Roy
Priority: Blocker
Fix For: 4.2.1
Steps :
===========================
1. Deploy a CS 3.0.6 advanced zone network with esx 4.1 host.
2. create VMs, snapshots, templates etc.
3. upgrade to CS 4.2
4. Stop and start the system vms once management server has come up
Observations :
===========================
When the system vms are restarted so that they can be started with the new
templates, following error is seen in the logs :
192.100/cpg_vol/abhinav/esx-sec4239, templatePathAtSecondaryStorage:
template/tmpl//2/202/, templateName: 319654a4-b3e6-3be0-b501-5cf015efbf09
2013-08-29 15:41:25,775 DEBUG [vmware.manager.VmwareManagerImpl]
(DirectAgent-7:10.102.192.23) Executing: sudo mount -t nfs
10.102.192.100:/cpg_vol/abhinav/esx-sec4239
/var/cloudstack/mnt/VM/90310994128556.4b062819
2013-08-29 15:41:26,167 DEBUG [vmware.manager.VmwareManagerImpl]
(DirectAgent-7:10.102.192.23) Execution is successful.
2013-08-29 15:41:26,168 DEBUG [vmware.manager.VmwareManagerImpl]
(DirectAgent-7:10.102.192.23) Executing: sudo chmod -R 777
/var/cloudstack/mnt/VM/90310994128556.4b062819
2013-08-29 15:41:26,261 DEBUG [vmware.manager.VmwareManagerImpl]
(DirectAgent-7:10.102.192.23) Exit value is 1
2013-08-29 15:41:26,261 DEBUG [vmware.manager.VmwareManagerImpl]
(DirectAgent-7:10.102.192.23) chmod: changing permissions of
`/var/cloudstack/mnt/VM/90310994128556.4b062819/.snapshot': Read-only file
system
2013-08-29 15:41:26,262 WARN [vmware.manager.VmwareManagerImpl]
(DirectAgent-7:10.102.192.23) Unable to set permissions for
/var/cloudstack/mnt/VM/90310994128556.4b062819 due to chmod: changing
permissions of `/var/cloudstack/mnt/VM/90310994128556.4b062819/.snapshot':
Read-only file system
2013-08-29 15:41:26,262 ERROR [vmware.manager.VmwareManagerImpl]
(DirectAgent-7:10.102.192.23) Unable to create mount point for
nfs://10.102.192.100/cpg_vol/abhinav/esx-sec4239
2013-08-29 15:41:26,263 INFO [storage.resource.VmwareStorageProcessor]
(DirectAgent-7:10.102.192.23) Secondary storage mount point: /mnt/sec
2013-08-29 15:41:26,271 INFO [storage.resource.VmwareStorageProcessor]
(DirectAgent-7:10.102.192.23) Executing command: tar --no-same-owner -xf
/mnt/sec/template/tmpl//2/202//319654a4-b3e6-3be0-b501-5cf015efbf09.ova
2013-08-29 15:41:26,271 DEBUG [storage.resource.VmwareStorageProcessor]
(DirectAgent-7:10.102.192.23) Executing: tar --no-same-owner -xf
/mnt/sec/template/tmpl//2/202//319654a4-b3e6-3be0-b501-5cf015efbf09.ova
2013-08-29 15:41:26,316 WARN [storage.resource.VmwareStorageProcessor]
(DirectAgent-7:10.102.192.23) Exception: tar --no-same-owner -xf
/mnt/sec/template/tmpl//2/202//319654a4-b3e6-3be0-b501-5cf015efbf09.ova
java.io.IOException: Cannot run program "tar" (in directory
"/mnt/sec/template/tmpl/2/202"): 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:223)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:70)
at
com.cloud.storage.resource.VmwareStorageSubsystemCommandHandler.execute(VmwareStorageSubsystemCommandHandler.java:147)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:561)
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-08-29 15:41:26,320 ERROR [storage.resource.VmwareStorageProcessor]
(DirectAgent-7:10.102.192.23) Unable to unpack snapshot OVA file at:
/mnt/sec/template/tmpl//2/202//319654a4-b3e6-3be0-b501-5cf015efbf09.ova
2013-08-29 15:41:26,322 ERROR [storage.resource.VmwareStorageProcessor]
(DirectAgent-7: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:
/mnt/sec/template/tmpl//2/202//319654a4-b3e6-3be0-b501-5cf015efbf09.ova
java.lang.Exception: Unable to unpack snapshot OVA file at:
/mnt/sec/template/tmpl//2/202//319654a4-b3e6-3be0-b501-5cf015efbf09.ova
at
com.cloud.storage.resource.VmwareStorageProcessor.copyTemplateFromSecondaryToPrimary(VmwareStorageProcessor.java:152)
at
com.cloud.storage.resource.VmwareStorageProcessor.copyTemplateToPrimaryStorage(VmwareStorageProcessor.java:223)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:70)
at
com.cloud.storage.resource.VmwareStorageSubsystemCommandHandler.execute(VmwareStorageSubsystemCommandHandler.java:147)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:561)
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-08-29 15:41:26,323 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-7:null) Seq 1-1429143564: Response Received:
2013-08-29 15:41:26,325 DEBUG [agent.transport.Request] (DirectAgent-7:null)
Seq 1-1429143564: Processing: { Ans: , MgmtId: 90310994128556, 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:
/mnt/sec/template/tmpl//2/202//319654a4-b3e6-3be0-b501-5cf015efbf09.ova\n","wait":0}}]
}
2013-08-29 15:41:26,325 DEBUG [agent.transport.Request] (consoleproxy-1:null)
Seq 1-1429143564: Received: { Ans: , MgmtId: 90310994128556, via: 1, Ver: v1,
Flags: 110, { CopyCmdAnswer } }
2013-08-29 15:41:26,329 DEBUG [agent.manager.AgentAttache] (DirectAgent-7:null)
Seq 1-1429143564: No more commands found
2013-08-29 15:41:26,347 INFO [storage.volume.VolumeServiceImpl]
(consoleproxy-1:null) releasing lock for VMTemplateStoragePool 3
2013-08-29 15:41:26,348 WARN [utils.db.Merovingian2] (consoleproxy-1:null) Was
unable to find lock for the key template_spool_ref3 and thread id 2718912
2013-08-29 15:41:26,348 DEBUG [cloud.storage.VolumeManagerImpl]
(consoleproxy-1:null) Unable to create Vol[7|vm=7|ROOT]:Unable to copy template
to primary storage due to exception:Exception: java.lang.Exception
Message: Unable to unpack snapshot OVA file at:
/mnt/sec/template/tmpl//2/202//319654a4-b3e6-3be0-b501-5cf015efbf09.ova
2013-08-29 15:41:26,349 INFO [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:201] is
unreachable: Unable to create Vol[7|vm=7|ROOT]:Unable to copy template to
primary storage due to exception:Exception: java.lang.Exception
Message: Unable to unpack snapshot OVA file at:
/mnt/sec/template/tmpl//2/202//319654a4-b3e6-3be0-b501-5cf015efbf09.ova
at
com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2544)
at
com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2592)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:571)
at
com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:556)
at
com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:928)
at
com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1672)
at
com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
at
com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111)
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)
--------------------------------------------------------------------------------------------------------------------------------------------
If we notice the 1st few lines of this error we will find that "Unable to
create mount point for nfs://10.102.192.100/cpg_vol/abhinav/esx-sec4239", even
though the mount point is in the previous step which is
Executing: sudo mount -t nfs 10.102.192.100:/cpg_vol/abhinav/esx-sec4239
/var/cloudstack/mnt/VM/90310994128556.4b062819
2013-08-29 15:41:26,167 DEBUG [vmware.manager.VmwareManagerImpl]
(DirectAgent-7:10.102.192.23) Execution is successful.
and we can see that on the management server also,
[root@MS-Rhel63 ~]# ls /var/cloudstack/mnt/VM/90310994128556.4b062819
snapshots systemvm template volumes
Now, after this it refers to a secondary storage location which does not exist
and tries to tar the template from that location and it fails expectedly.
"Secondary storage mount point: /mnt/sec "
2013-08-29 15:41:26,271 INFO [storage.resource.VmwareStorageProcessor]
(DirectAgent-7:10.102.192.23) Executing command: tar --no-same-owner -xf
/mnt/sec/template/tmpl//2/202//319654a4-b3e6-3be0-b501-5cf015efbf09.ova
==================
Workaround :
To proceed with my testing i created a /mnt/sec floder and mounted the
secondary storage there, after that the systemv vms got created.
Attaching all relevant logs and db dumps.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
