Kiran Koneti created CLOUDSTACK-2118:
----------------------------------------
Summary: Vm's not creating as route to MS is missing in the router
VM.
Key: CLOUDSTACK-2118
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-2118
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Install and Setup
Affects Versions: 4.2.0
Environment: VMware.
Reporter: Kiran Koneti
Priority: Blocker
Fix For: 4.2.0
While creating the VM with the New System VM templates the System VM's are
created and when trying to create VM the router VM is created but the route to
the management server is not created from the router and the VM creation fails
with the below error message.
"
2013-04-19 17:52:20,929 ERROR [vmware.resource.VmwareResource]
(DirectAgent-49:10.147.40.9) Unexpected exception:
java.net.SocketTimeoutException: The kexTimeout (60000 ms) expired. will
shortcut rest of IPAssoc commands
java.net.SocketTimeoutException: The kexTimeout (60000 ms) expired.
at com.trilead.ssh2.Connection.connect(Connection.java:785)
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:132)
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.assignPublicIpAddress(VmwareResource.java:1531)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:1672)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:357)
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-04-19 17:52:20,932 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-49:null) Seq 1-341966927: Response Received:
2013-04-19 17:52:20,933 DEBUG [agent.transport.Request] (DirectAgent-49:null)
Seq 1-341966927: Processing: { Ans: , MgmtId: 6703101771911, via: 1, Ver: v1,
Flags: 0,
[{"routing.IpAssocAnswer":{"results":["Failed"],"result":false,"wait":0}}] }
2013-04-19 17:52:20,933 DEBUG [agent.transport.Request]
(Job-Executor-11:job-11) Seq 1-341966927: Received: { Ans: , MgmtId:
6703101771911, via: 1, Ver: v1, Flags: 0, { IpAssocAnswer } }
2013-04-19 17:52:20,934 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-11:job-11) Resource is not available: VirtualRouter
com.cloud.exception.ResourceUnavailableException: Resource [DataCenter:1] is
unreachable: Unable to apply ip association on router
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyRules(VirtualNetworkApplianceManagerImpl.java:3436)
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.associatePublicIP(VirtualNetworkApplianceManagerImpl.java:3275)
at
com.cloud.network.router.VpcVirtualNetworkApplianceManagerImpl.associatePublicIP(VpcVirtualNetworkApplianceManagerImpl.java:557)
at
com.cloud.network.element.VirtualRouterElement.applyIps(VirtualRouterElement.java:439)
at
com.cloud.network.NetworkManagerImpl.applyIpAssociations(NetworkManagerImpl.java:539)
at
com.cloud.network.NetworkManagerImpl.shutdownNetworkResources(NetworkManagerImpl.java:3278)
at
com.cloud.network.NetworkManagerImpl.shutdownNetworkElementsAndResources(NetworkManagerImpl.java:2198)
at
com.cloud.network.NetworkManagerImpl.shutdownNetwork(NetworkManagerImpl.java:2153)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
com.cloud.network.NetworkManagerImpl.implementNetwork(NetworkManagerImpl.java:1496)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:1640)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:748)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:467)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:217)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3050)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2644)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2630)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:413)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:164)
at
com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:437)
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.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
2013-04-19 17:52:20,935 WARN [cloud.network.NetworkManagerImpl]
(Job-Executor-11:job-11) Unable to apply ip address associations for
Ntwk[204|Guest|8] as a part of shutdownNetworkRules
2013-04-19 17:52:20,938 WARN [cloud.network.NetworkManagerImpl]
(Job-Executor-11:job-11) Failed to cleanup network id=204 resources as a part
of shutdownNetwork
2013-04-19 17:52:20,951 DEBUG [cloud.network.NetworkManagerImpl]
(Job-Executor-11:job-11) Sending network shutdown to VirtualRouter
2013-04-19 17:52:20,956 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-11:job-11)
Stopping router VM[DomainRouter|r-4-VM]
2013-04-19 17:52:20,970 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-11:job-11) VM state transitted from :Running to Stopping with
event: StopRequestedvm's original host id: 1 new host id: 1 host id before
state transition: 1
2013-04-19 17:52:20,997 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-54:null) Seq 1-341966931: Executing request
2013-04-19 17:52:20,998 INFO [vmware.resource.VmwareResource]
(DirectAgent-54:10.147.40.9) Executing resource NetworkUsageCommand
2013-04-19 17:52:21,823 DEBUG [cloud.api.ApiServlet] (catalina-exec-4:null)
===START=== 10.252.241.75 -- GET
command=queryAsyncJobResult&jobId=2315402e-973f-42af-b2df-14c13db0ff4f&response=json&sessionkey=%2BWNwrh9E%2BRuPGcGBK3f%2F7h1%2F5%2Fo%3D&_=1366354575378
2013-04-19 17:52:21,861 DEBUG [cloud.api.ApiServlet] (catalina-exec-4:null)
===END=== 10.252.241.75 -- GET
command=queryAsyncJobResult&jobId=2315402e-973f-42af-b2df-14c13db0ff4f&response=json&sessionkey=%2BWNwrh9E%2BRuPGcGBK3f%2F7h1%2F5%2Fo%3D&_=1366354575378
2013-04-19 17:52:22,620 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 1 routers to update status.
2013-04-19 17:52:22,623 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
2013-04-19 17:52:22,653 ERROR [vmware.resource.VmwareResource]
(DirectAgent-52:10.147.40.9) Unable to execute NetworkUsage command on DomR
(10.147.40.104), domR may not be ready yet. failure due to Exception:
java.net.SocketTimeoutException
Message: The kexTimeout (60000 ms) expired.
java.net.SocketTimeoutException: The kexTimeout (60000 ms) expired.
at com.trilead.ssh2.Connection.connect(Connection.java:785)
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:132)
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.networkUsage(VmwareResource.java:4789)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.getNetworkStats(VmwareResource.java:4805)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:585)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:431)
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-04-19 17:52:22,657 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-52:null) Seq 1-341966928: Response Received:
2013-04-19 17:52:22,657 DEBUG [agent.transport.Request] (DirectAgent-52:null)
Seq 1-341966928: Processing: { Ans: , MgmtId: 6703101771911, via: 1, Ver: v1,
Flags: 10,
[{"NetworkUsageAnswer":{"routerName":"r-4-VM","bytesSent":0,"bytesReceived":0,"result":true,"details":"","wait":0}}]
}
2013-04-19 17:52:22,658 DEBUG [agent.transport.Request] (RouterMonitor-1:null)
Seq 1-341966928: Received: { Ans: , MgmtId: 6703101771911, via: 1, Ver: v1,
Flags: 10, { NetworkUsageAnswer } }
2013-04-19 17:52:22,658 DEBUG [agent.manager.AgentManagerImpl]
(RouterMonitor-1:null) Details from executing class
com.cloud.agent.api.NetworkUsageCommand:
2013-04-19 17:52:22,658 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:null)
Recieved and Sent bytes are both 0. Not updating user_statistics
2013-04-19 17:52:22,703 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 1 routers to update status.
2013-04-19 17:52:22,706 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
2013-04-19 17:52:22,726 ERROR [vmware.resource.VmwareResource]
(DirectAgent-9:10.147.40.9) Unable to execute NetworkUsage command on DomR
(10.147.40.104), domR may not be ready yet. failure due to Exception:
java.net.SocketTimeoutException
Message: The kexTimeout (60000 ms) expired.
java.net.SocketTimeoutException: The kexTimeout (60000 ms) expired.
at com.trilead.ssh2.Connection.connect(Connection.java:785)
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:132)
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.networkUsage(VmwareResource.java:4789)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.getNetworkStats(VmwareResource.java:4805)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:585)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:431)
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-04-19 17:52:22,729 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-9:null) Seq 1-341966929: Response Received:"
--
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
