You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Paul Angus (JIRA)" <ji...@apache.org> on 2013/09/06 15:31:52 UTC
[jira] [Created] (CLOUDSTACK-4624) VM Migration fails in 'Security
Group Enabled Advanced Zone' with CloudRuntimeException: callHostPlugin
failed for cmd: network_rules
Paul Angus created CLOUDSTACK-4624:
--------------------------------------
Summary: VM Migration fails in 'Security Group Enabled Advanced Zone' with CloudRuntimeException: callHostPlugin failed for cmd: network_rules
Key: CLOUDSTACK-4624
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4624
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: XenServer
Affects Versions: 4.2.0
Environment: CloudStack 4.2.0 with XenServer 6.1 or 6.2
Reporter: Paul Angus
VM Migration fails in a 'Security Group Enabled Advanced Zone' with CloudRuntimeException: callHostPlugin failed for cmd: network_rules
013-09-06 14:18:07,711 DEBUG [network.security.SecurityGroupManagerImpl] (Job-Executor-16:job-64 = [ 16e9e8e3-460e-4a72-a455-d65b01f3b360 ]) Security Group Mgr v2: scheduling ruleset updates for 1 vms (unique=1), current queue size=0
2013-09-06 14:18:07,715 DEBUG [network.security.SecurityGroupManagerImpl] (Job-Executor-16:job-64 = [ 16e9e8e3-460e-4a72-a455-d65b01f3b360 ]) Security Group Mgr v2: done scheduling ruleset updates for 1 vms: num new jobs=1 num rows insert or updated=1 time taken=4
2013-09-06 14:18:07,715 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-16:job-64 = [ 16e9e8e3-460e-4a72-a455-d65b01f3b360 ]) VM state transitted from :Migrating to Running with event: OperationSucceededvm's original host id: 7 new host id: 8 host id before state transition: 8
2013-09-06 14:18:07,721 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-244:null) Ping from 5
2013-09-06 14:18:07,728 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-16:job-64 = [ 16e9e8e3-460e-4a72-a455-d65b01f3b360 ]) Hosts's actual total CPU: 63840 and CPU after applying overprovisioning: 127680
2013-09-06 14:18:07,729 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-16:job-64 = [ 16e9e8e3-460e-4a72-a455-d65b01f3b360 ]) Hosts's actual total RAM: 267404820480 and RAM after applying overprovisioning: 267404820480
2013-09-06 14:18:07,729 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-16:job-64 = [ 16e9e8e3-460e-4a72-a455-d65b01f3b360 ]) release cpu from host: 7, old used: 1000,reserved: 0, actual total: 63840, total with overprovisioning: 127680; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-09-06 14:18:07,729 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-16:job-64 = [ 16e9e8e3-460e-4a72-a455-d65b01f3b360 ]) release mem from host: 7, old used: 1073741824,reserved: 0, total: 267404820480; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-09-06 14:18:07,731 DEBUG [cloud.api.ApiServlet] (catalina-exec-18:null) ===START=== 10.67.9.233 -- GET command=queryAsyncJobResult&jobId=16e9e8e3-460e-4a72-a455-d65b01f3b360&response=json&sessionkey=hLoqoRm93LQk67lSOtoBQZludFg%3D&_=1378473487668
2013-09-06 14:18:07,738 DEBUG [agent.transport.Request] (Job-Executor-16:job-64 = [ 16e9e8e3-460e-4a72-a455-d65b01f3b360 ]) Seq 8-576979043: Sending { Cmd , MgmtId: 345052351047, via: 8, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.CheckVirtualMachineCommand":{"vmName":"i-2-11-VM","wait":20}}] }
2013-09-06 14:18:07,738 DEBUG [agent.transport.Request] (Job-Executor-16:job-64 = [ 16e9e8e3-460e-4a72-a455-d65b01f3b360 ]) Seq 8-576979043: Executing: { Cmd , MgmtId: 345052351047, via: 8, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.CheckVirtualMachineCommand":{"vmName":"i-2-11-VM","wait":20}}] }
2013-09-06 14:18:07,739 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-436:null) Seq 8-576979043: Executing request
2013-09-06 14:18:07,747 DEBUG [network.security.SecurityGroupManagerImpl] (SecGrp-Worker-41:null) SecurityGroupManager v2: sending ruleset update for vm i-2-11-VM:ingress num rules=4:egress num rules=0 num cidrs=6 sig=8ccd7a72119d5c8180377d3cd847c10f
2013-09-06 14:18:07,750 DEBUG [agent.transport.Request] (SecGrp-Worker-41:null) Seq 8-576979044: Sending { Cmd , MgmtId: 345052351047, via: 8, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.SecurityGroupRulesCmd":{"guestIp":"10.79.129.49","vmName":"i-2-11-VM","guestMac":"06:b5:fa:00:07:25","signature":"8ccd7a72119d5c8180377d3cd847c10f","seqNum":11,"vmId":11,"msId":345052351047,"ingressRuleSet":[{"proto":"icmp","startPort":-1,"endPort":-1},{"proto":"tcp","startPort":1,"endPort":65535},{"proto":"tcp","startPort":22,"endPort":22},{"proto":"udp","startPort":1,"endPort":65535}],"egressRuleSet":[],"wait":0}}] }
2013-09-06 14:18:07,750 DEBUG [agent.transport.Request] (SecGrp-Worker-41:null) Seq 8-576979044: Executing: { Cmd , MgmtId: 345052351047, via: 8, Ver: v1, Flags: 100111, [{"com.cloud.agent.api.SecurityGroupRulesCmd":{"guestIp":"10.79.129.49","vmName":"i-2-11-VM","guestMac":"06:b5:fa:00:07:25","signature":"8ccd7a72119d5c8180377d3cd847c10f","seqNum":11,"vmId":11,"msId":345052351047,"ingressRuleSet":[{"proto":"icmp","startPort":-1,"endPort":-1},{"proto":"tcp","startPort":1,"endPort":65535},{"proto":"tcp","startPort":22,"endPort":22},{"proto":"udp","startPort":1,"endPort":65535}],"egressRuleSet":[],"wait":0}}] }
2013-09-06 14:18:07,750 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-406:null) Seq 8-576979044: Executing request
2013-09-06 14:18:07,765 DEBUG [cloud.api.ApiServlet] (catalina-exec-18:null) ===END=== 10.67.9.233 -- GET command=queryAsyncJobResult&jobId=16e9e8e3-460e-4a72-a455-d65b01f3b360&response=json&sessionkey=hLoqoRm93LQk67lSOtoBQZludFg%3D&_=1378473487668
2013-09-06 14:18:07,773 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) SeqA 14-366: Processing Seq 14-366: { Cmd , MgmtId: -1, via: 14, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":4,"_loadInfo":"{\n \"connections\": [\n {\n \"id\": 2,\n \"clientInfo\": \"\",\n \"host\": \"10.79.149.198\",\n \"port\": -1,\n \"tag\": \"d40c2f3a-7677-4e8f-abb4-ee40ca6e4ff9\",\n \"createTime\": 1378472362519,\n \"lastUsedTime\": 1378473485748\n },\n {\n \"id\": 1,\n \"clientInfo\": \"\",\n \"host\": \"10.79.149.196\",\n \"port\": -1,\n \"tag\": \"e4a541da-d89c-45f2-afe4-cd8899b85a81\",\n \"createTime\": 1378472139707,\n \"lastUsedTime\": 1378473486795\n }\n ]\n}","wait":0}}] }
2013-09-06 14:18:07,779 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-9:null) SeqA 14-366: Sending Seq 14-366: { Ans: , MgmtId: 345052351047, via: 14, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2013-09-06 14:18:07,868 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-457:null) Ping from 4
2013-09-06 14:18:07,900 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-436:null) 3. The VM i-2-11-VM is in Running state
2013-09-06 14:18:07,900 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-436:null) Seq 8-576979043: Response Received:
2013-09-06 14:18:07,901 DEBUG [agent.transport.Request] (DirectAgent-436:null) Seq 8-576979043: Processing: { Ans: , MgmtId: 345052351047, via: 8, Ver: v1, Flags: 10, [{"com.cloud.agent.api.CheckVirtualMachineAnswer":{"state":"Running","result":true,"wait":0}}] }
2013-09-06 14:18:07,901 DEBUG [agent.transport.Request] (Job-Executor-16:job-64 = [ 16e9e8e3-460e-4a72-a455-d65b01f3b360 ]) Seq 8-576979043: Received: { Ans: , MgmtId: 345052351047, via: 8, Ver: v1, Flags: 10, { CheckVirtualMachineAnswer } }
2013-09-06 14:18:07,942 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-16:job-64 = [ 16e9e8e3-460e-4a72-a455-d65b01f3b360 ]) Complete async job-64 = [ 16e9e8e3-460e-4a72-a455-d65b01f3b360 ], jobStatus: 1, resultCode: 0, result: org.apache.cloudstack.api.response.UserVmResponse@18546902
2013-09-06 14:18:07,947 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-16:job-64 = [ 16e9e8e3-460e-4a72-a455-d65b01f3b360 ]) Done executing org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd for job-64 = [ 16e9e8e3-460e-4a72-a455-d65b01f3b360 ]
2013-09-06 14:18:07,979 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-292:null) Ping from 3
2013-09-06 14:18:08,272 WARN [xen.resource.CitrixResourceBase] (DirectAgent-406:null) callHostPlugin failed for cmd: network_rules with args seqno: 11, vmIP: 10.79.129.49, deflated: true, secIps: 0:, vmID: 11, vmMAC: 06:b5:fa:00:07:25, vmName: i-2-11-VM, rules: eJzztMpMzi2w0jUEIQM9MNQ30PFzjQhR8LQqSS6wMrQyMzU1NrUyNNAzt9QzNLLUMzHXNzbSQeJbgvhIWoyMQMgQZpwFTK40hUTjAHzDJCY=, signature: 8ccd7a72119d5c8180377d3cd847c10f, due to There was a failure communicating with the plugin.
2013-09-06 14:18:08,273 WARN [agent.manager.DirectAgentAttache] (DirectAgent-406:null) Seq 8-576979044: Exception Caught while executing command
com.cloud.utils.exception.CloudRuntimeException: callHostPlugin failed for cmd: network_rules with args seqno: 11, vmIP: 10.79.129.49, deflated: true, secIps: 0:, vmID: 11, vmMAC: 06:b5:fa:00:07:25, vmName: i-2-11-VM, rules: eJzztMpMzi2w0jUEIQM9MNQ30PFzjQhR8LQqSS6wMrQyMzU1NrUyNNAzt9QzNLLUMzHXNzbSQeJbgvhIWoyMQMgQZpwFTK40hUTjAHzDJCY=, signature: 8ccd7a72119d5c8180377d3cd847c10f, due to There was a failure communicating with the plugin.
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.callHostPlugin(CitrixResourceBase.java:4188)
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:5776)
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:561)
at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:104)
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:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
--
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