Sanjeev N created CLOUDSTACK-4937:
-------------------------------------
Summary: Failed to Stop or Destroy Virtual Router from CS
Key: CLOUDSTACK-4937
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4937
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Management Server, Virtual Router
Affects Versions: 4.2.1
Environment: Build from 4.2 branch with commit
f9731144cda4d7982cc4be1e60c1e4aa3b3ca2e2
Reporter: Sanjeev N
Fix For: 4.2.1
Failed to Stop or Destroy Virtual Router from CS
Steps to Reproduce:
=================
1.Bring up CS in basic/advanced zone with Xen6.2
2.Deploy guest vm with default cent os template
3.Now try to stop VR from UI or destroy VR using destroyRouter API
Expected Result:
==============
VR should go to stopped state
Actual Result:
============
CS throws error saying "Failed to stop VR" or "Failed to destroy router"
Observations:
============
>From XenServer we see stop succeed response in stopAnswer. However CS says
>unable to stop vm.
Following are the sequence of events:
2013-10-23 07:12:20,688 DEBUG [cloud.async.AsyncJobManagerImpl]
(ApiServer-6:null) submit async job-36 = [ f9db8c4a-148b-49a4-8538-8818c812e22a
], details: AsyncJobVO {id:36, userId: 1, accountId: 1, sessionKey: null,
instanceType: DomainRouter, instanceId: 3984, cmd:
org.apache.cloudstack.api.command.admin.router.DestroyRouterCmd, cmdOriginator:
null, cmdInfo:
{"id":"28166729-6498-454b-b930-6051833e1b27","cmdEventType":"ROUTER.DESTROY","ctxUserId":"1","httpmethod":"GET","ctxAccountId":"1","ctxStartEventId":"144"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
processStatus: 0, resultCode: 0, result: null, initMsid: 6615759585382,
completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-10-23 07:12:20,696 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-36:job-36 = [ f9db8c4a-148b-49a4-8538-8818c812e22a ]) Executing
org.apache.cloudstack.api.command.admin.router.DestroyRouterCmd for job-36 = [
f9db8c4a-148b-49a4-8538-8818c812e22a ]
2013-10-23 07:12:20,711 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-36:job-36 = [
f9db8c4a-148b-49a4-8538-8818c812e22a ]) Attempting to destroy router 3984
2013-10-23 07:12:20,733 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-36:job-36 = [ f9db8c4a-148b-49a4-8538-8818c812e22a ]) VM state
transitted from :Running to Stopping with event: StopRequestedvm's original
host id: 4 new host id: 4 host id before state transition: 4
2013-10-23 07:12:20,745 DEBUG [agent.transport.Request] (Job-Executor-36:job-36
= [ f9db8c4a-148b-49a4-8538-8818c812e22a ]) Seq 4-35651885: Sending { Cmd ,
MgmtId: 6615759585382, via: 4, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"r-3984-VM","wait":0}}]
}
2013-10-23 07:12:20,745 DEBUG [agent.transport.Request] (Job-Executor-36:job-36
= [ f9db8c4a-148b-49a4-8538-8818c812e22a ]) Seq 4-35651885: Executing: { Cmd ,
MgmtId: 6615759585382, via: 4, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"r-3984-VM","wait":0}}]
}
2013-10-23 07:12:20,745 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-272:null) Seq 4-35651885: Executing request
2013-10-23 07:12:20,833 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-272:null) 9. The VM r-3984-VM is in Stopping state
2013-10-23 07:12:21,081 INFO [xen.resource.CitrixResourceBase]
(DirectAgent-272:null) Removed network rules for vm r-3984-VM
2013-10-23 07:12:23,150 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-356:null) Seq 4-35651588: Executing request
2013-10-23 07:12:23,383 WARN [xen.resource.CitrixResourceBase]
(DirectAgent-356:null) Detecting a change in xstoolsversion for r-3984-VM
2013-10-23 07:12:23,384 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-356:null) 11. The VM r-3984-VM is in Running state
2013-10-23 07:12:23,384 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-356:null) Seq 4-35651588: Response Received:
2013-10-23 07:12:23,385 DEBUG [agent.transport.Request] (DirectAgent-356:null)
Seq 4-35651588: Processing: { Ans: , MgmtId: 6615759585382, via: 4, Ver: v1,
Flags: 10,
[{"com.cloud.agent.api.ClusterSyncAnswer":{"_clusterId":2,"_newStates":{"r-3984-VM":{"t":"7a6899bb-62ed-4585-97ea-dc0f45547364","u":"Running","v":"xenserver56"}},"_isExecuted":false,"result":true,"wait":0}}]
}
2013-10-23 07:12:23,391 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(DirectAgent-356:null) VM r-3984-VM: cs state = Stopping and realState = Running
2013-10-23 07:12:23,392 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(DirectAgent-356:null) VM r-3984-VM: cs state = Stopping and realState = Running
2013-10-23 07:12:23,392 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(DirectAgent-356:null) Scheduling a stop command for VM[DomainRouter|r-3984-VM]
2013-10-23 07:12:23,394 INFO [cloud.ha.HighAvailabilityManagerImpl]
(DirectAgent-356:null) There's already a job scheduled to stop
VM[DomainRouter|r-3984-VM]
2013-10-23 07:12:24,996 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-9:null) SeqA 6-938: Processing Seq 6-938: { Cmd ,
MgmtId: -1, via: 6, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":3982,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2013-10-23 07:12:25,003 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-9:null) SeqA 6-938: Sending Seq 6-938: { Ans: , MgmtId:
6615759585382, via: 6, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2013-10-23 07:12:29,148 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-272:null) 10. The VM r-3984-VM is in Stopped state
2013-10-23 07:12:29,148 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-272:null) Seq 4-35651885: Response Received:
2013-10-23 07:12:29,149 DEBUG [agent.transport.Request] (DirectAgent-272:null)
Seq 4-35651885: Processing: { Ans: , MgmtId: 6615759585382, via: 4, Ver: v1,
Flags: 110,
[{"com.cloud.agent.api.StopAnswer":{"hypervisortoolsversion":"xenserver56","result":true,"details":"Stop
VM r-3984-VM Succeed","wait":0}}] }
2013-10-23 07:12:29,149 DEBUG [agent.transport.Request] (Job-Executor-36:job-36
= [ f9db8c4a-148b-49a4-8538-8818c812e22a ]) Seq 4-35651885: Received: { Ans: ,
MgmtId: 6615759585382, via: 4, Ver: v1, Flags: 110, { StopAnswer } }
2013-10-23 07:12:29,151 WARN [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-36:job-36 = [ f9db8c4a-148b-49a4-8538-8818c812e22a ]) Unable to
stop vm VM[DomainRouter|r-3984-VM]
2013-10-23 07:12:29,154 DEBUG [agent.manager.AgentAttache]
(DirectAgent-272:null) Seq 4-35651885: No more commands found
2013-10-23 07:12:29,255 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-36:job-36 = [ f9db8c4a-148b-49a4-8538-8818c812e22a ]) VM state
transitted from :Stopping to Running with event: OperationFailedvm's original
host id: 4 new host id: 4 host id before state transition: 4
2013-10-23 07:12:29,255 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-36:job-36 = [ f9db8c4a-148b-49a4-8538-8818c812e22a ]) Unable to
stop the VM so we can't expunge it.
2013-10-23 07:12:29,257 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-36:job-36 = [ f9db8c4a-148b-49a4-8538-8818c812e22a ]) Unable to
destroy the vm because it is not in the correct state:
VM[DomainRouter|r-3984-VM]
2013-10-23 07:12:29,257 INFO [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-36:job-36 = [ f9db8c4a-148b-49a4-8538-8818c812e22a ]) Did not
expunge VM[DomainRouter|r-3984-VM]
2013-10-23 07:12:29,260 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-36:job-36 = [ f9db8c4a-148b-49a4-8538-8818c812e22a ]) Complete
async job-36 = [ f9db8c4a-148b-49a4-8538-8818c812e22a ], jobStatus: 2,
resultCode: 530, result: Error Code: 530 Error text: Failed to destroy router
Attaching latest log from management server.
--
This message was sent by Atlassian JIRA
(v6.1#6144)
