cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Sudha Ponnaganti (JIRA)" <j...@apache.org>
Subject [jira] [Closed] (CLOUDSTACK-1774) Used Master Branch System VM Template: Volume of System VM Failed to Create on the ESXi host due to Runtime Error
Date Tue, 09 Apr 2013 17:42:17 GMT

     [ https://issues.apache.org/jira/browse/CLOUDSTACK-1774?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Sudha Ponnaganti closed CLOUDSTACK-1774.
----------------------------------------

    
> 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

Mime
View raw message