cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Pavan Kumar Bandarupally (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CLOUDSTACK-5005) issue with stopping vms parallelly
Date Fri, 01 Nov 2013 07:41:19 GMT

    [ https://issues.apache.org/jira/browse/CLOUDSTACK-5005?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13811105#comment-13811105
] 

Pavan Kumar Bandarupally commented on CLOUDSTACK-5005:
------------------------------------------------------

I have seen this issue even when it is not a parallel VM deployment. Here are job traces:

-------------------------------------------------------------- 

2013-11-01 18:12:35,690 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-3:null) submit
async job-41 = [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c ], details: AsyncJobVO {id:41, userId:
2, accountId: 2, sessionKey: null, instanceType: VirtualMachine, instanceId: 3, cmd: org.apache.cloudstack.api.command.user.vm.StopVMCmd,
cmdOriginator: null, cmdInfo: {"id":"f69ea75b-b3cd-4f74-8810-866bd0d557d5","response":"json","sessionkey":"VXAURlAF7J9QjdwOd2+hXFtYzQQ\u003d","cmdEventType":"VM.STOP","ctxUserId":"2","httpmethod":"GET","_":"1383290487063","ctxAccountId":"2","ctxStartEventId":"151","forced":"false"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode:
0, result: null, initMsid: 6804838809635, completeMsid: null, lastUpdated: null, lastPolled:
null, created: null}
2013-11-01 18:12:35,694 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-19:job-41 =
[ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c ]) Executing org.apache.cloudstack.api.command.user.vm.StopVMCmd
for job-41 = [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c ]
2013-11-01 18:12:35,701 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-19:job-41 = [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c
]) ControlledEntity name is:com.cloud.vm.VirtualMachine
2013-11-01 18:12:35,703 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-19:job-41 = [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c
]) ControlledEntity name is:com.cloud.uservm.UserVm
2013-11-01 18:12:35,704 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-19:job-41 = [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c
]) ControlledEntity name is:com.cloud.network.router.VirtualRouter
2013-11-01 18:12:35,736 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-19:job-41
= [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c ]) VM state transitted from :Running to Stopping
with event: StopRequestedvm's original host id: 1 new host id: 1 host id before state transition:
1
2013-11-01 18:12:35,740 DEBUG [agent.transport.Request] (Job-Executor-19:job-41 = [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c
]) Seq 1-1827016164: Sending  { Cmd , MgmtId: 6804838809635, via: 1, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-3-VM","wait":0}}]
}
2013-11-01 18:12:35,740 DEBUG [agent.transport.Request] (Job-Executor-19:job-41 = [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c
]) Seq 1-1827016164: Executing:  { Cmd , MgmtId: 6804838809635, via: 1, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-2-3-VM","wait":0}}]
}
2013-11-01 18:12:59,595 DEBUG [agent.transport.Request] (Job-Executor-19:job-41 = [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c
]) Seq 1-1827016164: Received:  { Ans: , MgmtId: 6804838809635, via: 1, Ver: v1, Flags: 110,
{ StopAnswer } }
2013-11-01 18:12:59,671 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-19:job-41
= [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c ]) VM[User|w2k8R2NoPV] is stopped on the host.  Proceeding
to release resource held.
2013-11-01 18:12:59,687 DEBUG [db.Transaction.Transaction] (Job-Executor-19:job-41 = [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c
]) Rolling back the transaction: Time = 9 Name =  -AsyncJobManagerImpl$1.run:494-Executors$RunnableAdapter.call:471-FutureTask$Sync.innerRun:334-FutureTask.run:166-ThreadPoolExecutor.runWorker:1110-ThreadPoolExecutor$Worker.run:603-Thread.run:679;
called by -Transaction.rollback:897-Transaction.removeUpTo:840-Transaction.close:664-TransactionContextBuilder.interceptComplete:56-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:131-NetworkManagerImpl.release:2394-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-VirtualMachineManagerImpl.advanceStop:1324-VirtualMachineManagerImpl.stop:1053-VMEntityManagerImpl.stopvirtualmachine:251-VirtualMachineEntityImpl.stop:214-UserVmManagerImpl.stopVirtualMachine:3255
2013-11-01 18:12:59,691 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-19:job-41
= [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c ]) Successfully released network resources for the
vm VM[User|w2k8R2NoPV]
2013-11-01 18:12:59,691 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-19:job-41
= [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c ]) Successfully released storage resources for the
vm VM[User|w2k8R2NoPV]
2013-11-01 18:12:59,705 DEBUG [vm.dao.VMInstanceDaoImpl] (Job-Executor-19:job-41 = [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c
]) Unable to update VM[User|w2k8R2NoPV]: DB Data={Host=null; State=Stopped; updated=15; time=Fri
Nov 01 18:12:59 IST 2013} New Data: {Host=null; State=Stopped; updated=15; time=Fri Nov 01
18:12:59 IST 2013} Stale Data: {Host=1; State=Stopping; updated=14; time=Fri Nov 01 18:12:35
IST 2013}
2013-11-01 18:12:59,726 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-19:job-41 =
[ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c ]) Complete async job-41 = [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c
], jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: Failed to stop vm
2013-11-01 18:12:59,768 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-7:null) Async
job-41 = [ bd013e4f-d898-4c97-9c77-b2ead3dbfd6c ] completed


---------------------------------------------------------------

> issue with stopping vms parallelly 
> -----------------------------------
>
>                 Key: CLOUDSTACK-5005
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5005
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>    Affects Versions: 4.2.1
>            Reporter: prashant kumar mishra
>            Assignee: Sheng Yang
>         Attachments: MS_XEN_DB.rar
>
>
> steps to reproduce
> ---------------------------
> 1-prepare CS setup with xen 6.1
> 2-set execute.in.sequence.hypervisor.commands and execute.in.sequence.network.element.commands
to false
> 3-Restart MS
> 4-deploy 35 vms parallelly with default centOS template
> 5-try to stop all uservms using script
> Expected
> -------------
> All vms should  get  stopped , 
> Actual
> ------------
> before vms went in stopped state , Log show error messages
> Logs
> --------
> [root@localhost ~]# grep "job-436" /var/log/cloudstack/management/management-server.log
> 2013-10-30 12:21:57,817 DEBUG [cloud.async.AsyncJobManagerImpl] (ApiServer-1:null) submit
async job-436 = [ 432f8bd7-8f4b-4e72-b69b-b148fc1733dc ], details: AsyncJobVO {id:436, userId:
1, accountId: 1, sessionKey: null, instanceType: VirtualMachine, instanceId: 78, cmd: org.apache.cloudstack.api.command.user.vm.StopVMCmd,
cmdOriginator: null, cmdInfo: {"id":"78","cmdEventType":"VM.STOP","ctxUserId":"1","httpmethod":"GET","ctxAccountId":"1","ctxStartEventId":"1384"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode:
0, result: null, initMsid: 7484181839895, completeMsid: null, lastUpdated: null, lastPolled:
null, created: null}
> 2013-10-30 12:21:57,818 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-122:job-436
= [ 432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) Executing org.apache.cloudstack.api.command.user.vm.StopVMCmd
for job-436 = [ 432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]
> 2013-10-30 12:21:57,941 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-122:job-436 = [
432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) ControlledEntity name is:com.cloud.vm.VirtualMachine
> 2013-10-30 12:21:58,056 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-122:job-436 = [
432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) ControlledEntity name is:com.cloud.uservm.UserVm
> 2013-10-30 12:21:58,111 DEBUG [cloud.api.ApiDispatcher] (Job-Executor-122:job-436 = [
432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) ControlledEntity name is:com.cloud.network.router.VirtualRouter
> 2013-10-30 12:21:58,528 DEBUG [cloud.capacity.CapacityManagerImpl] (Job-Executor-122:job-436
= [ 432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) VM state transitted from :Running to Stopping
with event: StopRequestedvm's original host id: 3 new host id: 3 host id before state transition:
3
> 2013-10-30 12:21:58,696 DEBUG [agent.transport.Request] (Job-Executor-122:job-436 = [
432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) Seq 3-125568146: Sending  { Cmd , MgmtId: 7484181839895,
via: 3, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-2-78-VM","wait":0}}]
}
> 2013-10-30 12:21:58,696 DEBUG [agent.transport.Request] (Job-Executor-122:job-436 = [
432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) Seq 3-125568146: Executing:  { Cmd , MgmtId: 7484181839895,
via: 3, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-2-78-VM","wait":0}}]
}
> 2013-10-30 12:22:58,051 DEBUG [agent.transport.Request] (Job-Executor-122:job-436 = [
432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) Seq 3-125568146: Received:  { Ans: , MgmtId: 7484181839895,
via: 3, Ver: v1, Flags: 10, { StopAnswer } }
> 2013-10-30 12:22:58,078 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-122:job-436
= [ 432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) VM[User|f1ad8bfe-b9a4-4669-a37c-f0edb2f0098f]
is stopped on the host.  Proceeding to release resource held.
> 2013-10-30 12:22:58,088 DEBUG [cloud.network.NetworkModelImpl] (Job-Executor-122:job-436
= [ 432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) Service SecurityGroup is not supported in the
network id=204
> 2013-10-30 12:22:58,095 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-122:job-436
= [ 432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) Changing active number of nics for network id=204
on -1
> 2013-10-30 12:22:58,123 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-122:job-436
= [ 432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) Asking VirtualRouter to release Nic[89-78-d1a70d9b-1e6e-4de8-bd4b-6f0649faf997-10.1.1.177]
> 2013-10-30 12:22:58,123 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-122:job-436
= [ 432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) Successfully released network resources for the
vm VM[User|f1ad8bfe-b9a4-4669-a37c-f0edb2f0098f]
> 2013-10-30 12:22:58,123 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-122:job-436
= [ 432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) Successfully released storage resources for the
vm VM[User|f1ad8bfe-b9a4-4669-a37c-f0edb2f0098f]
> 2013-10-30 12:22:58,141 DEBUG [vm.dao.VMInstanceDaoImpl] (Job-Executor-122:job-436 =
[ 432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) Unable to update VM[User|f1ad8bfe-b9a4-4669-a37c-f0edb2f0098f]:
DB Data={Host=3; State=Running; updated=5; time=Wed Oct 30 12:22:58 EDT 2013} New Data: {Host=null;
State=Stopped; updated=5; time=Wed Oct 30 12:22:58 EDT 2013} Stale Data: {Host=3; State=Stopping;
updated=4; time=Wed Oct 30 12:21:58 EDT 2013}
> 2013-10-30 12:22:58,161 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-122:job-436
= [ 432f8bd7-8f4b-4e72-b69b-b148fc1733dc ]) Complete async job-436 = [ 432f8bd7-8f4b-4e72-b69b-b148fc1733dc
], jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: Failed to stop vm
> Log2
> -------
> 2013-10-30 12:25:54,535 INFO  [xen.resource.XenServer56Resource] (DirectAgent-262:null)
Catch com.xensource.xenapi.Types$VifInUse: failed to destory VLAN eth0 on host 7f8a4f8f-1c15-4b7a-95cf-1f64b09ce674
due to Network has active VIFs



--
This message was sent by Atlassian JIRA
(v6.1#6144)

Mime
View raw message