[
https://issues.apache.org/jira/browse/CLOUDSTACK-1774?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Abhinandan Prateek reassigned CLOUDSTACK-1774:
----------------------------------------------
Assignee: Rohit Yadav (was: Abhinandan Prateek)
> Used Master Branch System VM Template: Volume of System VM Failed to Create
> on the ESXi host due to Runtime Error
> -----------------------------------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-1774
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-1774
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Management Server
> Affects Versions: 4.2.0
> Reporter: Chandan Purushothama
> Assignee: Rohit Yadav
> Priority: Blocker
> Fix For: 4.2.0
>
> Attachments: management-server.zip
>
>
> Observed the bug on an Advanced Zone setup where I used the new master branch
> System VM Template for VMWare. I am not sure whether the bug is in the
> CloudStack management server code or the System VM Template itself. I will
> re-check the build using the old System VM Template and add more information
> to the bug report.
> ===========
> Observations:
> ===========
> 2013-03-21 19:44:24,629 DEBUG [agent.transport.Request] (consoleproxy-1:null)
> Seq 1-62062601: Sending { Cmd , MgmtId: 206915885093604, via: 1, Ver: v1,
> Flags: 100111,
> [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/d7574a80-9bb1-3c9c-be00-f12d6fd010f6","poolUuid":"d7574a80-9bb1-3c9c-be00-f12d6fd010f6","poolId":200,"primaryPool":{"id":200,"uuid":"d7574a80-9bb1-3c9c-be00-f12d6fd010f6","host":"10.223.110.232","path":"/export/home/chandan/asfmas-59-67/primary","port":2049,"type":"NetworkFilesystem"},"secondaryStorageUrl":"nfs://10.223.110.232/export/home/chandan/asfmas-59-67/secondary","primaryStorageUrl":"nfs://10.223.110.232/export/home/chandan/asfmas-59-67/primary","url":"nfs://10.223.110.232/export/home/chandan/asfmas-59-67/secondary/template/tmpl/1/8/","format":"OVA","accountId":1,"name":"routing-8","wait":10800}}]
> }
> 2013-03-21 19:44:24,630 DEBUG [agent.transport.Request] (consoleproxy-1:null)
> Seq 1-62062601: Executing: { Cmd , MgmtId: 206915885093604, via: 1, Ver: v1,
> Flags: 100111,
> [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/d7574a80-9bb1-3c9c-be00-f12d6fd010f6","poolUuid":"d7574a80-9bb1-3c9c-be00-f12d6fd010f6","poolId":200,"primaryPool":{"id":200,"uuid":"d7574a80-9bb1-3c9c-be00-f12d6fd010f6","host":"10.223.110.232","path":"/export/home/chandan/asfmas-59-67/primary","port":2049,"type":"NetworkFilesystem"},"secondaryStorageUrl":"nfs://10.223.110.232/export/home/chandan/asfmas-59-67/secondary","primaryStorageUrl":"nfs://10.223.110.232/export/home/chandan/asfmas-59-67/primary","url":"nfs://10.223.110.232/export/home/chandan/asfmas-59-67/secondary/template/tmpl/1/8/","format":"OVA","accountId":1,"name":"routing-8","wait":10800}}]
> }
> 2013-03-21 19:44:24,631 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-1:null) Seq 1-62062601: Executing request
> 2013-03-21 19:44:24,632 INFO [vmware.resource.VmwareResource]
> (DirectAgent-1:10.223.59.66) Executing resource
> PrimaryStorageDownloadCommand:
> {"localPath":"/mnt/d7574a80-9bb1-3c9c-be00-f12d6fd010f6","poolUuid":"d7574a80-9bb1-3c9c-be00-f12d6fd010f6","poolId":200,"primaryPool":{"id":200,"uuid":"d7574a80-9bb1-3c9c-be00-f12d6fd010f6","host":"10.223.110.232","path":"/export/home/chandan/asfmas-59-67/primary","port":2049,"type":"NetworkFilesystem"},"secondaryStorageUrl":"nfs://10.223.110.232/export/home/chandan/asfmas-59-67/secondary","primaryStorageUrl":"nfs://10.223.110.232/export/home/chandan/asfmas-59-67/primary","url":"nfs://10.223.110.232/export/home/chandan/asfmas-59-67/secondary/template/tmpl/1/8/","format":"OVA","accountId":1,"name":"routing-8","wait":10800}
> 2013-03-21 19:44:24,642 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-5:null) Seq 1-62062600: Response Received:
> 2013-03-21 19:44:24,643 DEBUG [agent.transport.Request] (DirectAgent-5:null)
> Seq 1-62062600: Processing: { Ans: , MgmtId: 206915885093604, via: 1, Ver:
> v1, Flags: 10, [{"CheckHealthAnswer":{"result":true,"details":"resource is
> alive","wait":0}}] }
> 2013-03-21 19:44:24,643 DEBUG [agent.transport.Request]
> (AgentTaskPool-1:null) Seq 1-62062600: Received: { Ans: , MgmtId:
> 206915885093604, via: 1, Ver: v1, Flags: 10, { CheckHealthAnswer } }
> 2013-03-21 19:44:24,643 DEBUG [agent.manager.AgentManagerImpl]
> (AgentTaskPool-1:null) Details from executing class
> com.cloud.agent.api.CheckHealthCommand: resource is alive
> 2013-03-21 19:44:24,643 DEBUG [agent.manager.AgentManagerImpl]
> (AgentTaskPool-1:null) agent (1) responded to checkHeathCommand, reporting
> that agent is Up
> 2013-03-21 19:44:24,643 INFO [agent.manager.AgentManagerImpl]
> (AgentTaskPool-1:null) The state determined is Up
> 2013-03-21 19:44:24,643 INFO [agent.manager.AgentManagerImpl]
> (AgentTaskPool-1:null) Agent is determined to be up and running
> 2013-03-21 19:44:24,643 DEBUG [cloud.host.Status] (AgentTaskPool-1:null)
> Transition:[Resource state = Enabled, Agent event = Ping, Host id = 1, name =
> 10.223.59.66]
> 2013-03-21 19:44:24,656 INFO [vmware.manager.VmwareStorageManagerImpl]
> (DirectAgent-1:10.223.59.66) Template routing-8 is not setup yet, setup
> template from secondary storage with uuid name:
> b3ec0e8a2229370f80cc00b0ad6c4c72
> 2013-03-21 19:44:24,659 DEBUG [cloud.host.Status] (AgentTaskPool-1:null)
> Agent status update: [id = 1; name = 10.223.59.66; old status = Up; event =
> Ping; new status = Up; old update count = 2; new update count = 3]
> 2013-03-21 19:44:24,668 INFO [vmware.manager.VmwareStorageManagerImpl]
> (DirectAgent-1:10.223.59.66) Executing copyTemplateFromSecondaryToPrimary.
> secondaryStorage:
> nfs://10.223.110.232/export/home/chandan/asfmas-59-67/secondary,
> templatePathAtSecondaryStorage: template/tmpl/1/8/, templateName: routing-8
> 2013-03-21 19:44:24,668 INFO [vmware.manager.VmwareStorageManagerImpl]
> (DirectAgent-1:10.223.59.66) Secondary storage mount point:
> /var/cloudstack/mnt/NEWSYSTEMPLVMW/206915885093604.e5d2f74
> 2013-03-21 19:44:24,674 ERROR [vmware.manager.VmwareStorageManagerImpl]
> (DirectAgent-1:10.223.59.66) Unable to execute PrimaryStorageDownloadCommand
> due to exception
> java.io.FileNotFoundException:
> /var/cloudstack/mnt/NEWSYSTEMPLVMW/206915885093604.e5d2f74/template/tmpl/1/8/systemvmtemplate-2013-03-20-master-vmware.ovf
> (Permission denied)
> at java.io.FileInputStream.open(Native Method)
> at java.io.FileInputStream.<init>(FileInputStream.java:137)
> at java.io.FileInputStream.<init>(FileInputStream.java:96)
> at
> com.cloud.hypervisor.vmware.mo.HttpNfcLeaseMO.readOvfContent(HttpNfcLeaseMO.java:125)
> at
> com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.importVmFromOVF(HypervisorHostHelper.java:981)
> at
> com.cloud.hypervisor.vmware.mo.HostMO.importVmFromOVF(HostMO.java:681)
> at
> com.cloud.hypervisor.vmware.manager.VmwareStorageManagerImpl.copyTemplateFromSecondaryToPrimary(VmwareStorageManagerImpl.java:478)
> at
> com.cloud.hypervisor.vmware.manager.VmwareStorageManagerImpl.execute(VmwareStorageManagerImpl.java:153)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:3660)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:414)
> 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-03-21 19:44:24,676 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-1:null) Seq 1-62062601: Response Received:
> 2013-03-21 19:44:24,676 DEBUG [agent.transport.Request] (DirectAgent-1:null)
> Seq 1-62062601: Processing: { Ans: , MgmtId: 206915885093604, via: 1, Ver:
> v1, Flags: 110,
> [{"storage.PrimaryStorageDownloadAnswer":{"templateSize":0,"result":false,"details":"Unable
> to execute PrimaryStorageDownloadCommand due to exception","wait":0}}] }
> 2013-03-21 19:44:24,676 DEBUG [agent.transport.Request] (consoleproxy-1:null)
> Seq 1-62062601: Received: { Ans: , MgmtId: 206915885093604, via: 1, Ver: v1,
> Flags: 110, { PrimaryStorageDownloadAnswer } }
> 2013-03-21 19:44:24,676 DEBUG [agent.manager.AgentAttache]
> (DirectAgent-1:null) Seq 1-62062601: No more commands found
> 2013-03-21 19:44:24,677 DEBUG [agent.manager.AgentManagerImpl]
> (consoleproxy-1:null) Details from executing class
> com.cloud.agent.api.storage.PrimaryStorageDownloadCommand: Unable to execute
> PrimaryStorageDownloadCommand due to exception
> 2013-03-21 19:44:24,677 DEBUG [cloud.template.TemplateManagerImpl]
> (consoleproxy-1:null) Template 8 download to pool 200 failed due to Unable to
> execute PrimaryStorageDownloadCommand due to exception
> 2013-03-21 19:44:24,678 DEBUG [cloud.template.TemplateManagerImpl]
> (consoleproxy-1:null) Template 8 is not found on and can not be downloaded to
> pool 200
> 2013-03-21 19:44:24,744 DEBUG [agent.transport.Request] (consoleproxy-1:null)
> Seq 1-62062602: Sending { Cmd , MgmtId: 206915885093604, via: 1, Ver: v1,
> Flags: 100111,
> [{"storage.CreateCommand":{"volId":2,"pool":{"id":200,"uuid":"d7574a80-9bb1-3c9c-be00-f12d6fd010f6","host":"10.223.110.232","path":"/export/home/chandan/asfmas-59-67/primary","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":0,"tags":[],"type":"ROOT","name":"ROOT-2","useLocalStorage":false,"recreatable":true,"diskOfferingId":10,"volumeId":2},"wait":0}}]
> }
> 2013-03-21 19:44:24,745 DEBUG [agent.transport.Request] (consoleproxy-1:null)
> Seq 1-62062602: Executing: { Cmd , MgmtId: 206915885093604, via: 1, Ver: v1,
> Flags: 100111,
> [{"storage.CreateCommand":{"volId":2,"pool":{"id":200,"uuid":"d7574a80-9bb1-3c9c-be00-f12d6fd010f6","host":"10.223.110.232","path":"/export/home/chandan/asfmas-59-67/primary","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":0,"tags":[],"type":"ROOT","name":"ROOT-2","useLocalStorage":false,"recreatable":true,"diskOfferingId":10,"volumeId":2},"wait":0}}]
> }
> 2013-03-21 19:44:24,745 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-6:null) Seq 1-62062602: Executing request
> 2013-03-21 19:44:24,747 INFO [vmware.resource.VmwareResource]
> (DirectAgent-6:10.223.59.66) Executing resource CreateCommand:
> {"volId":2,"pool":{"id":200,"uuid":"d7574a80-9bb1-3c9c-be00-f12d6fd010f6","host":"10.223.110.232","path":"/export/home/chandan/asfmas-59-67/primary","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":0,"tags":[],"type":"ROOT","name":"ROOT-2","useLocalStorage":false,"recreatable":true,"diskOfferingId":10,"volumeId":2},"wait":0}
> 2013-03-21 19:44:27,227 DEBUG [vmware.mo.HostMO] (DirectAgent-6:10.223.59.66)
> find VM 56b1ebcb2b854ec5b786d6be4afcaaa4 on host
> 2013-03-21 19:44:27,227 DEBUG [vmware.mo.HostMO] (DirectAgent-6:10.223.59.66)
> load VM cache on host
> 2013-03-21 19:44:27,238 INFO [vmware.resource.VmwareResource]
> (DirectAgent-6:10.223.59.66) Delete file if exists in datastore to clear the
> way for creating the volume. file: [d7574a809bb13c9cbe00f12d6fd010f6]
> ROOT-2-2.vmdk
> 2013-03-21 19:44:27,243 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-6:10.223.59.66) Search file ROOT-2-2.vmdk on
> [d7574a809bb13c9cbe00f12d6fd010f6]
> 2013-03-21 19:44:27,258 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-6:10.223.59.66) File [d7574a809bb13c9cbe00f12d6fd010f6]
> ROOT-2-2.vmdk does not exist on datastore
> 2013-03-21 19:44:27,261 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-6:10.223.59.66) Search file ROOT-2-2-flat.vmdk on
> [d7574a809bb13c9cbe00f12d6fd010f6]
> 2013-03-21 19:44:27,277 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-6:10.223.59.66) File [d7574a809bb13c9cbe00f12d6fd010f6]
> ROOT-2-2-flat.vmdk does not exist on datastore
> 2013-03-21 19:44:27,280 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-6:10.223.59.66) Search file ROOT-2-2-delta.vmdk on
> [d7574a809bb13c9cbe00f12d6fd010f6]
> 2013-03-21 19:44:27,298 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-6:10.223.59.66) File [d7574a809bb13c9cbe00f12d6fd010f6]
> ROOT-2-2-delta.vmdk does not exist on datastore
> 2013-03-21 19:44:27,843 INFO [vmware.resource.VmwareResource]
> (DirectAgent-6:10.223.59.66) Destroy dummy VM after volume creation
> 2013-03-21 19:44:28,898 ERROR [vmware.resource.VmwareResource]
> (DirectAgent-6:10.223.59.66) CreateCommand failed due to Exception:
> java.lang.RuntimeException
> Message: Invalid configuration for device '0'.
> java.lang.RuntimeException: Invalid configuration for device '0'.
> at
> com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:291)
> at
> com.cloud.hypervisor.vmware.mo.VirtualMachineMO.createDisk(VirtualMachineMO.java:944)
> at
> com.cloud.hypervisor.vmware.mo.VirtualMachineMO.createDisk(VirtualMachineMO.java:867)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:3955)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:348)
> 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-03-21 19:44:28,900 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-6:null) Seq 1-62062602: Response Received:
> 2013-03-21 19:44:28,901 DEBUG [agent.transport.Request] (DirectAgent-6:null)
> Seq 1-62062602: Processing: { Ans: , MgmtId: 206915885093604, via: 1, Ver:
> v1, Flags: 110,
> [{"storage.CreateAnswer":{"requestTemplateReload":false,"result":false,"details":"Exception:
> java.lang.Exception\nMessage: java.lang.RuntimeException: Invalid
> configuration for device '0'.\nStack: java.lang.Exception:
> java.lang.RuntimeException: Invalid configuration for device '0'.\n\tat
> com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:4034)\n\tat
>
> com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:348)\n\tat
>
> com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)\n\tat
>
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)\n\tat
> java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)\n\tat
> java.util.concurrent.FutureTask.run(FutureTask.java:166)\n\tat
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)\n\tat
>
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)\n\tat
>
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)\n\tat
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)\n\tat
> java.lang.Thread.run(Thread.java:679)\nCaused by:
> java.lang.RuntimeException: Invalid configuration for device '0'.\n\tat
> com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:291)\n\tat
>
> com.cloud.hypervisor.vmware.mo.VirtualMachineMO.createDisk(VirtualMachineMO.java:944)\n\tat
>
> com.cloud.hypervisor.vmware.mo.VirtualMachineMO.createDisk(VirtualMachineMO.java:867)\n\tat
>
> com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:3955)\n\t...
> 10 more\n","wait":0}}] }
--
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
