cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Paul Angus (JIRA)" <j...@apache.org>
Subject [jira] [Created] (CLOUDSTACK-4624) VM Migration fails in 'Security Group Enabled Advanced Zone' with CloudRuntimeException: callHostPlugin failed for cmd: network_rules
Date Fri, 06 Sep 2013 13:31:52 GMT
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

Mime
View raw message