[
https://issues.apache.org/jira/browse/CLOUDSTACK-4540?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13804100#comment-13804100
]
shweta agarwal commented on CLOUDSTACK-4540:
--------------------------------------------
on latest 4.2.1 setup also hitting this issue
Ms log shows same error messages :
2013-10-24 22:28:10,014 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-10:null) SeqA 2-11938: Processing Seq 2-11938: { Cmd ,
MgmtId: -1, via: 2, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2013-10-24 22:28:10,023 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-10:null) SeqA 2-11938: Sending Seq 2-11938: { Ans: ,
MgmtId: 7614406590488, via: 2, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2013-10-24 22:28:14,265 ERROR [utils.ssh.SshHelper]
(DirectAgent-66:10.147.40.27) Timed out in waiting SSH execution result
2013-10-24 22:28:14,323 ERROR [vmware.resource.VmwareResource]
(DirectAgent-66:10.147.40.27) DhcpEntryCommand failed due to Exception:
java.lang.Exception
Message: Timed out in waiting SSH execution result
java.lang.Exception: Timed out in waiting SSH execution result
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:166)
at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2156)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:429)
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-24 22:28:14,326 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-66:null) Seq 4-273809553: Response Received:
2013-10-24 22:28:14,326 DEBUG [agent.transport.Request] (DirectAgent-66:null)
Seq 4-273809553: Processing: { Ans: , MgmtId: 7614406590488, via: 4, Ver: v1,
Flags: 10,
[{"com.cloud.agent.api.Answer":{"result":false,"details":"DhcpEntryCommand
failed due to Exception: java.lang.Exception\nMessage: Timed out in waiting SSH
execution result\n","wait":0}}] }
2013-10-24 22:28:14,327 DEBUG [agent.transport.Request]
(Job-Executor-71:job-210 = [ d835a756-5e9a-417e-adc6-c6670d8f1d20 ]) Seq
4-273809553: Received: { Ans: , MgmtId: 7614406590488, via: 4, Ver: v1, Flags:
10, { Answer } }
2013-10-24 22:28:14,336 INFO [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-71:job-210 = [ d835a756-5e9a-417e-adc6-c6670d8f1d20 ]) Unable to
contact resource.
com.cloud.exception.ResourceUnavailableException: Resource [DataCenter:1] is
unreachable: Unable to apply dhcp entry on router
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyRules(VirtualNetworkApplianceManagerImpl.java:3827)
at
com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyDhcpEntry(VirtualNetworkApplianceManagerImpl.java:2943)
at
com.cloud.network.element.VirtualRouterElement.addDhcpEntry(VirtualRouterElement.java:902)
at
com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2079)
at
com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2200)
at
com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2136)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:886)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3425)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2985)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2971)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
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-10-24 22:28:14,345 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-71:job-210 = [ d835a756-5e9a-417e-adc6-c6670d8f1d20 ]) Cleaning
up resources for the vm VM[User|09200ff2-3c13-428e-bfbd-fb0bf89bf694] in
Starting state
2013-10-24 22:28:14,349 DEBUG [agent.transport.Request]
(Job-Executor-71:job-210 = [ d835a756-5e9a-417e-adc6-c6670d8f1d20 ]) Seq
4-273809568: Sending { Cmd , MgmtId: 7614406590488, via: 4, Ver: v1, Flags:
100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-3-75-VM","wait":0}}]
}
2013-10-24 22:28:14,349 DEBUG [agent.transport.Request]
(Job-Executor-71:job-210 = [ d835a756-5e9a-417e-adc6-c6670d8f1d20 ]) Seq
4-273809568: Executing: { Cmd , MgmtId: 7614406590488, via: 4, Ver: v1, Flags:
100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-3-75-VM","wait":0}}]
}
2013-10-24 22:28:14,350 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-73:null) Seq 4-273809568: Executing request
2013-10-24 22:28:14,356 INFO [vmware.resource.VmwareResource]
(DirectAgent-73:10.147.40.27) Executing resource StopCommand:
{"isProxy":false,"executeInSequence":false,"vmName":"i-3-75-VM","wait":0}
2013-10-24 22:28:14,392 DEBUG [vmware.mo.HostMO] (DirectAgent-73:10.147.40.27)
find VM i-3-75-VM on host
2013-10-24 22:28:14,393 INFO [vmware.mo.HostMO] (DirectAgent-73:10.147.40.27)
VM i-3-75-VM not found in host cache
2013-10-24 22:28:14,393 DEBUG [vmware.mo.HostMO] (DirectAgent-73:10.147.40.27)
load VM cache on host
2013-10-24 22:28:14,416 INFO [vmware.resource.VmwareResource]
(DirectAgent-73:10.147.40.27) VM i-3-75-VM is no longer in vSphere
2013-10-24 22:28:14,418 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-73:null) Seq 4-273809568: Response Received:
2013-10-24 22:28:14,418 DEBUG [agent.transport.Request] (DirectAgent-73:null)
Seq 4-273809568: Processing: { Ans: , MgmtId: 7614406590488, via: 4, Ver: v1,
Flags: 10, [{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM
i-3-75-VM is no longer in vSphere","wait":0}}] }
> Parallel deployment - Vmware - When deploying 30 parallel Vms , 16 Vms fails
> to get deployed due to "VmDataCommand failed due to Exception:
> java.lang.Exception Message: Timed out in waiting SSH execution result"
> -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-4540
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4540
> 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
> Environment: Build from 4.2-forward.
> Reporter: Sangeetha Hariharan
> Assignee: Sheng Yang
> Priority: Blocker
> Fix For: 4.2.1
>
> Attachments: management-server.log
>
>
> Parallel deployment - Vmware - When deploying 30 parallel Vms , 16 Vms fails
> to get deployed due to "VmDataCommand failed due to Exception:
> java.lang.Exception
> Message: Timed out in waiting SSH execution result"
> Set up - Advanced zone with 1 Vmware 5.0.0 Esxi host.
> Deploy 30 Vms in parallel.
> 16 out of 30 vms deployed in parallel , failed due to "VmDataCommand failed
> due to Exception: java.lang.Exception
> Message: Timed out in waiting SSH execution result"
> Following exception seen in Management server logs:
> 2013-08-28 10:26:58,939 ERROR [vmware.resource.VmwareResource]
> (DirectAgent-21:10.223.58.66) VmDataCommand failed due to Exception:
> java.lang.Exception
> Message: Timed out in waiting SSH execution result
> java.lang.Exception: Timed out in waiting SSH execution result
> at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:166)
> at com.cloud.utils.ssh.SshHelper.sshExecute(SshHelper.java:37)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2470)
> at
> com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:441)
> 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-28 10:26:58,940 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-21:null) Seq 1-170983503: Response Received:
> 2013-08-28 10:26:58,941 DEBUG [agent.transport.Request] (DirectAgent-21:null)
> Seq 1-170983503: Processing: { Ans: , MgmtId: 7083743249448, via: 1, Ver:
> v1, Flags: 10,
> [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}},{"com.cloud.agent.api.Answer":{"result":false,"details":"VmDataCommand
> failed due to Exception: java.lang.Exception\nMessage: Timed out in waiting
> SSH execution result\n","wait":0}}] }
> 2013-08-28 10:26:58,941 DEBUG [agent.transport.Request]
> (Job-Executor-29:job-398 = [ b3a34f25-37b2-4f33-b183-c0ea348d7af9 ]) Seq
> 1-170983503: Received: { Ans: , MgmtId: 7083743249448, via: 1, Ver: v1,
> Flags: 10, { Answer, Answer } }
> 2013-08-28 10:26:58,979 INFO [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-29:job-398 = [ b3a34f25-37b2-4f33-b183-c0ea348d7af9 ]) Unable
> to contact resource.
> com.cloud.exception.ResourceUnavailableException: Resource [DataCenter:1] is
> unreachable: Unable to apply userdata and password entry on router
> at
> com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyRules(VirtualNetworkApplianceManagerImpl.java:3808)
> at
> com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyUserData(VirtualNetworkApplianceManagerImpl.java:2993)
> at
> com.cloud.network.element.VirtualRouterElement.addPasswordAndUserdata(VirtualRouterElement.java:926)
> at
> com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2076)
> at
> com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2191)
> at
> com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2127)
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:886)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:227)
> at
> org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3406)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2966)
> at
> com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2952)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:420)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> at
> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> 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)
--
This message was sent by Atlassian JIRA
(v6.1#6144)
