Return-Path: X-Original-To: apmail-cloudstack-issues-archive@www.apache.org Delivered-To: apmail-cloudstack-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id CE7FACFC9 for ; Thu, 18 Jul 2013 19:52:48 +0000 (UTC) Received: (qmail 5067 invoked by uid 500); 18 Jul 2013 19:52:48 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 5050 invoked by uid 500); 18 Jul 2013 19:52:48 -0000 Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cloudstack.apache.org Delivered-To: mailing list issues@cloudstack.apache.org Received: (qmail 5042 invoked by uid 500); 18 Jul 2013 19:52:48 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 5039 invoked by uid 99); 18 Jul 2013 19:52:48 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 18 Jul 2013 19:52:48 +0000 Date: Thu, 18 Jul 2013 19:52:48 +0000 (UTC) From: "Sangeetha Hariharan (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Comment Edited] (CLOUDSTACK-3434) Parallel deployment - Xenserver - When deploying 30 Vms in parallel/starting 30 VMs in parallel, Vms failed because of failing in "SavePasswordCommand"/"Dhcp Entry". MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-3434?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13712711#comment-13712711 ] Sangeetha Hariharan edited comment on CLOUDSTACK-3434 at 7/18/13 7:51 PM: -------------------------------------------------------------------------- Tested with latest build from 4.2: Deployed 40 vms in parallel. 5 Vms failed to get deployed. mysql> select count(*),state,type from vm_instance where name like "zzz%" group by state,type; +----------+-----------+------+ | count(*) | state | type | +----------+-----------+------+ | 5 | Expunging | User | | 35 | Running | User | +----------+-----------+------+ 2 rows in set (0.02 sec) I am still seeing the same problem where Vms deployment is failing in "SavePasswordCommand"/"Dhcp Entry". Following error seen in the SM.log: [2023] 2013-07-18 11:36:06.301305 #### VMOPS enter saveDhcpEntry #### [2023] 2013-07-18 11:36:06.301427 ['/bin/bash', '/opt/xensource/bin/dhcp_entry.sh', '-r', '169.254.3.85', '-v', '10.1.1.9', '-m', '02:00:11:e8:00:ac', '-n', 'zzzz-21', '-d', '10.1.1.1', '-N', '10.1.1.1'] [2023] 2013-07-18 11:36:06.324631 FAILED in util.pread: (rc 255) stdout: '', stderr: 'ssh_exchange_identification: Connection closed by remote host ' [2023] 2013-07-18 11:36:06.324862 save dhcp entry failed [2023] 2013-07-18 11:36:06.325002 #### VMOPS exit saveDhcpEntry #### [1559] 2013-07-18 11:36:06.373660 pread SUCCESS [1559] 2013-07-18 11:36:06.374216 ['/bin/bash', '/opt/xensource/bin/vm_data.sh', '-r', '169.254.3.85', '-v', '10.1.1.51', '-F', 'metadata', '-f', 'public-ipv4', '-d', '/tmp/tmpiE52xF'] [2030] 2013-07-18 11:36:06.557088 #### VMOPS enter savePassword #### [2030] 2013-07-18 11:36:06.557238 ['/bin/bash', '/opt/xensource/bin/save_password_to_domr.sh', '-r', '169.254.3.85', '-v', '10.1.1.137', '-p', 'fnirq_cnffjbeq', 'zzzz-38'] [2030] 2013-07-18 11:36:06.719090 FAILED in util.pread: (rc 1) stdout: '', stderr: 'ssh_exchange_identification: Connection closed by remote host ssh_exchange_identification: Connection closed by remote host ' [2030] 2013-07-18 11:36:06.719316 save password to domr failed [2030] 2013-07-18 11:36:06.719424 #### VMOPS exit savePassword #### [1638] 2013-07-18 11:36:06.892928 pread SUCCESS [1638] 2013-07-18 11:36:06.893502 ['/bin/bash', '/opt/xensource/bin/vm_data.sh', '-r', '169.254.3.85', '-v', '10.1.1.158', '-F', 'metadata', '-f', 'public-ipv4', '-d', '/tmp/tmpsMoUIc'] [830] 2013-07-18 11:36:06.914788 pread SUCCESS [830] 2013-07-18 11:36:06.915369 ['/bin/bash', '/opt/xensource/bin/vm_data.sh', '-r', '169.254.3.85', '-v', '10.1.1.174', '-F', 'metadata', '-f', 'local-ipv4', '-d', '/tmp/tmpZNbBwW'] [1460] 2013-07-18 11:36:06.992292 FAILED in util.pread: (rc 255) stdout: '', stderr: '+ cert=/root/.ssh/id_rsa.cloud was (Author: sangeethah): Tested with latest build from 4.2: I am still seeing the same problem where Vms deployment is failing in "SavePasswordCommand"/"Dhcp Entry". Following error seen in the SM.log: [2023] 2013-07-18 11:36:06.301305 #### VMOPS enter saveDhcpEntry #### [2023] 2013-07-18 11:36:06.301427 ['/bin/bash', '/opt/xensource/bin/dhcp_entry.sh', '-r', '169.254.3.85', '-v', '10.1.1.9', '-m', '02:00:11:e8:00:ac', '-n', 'zzzz-21', '-d', '10.1.1.1', '-N', '10.1.1.1'] [2023] 2013-07-18 11:36:06.324631 FAILED in util.pread: (rc 255) stdout: '', stderr: 'ssh_exchange_identification: Connection closed by remote host ' [2023] 2013-07-18 11:36:06.324862 save dhcp entry failed [2023] 2013-07-18 11:36:06.325002 #### VMOPS exit saveDhcpEntry #### [1559] 2013-07-18 11:36:06.373660 pread SUCCESS [1559] 2013-07-18 11:36:06.374216 ['/bin/bash', '/opt/xensource/bin/vm_data.sh', '-r', '169.254.3.85', '-v', '10.1.1.51', '-F', 'metadata', '-f', 'public-ipv4', '-d', '/tmp/tmpiE52xF'] [2030] 2013-07-18 11:36:06.557088 #### VMOPS enter savePassword #### [2030] 2013-07-18 11:36:06.557238 ['/bin/bash', '/opt/xensource/bin/save_password_to_domr.sh', '-r', '169.254.3.85', '-v', '10.1.1.137', '-p', 'fnirq_cnffjbeq', 'zzzz-38'] [2030] 2013-07-18 11:36:06.719090 FAILED in util.pread: (rc 1) stdout: '', stderr: 'ssh_exchange_identification: Connection closed by remote host ssh_exchange_identification: Connection closed by remote host ' [2030] 2013-07-18 11:36:06.719316 save password to domr failed [2030] 2013-07-18 11:36:06.719424 #### VMOPS exit savePassword #### [1638] 2013-07-18 11:36:06.892928 pread SUCCESS [1638] 2013-07-18 11:36:06.893502 ['/bin/bash', '/opt/xensource/bin/vm_data.sh', '-r', '169.254.3.85', '-v', '10.1.1.158', '-F', 'metadata', '-f', 'public-ipv4', '-d', '/tmp/tmpsMoUIc'] [830] 2013-07-18 11:36:06.914788 pread SUCCESS [830] 2013-07-18 11:36:06.915369 ['/bin/bash', '/opt/xensource/bin/vm_data.sh', '-r', '169.254.3.85', '-v', '10.1.1.174', '-F', 'metadata', '-f', 'local-ipv4', '-d', '/tmp/tmpZNbBwW'] [1460] 2013-07-18 11:36:06.992292 FAILED in util.pread: (rc 255) stdout: '', stderr: '+ cert=/root/.ssh/id_rsa.cloud > Parallel deployment - Xenserver - When deploying 30 Vms in parallel/starting 30 VMs in parallel, Vms failed because of failing in "SavePasswordCommand"/"Dhcp Entry". > ---------------------------------------------------------------------------------------------------------------------------------------------------------------------- > > Key: CLOUDSTACK-3434 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-3434 > 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 > Reporter: Sangeetha Hariharan > Assignee: Sheng Yang > Priority: Blocker > Fix For: 4.2.0 > > Attachments: xenparallel.rar > > > Parallel deployment - Xenserver - When deploying 30 Vms in parallel/starting 30 VMs in parallel, Vms failed because of failing in "SavePasswordCommand"/"Dhcp Entry". > Steps to reproduce the problem: > Advanced zone set up with Xenserver host. > Deploy 30 Vms in parallel. > Out of 30 vms , 1 vm failed to start successfully and is in "Error" state because of timing out on the "SavePasswordCommand". > Following is the snippet from management server logs: > 2013-07-09 16:30:28,895 DEBUG [cloud.network.NetworkModelImpl] (Job-Executor-35:job-35) Service SecurityGroup is not supported in the network id=204 > 2013-07-09 16:30:28,898 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-35:job-35) Applying userdata and password entry in network Ntwk[204|Guest|8] > 2013-07-09 16:30:28,910 DEBUG [agent.transport.Request] (Job-Executor-35:job-35) Seq 1-729350387: Sending { Cmd , MgmtId: 7200344900649, via: 1, Ver: v1, Flags: 100011, [{"com.clou > d.agent.api.routing.SavePasswordCommand":{"password":"fnirq_cnffjbeq","vmIpAddress":"10.1.1.148","vmName":"hello-14","executeInSequence":false,"accessDetails":{"router.guest.ip":"10 > .1.1.1","zone.network.type":"Advanced","router.ip":"169.254.3.54","router.name":"r-4-VM"},"wait":0}},{"com.cloud.agent.api.routing.VmDataCommand":{"vmIpAddress":"10.1.1.148","vmName > ":"hello-14","executeInSequence":false,"accessDetails":{"router.guest.ip":"10.1.1.1","zone.network.type":"Advanced","router.ip":"169.254.3.54","router.name":"r-4-VM"},"wait":0}}] } > 2013-07-09 16:30:28,911 DEBUG [agent.transport.Request] (Job-Executor-35:job-35) Seq 1-729350387: Executing: { Cmd , MgmtId: 7200344900649, via: 1, Ver: v1, Flags: 100011, [{"com.c > loud.agent.api.routing.SavePasswordCommand":{"password":"fnirq_cnffjbeq","vmIpAddress":"10.1.1.148","vmName":"hello-14","executeInSequence":false,"accessDetails":{"router.guest.ip": > "10.1.1.1","zone.network.type":"Advanced","router.ip":"169.254.3.54","router.name":"r-4-VM"},"wait":0}},{"com.cloud.agent.api.routing.VmDataCommand":{"vmIpAddress":"10.1.1.148","vmN > ame":"hello-14","executeInSequence":false,"accessDetails":{"router.guest.ip":"10.1.1.1","zone.network.type":"Advanced","router.ip":"169.254.3.54","router.name":"r-4-VM"},"wait":0}}] > } > ...... > 2013-07-09 16:30:32,224 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-105:null) Seq 1-729350387: Cancelling because one of the answers is false and it is stop on error. > 2013-07-09 16:30:32,224 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-105:null) Seq 1-729350387: Response Received: > 2013-07-09 16:30:32,225 DEBUG [agent.transport.Request] (DirectAgent-105:null) Seq 1-729350387: Processing: { Ans: , MgmtId: 7200344900649, via: 1, Ver: v1, Flags: 10, [{"com.cloud > .agent.api.Answer":{"result":false,"details":"savePassword failed","wait":0}}] } > 2013-07-09 16:30:32,225 DEBUG [agent.transport.Request] (Job-Executor-35:job-35) Seq 1-729350387: Received: { Ans: , MgmtId: 7200344900649, via: 1, Ver: v1, Flags: 10, { Answer } } > 2013-07-09 16:30:32,225 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35) 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:3784) > at com.cloud.network.router.VirtualNetworkApplianceManagerImpl.applyUserData(VirtualNetworkApplianceManagerImpl.java:2977) > at com.cloud.network.element.VirtualRouterElement.addPasswordAndUserdata(VirtualRouterElement.java:944) > at com.cloud.network.NetworkManagerImpl.prepareElement(NetworkManagerImpl.java:2006) > at com.cloud.network.NetworkManagerImpl.prepareNic(NetworkManagerImpl.java:2112) > at com.cloud.network.NetworkManagerImpl.prepare(NetworkManagerImpl.java:2053) > at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:849) > at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:557) > at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:239) > at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209) > at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3317) > at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2877) > at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:2863) > 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:155) > at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:513) > 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-07-09 16:30:32,230 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-35:job-35) Cleaning up resources for the vm VM[User|hello-14] in Starting state > 2013-07-09 16:30:32,231 DEBUG [agent.transport.Request] (Job-Executor-35:job-35) Seq 1-729350390: Sending { Cmd , MgmtId: 7200344900649, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-3-27-VM","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