[
https://issues.apache.org/jira/browse/CLOUDSTACK-4624?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13797793#comment-13797793
]
Paul Angus commented on CLOUDSTACK-4624:
----------------------------------------
Yes, /var/run/cloud does exist, and it contains i-2-76-VM.log and r-32-VM.log.
i-2-76-VM.log contains:
i-2-76-VM,76,[IP_REDACTED],12,2602c3ba6866a7a5d48335c74c185df5,1,06:f8:32:00:05:32
> 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, Future
> Environment: CloudStack 4.2.0 with XenServer 6.1 or 6.2
> Reporter: Paul Angus
> Assignee: Jayapal Reddy
> Priority: Critical
> Fix For: 4.2.1
>
>
> 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 was sent by Atlassian JIRA
(v6.1#6144)
