Srikanteswararao Talluri created CLOUDSTACK-2336:
----------------------------------------------------
Summary: UI: SXM : wrong API is being called while trying to
migrate a VM with volume
Key: CLOUDSTACK-2336
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-2336
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: UI
Affects Versions: 4.2.0
Environment: Xenserver 6.1 with storage xenmotion feature enabled
Single zone with two clusters having shared storage pool for each cluster.
Reporter: Srikanteswararao Talluri
Priority: Critical
Fix For: 4.2.0
Refer to the environment section for setup used
>From UI:
1. In the virtual machine screen, Click on 'migrate' button to list the
suitable hosts to migrate the VM to.
2. Select a host which is in different cluster.
After selecting the host to migrate to,If VM is
1. being migrated to a host in the same cluster - migrateVirtualMachine API
should be called
otherwise if,
2. being migrated to a host in different cluster then
migrateVirtualMachineWithVolume API should be called.
Issue:
When user is trying to select a host in a different cluster to migrate to,
operation is failing for the first time (because migrateVirtualMachine is being
called instead of migrateVirtualMachineWithVolume ). However, it succeeds when
the host in the different cluster is listed first in the
'findHostsForMigration' API call
===START=== 10.252.242.121 -- GET
command=findHostsForMigration&VirtualMachineId=4f417cd8-055e-4efe-a466-3fba321f1666&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826850005
2013-05-06 18:50:17,947 DEBUG [cloud.storage.StorageManagerImpl]
(catalina-exec-2:null) Checking pool: 1 for volume allocation
[Vol[3|vm=3|ROOT]], maxSize : 11804569632768, totalAllocatedSize : 66748535808,
askingSize : 0, allocated disable threshold: 0.85
2013-05-06 18:50:18,017 DEBUG [cloud.storage.StorageManagerImpl]
(catalina-exec-2:null) Checking pool: 2 for volume allocation
[Vol[3|vm=3|ROOT]], maxSize : 11804569632768, totalAllocatedSize : 73190986752,
askingSize : 0, allocated disable threshold: 0.85
2013-05-06 18:50:18,068 DEBUG [cloud.storage.StorageManagerImpl]
(catalina-exec-2:null) Checking pool: 1 for volume allocation
[Vol[7|vm=3|DATADISK]], maxSize : 11804569632768, totalAllocatedSize :
66748535808, askingSize : 0, allocated disable threshold: 0.85
2013-05-06 18:50:18,138 DEBUG [cloud.storage.StorageManagerImpl]
(catalina-exec-2:null) Checking pool: 2 for volume allocation
[Vol[7|vm=3|DATADISK]], maxSize : 11804569632768, totalAllocatedSize :
73190986752, askingSize : 0, allocated disable threshold: 0.85
2013-05-06 18:50:18,218 DEBUG [cloud.storage.StorageManagerImpl]
(catalina-exec-2:null) Checking pool: 3 for volume allocation
[Vol[3|vm=3|ROOT]], maxSize : 11804569632768, totalAllocatedSize : 92518339584,
askingSize : 0, allocated disable threshold: 0.85
2013-05-06 18:50:18,296 DEBUG [cloud.storage.StorageManagerImpl]
(catalina-exec-2:null) Checking pool: 3 for volume allocation
[Vol[7|vm=3|DATADISK]], maxSize : 11804569632768, totalAllocatedSize :
92518339584, askingSize : 0, allocated disable threshold: 0.85
2013-05-06 18:50:18,306 DEBUG [allocator.impl.FirstFitAllocator]
(catalina-exec-2:null) FirstFitAllocator has 2 hosts to check for allocation:
[Host[-2-Routing], Host[-3-Routing]]
2013-05-06 18:50:18,312 DEBUG [allocator.impl.FirstFitAllocator]
(catalina-exec-2:null) Found 2 hosts for allocation after prioritization:
[Host[-2-Routing], Host[-3-Routing]]
2013-05-06 18:50:18,312 DEBUG [allocator.impl.FirstFitAllocator]
(catalina-exec-2:null) Looking for speed=500Mhz, Ram=512
2013-05-06 18:50:18,321 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) Checking if host: 2 has enough capacity for requested
CPU: 500 and requested RAM: 536870912 , cpuOverprovisioningFactor: 1.0
2013-05-06 18:50:18,325 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) Hosts's actual total CPU: 9576 and CPU after applying
overprovisioning: 9576
2013-05-06 18:50:18,325 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) considerReservedCapacity isfalse , not considering
reserved capacity for calculating free capacity
2013-05-06 18:50:18,325 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) Free CPU: 9076 , Requested CPU: 500
2013-05-06 18:50:18,326 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) Free RAM: 15921721344 , Requested RAM: 536870912
2013-05-06 18:50:18,326 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) Host has enough CPU and RAM available
2013-05-06 18:50:18,326 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) STATS: Can alloc CPU from host: 2, used: 500, reserved:
0, actual total: 9576, total with overprovisioning: 9576; requested
cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: false
2013-05-06 18:50:18,326 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) STATS: Can alloc MEM from host: 2, used: 268435456,
reserved: 0, total: 16190156800; requested mem:
536870912,alloc_from_last_host?:false ,considerReservedCapacity?: false
2013-05-06 18:50:18,326 DEBUG [allocator.impl.FirstFitAllocator]
(catalina-exec-2:null) Found a suitable host, adding to list: 2
2013-05-06 18:50:18,334 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) Checking if host: 3 has enough capacity for requested
CPU: 500 and requested RAM: 536870912 , cpuOverprovisioningFactor: 1.0
2013-05-06 18:50:18,338 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) Hosts's actual total CPU: 9580 and CPU after applying
overprovisioning: 9580
2013-05-06 18:50:18,338 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) considerReservedCapacity isfalse , not considering
reserved capacity for calculating free capacity
2013-05-06 18:50:18,338 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) Free CPU: 8480 , Requested CPU: 500
2013-05-06 18:50:18,338 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) Free RAM: 14982197248 , Requested RAM: 536870912
2013-05-06 18:50:18,338 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) Host has enough CPU and RAM available
2013-05-06 18:50:18,338 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) STATS: Can alloc CPU from host: 3, used: 1100, reserved:
0, actual total: 9580, total with overprovisioning: 9580; requested
cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: false
2013-05-06 18:50:18,338 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-2:null) STATS: Can alloc MEM from host: 3, used: 1207959552,
reserved: 0, total: 16190156800; requested mem:
536870912,alloc_from_last_host?:false ,considerReservedCapacity?: false
2013-05-06 18:50:18,338 DEBUG [allocator.impl.FirstFitAllocator]
(catalina-exec-2:null) Found a suitable host, adding to list: 3
2013-05-06 18:50:18,338 DEBUG [allocator.impl.FirstFitAllocator]
(catalina-exec-2:null) Host Allocator returning 2 suitable hosts
2013-05-06 18:50:18,339 DEBUG [cloud.server.ManagementServerImpl]
(catalina-exec-2:null) Hosts having capacity and suitable for migration:
[Host[-2-Routing], Host[-3-Routing]]
2013-05-06 18:50:18,358 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null)
===END=== 10.252.242.121 -- GET
command=findHostsForMigration&VirtualMachineId=4f417cd8-055e-4efe-a466-3fba321f1666&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826850005
2013-05-06 18:50:18,989 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-412:null) Ping from 2
2013-05-06 18:50:23,434 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-31:null) Ping from 3
2013-05-06 18:50:24,441 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-412:null) Seq 3-1946091524: Executing request
2013-05-06 18:50:24,756 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-412:null) Seq 3-1946091524: Response Received:
2013-05-06 18:50:24,757 DEBUG [agent.transport.Request] (DirectAgent-412:null)
Seq 3-1946091524: Processing: { Ans: , MgmtId: 7363452993625, via: 3, Ver: v1,
Flags: 10,
[{"ClusterSyncAnswer":{"_clusterId":2,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}]
}
2013-05-06 18:50:27,511 DEBUG [cloud.api.ApiServlet] (catalina-exec-23:null)
===START=== 10.252.242.121 -- GET
command=migrateVirtualMachine&hostid=180882a5-aa3e-4252-b42d-f405d3225a08&virtualmachineid=4f417cd8-055e-4efe-a466-3fba321f1666&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826859656
2013-05-06 18:50:27,566 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-23:null) submit async job-283, details: AsyncJobVO {id:283,
userId: 2, accountId: 2, sessionKey: null, instanceType: None, instanceId:
null, cmd: org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd,
cmdOriginator: null, cmdInfo:
{"response":"json","sessionkey":"cSc24xTjuz69EQZS4m5DA9c3Tpc\u003d","virtualmachineid":"4f417cd8-055e-4efe-a466-3fba321f1666","hostid":"180882a5-aa3e-4252-b42d-f405d3225a08","ctxUserId":"2","httpmethod":"GET","_":"1367826859656","ctxAccountId":"2","ctxStartEventId":"1338"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
processStatus: 0, resultCode: 0, result: null, initMsid: 7363452993625,
completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-05-06 18:50:27,569 DEBUG [cloud.api.ApiServlet] (catalina-exec-23:null)
===END=== 10.252.242.121 -- GET
command=migrateVirtualMachine&hostid=180882a5-aa3e-4252-b42d-f405d3225a08&virtualmachineid=4f417cd8-055e-4efe-a466-3fba321f1666&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826859656
2013-05-06 18:50:27,578 DEBUG [cloud.server.StatsCollector]
(StatsCollector-1:null) VmStatsCollector is running...
2013-05-06 18:50:27,579 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-13:job-283) Executing
org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd for job-283
2013-05-06 18:50:27,611 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-241:null) Seq 1-1011950818: Executing request
2013-05-06 18:50:27,674 INFO [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-13:job-283) Migrating VM[User|v] to
Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
: Dest[Zone(1)-Pod(1)-Cluster(2)-Host(3)-Storage()]
2013-05-06 18:50:27,683 INFO [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-13:job-283) Source and destination host are not in same cluster,
unable to migrate to host: 3
2013-05-06 18:50:27,729 ERROR [cloud.async.AsyncJobManagerImpl]
(Job-Executor-13:job-283) Unexpected exception while executing
org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd
com.cloud.utils.exception.CloudRuntimeException: Source and destination host
are not in same cluster, unable to migrate to host: 3
at
com.cloud.vm.VirtualMachineManagerImpl.migrate(VirtualMachineManagerImpl.java:1357)
at
com.cloud.vm.UserVmManagerImpl.migrateVirtualMachine(UserVmManagerImpl.java:3535)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
org.apache.cloudstack.api.command.admin.vm.MigrateVMCmd.execute(MigrateVMCmd.java:147)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:155)
at
com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:437)
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.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
2013-05-06 18:50:27,737 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-13:job-283) Complete async job-283, jobStatus: 2, resultCode:
530, result: Error Code: 530 Error text: Source and destination host are not in
same cluster, unable to migrate to host: 3
2013-05-06 18:50:27,889 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-241:null) Vm cpu utilization 0.0039062499999999996
2013-05-06 18:50:27,891 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-241:null) Seq 1-1011950818: Response Received:
2013-05-06 18:50:27,891 DEBUG [agent.transport.Request] (StatsCollector-1:null)
Seq 1-1011950818: Received: { Ans: , MgmtId: 7363452993625, via: 1, Ver: v1,
Flags: 10, { GetVmStatsAnswer } }
2013-05-06 18:50:27,912 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-309:null) Seq 3-1946102639: Executing request
2013-05-06 18:50:28,153 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-309:null) Vm cpu utilization 0.0039062499999999996
2013-05-06 18:50:28,153 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-309:null) Vm cpu utilization 0.0039062499999999996
2013-05-06 18:50:28,153 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-309:null) Seq 3-1946102639: Response Received:
2013-05-06 18:50:28,154 DEBUG [agent.transport.Request] (StatsCollector-1:null)
Seq 3-1946102639: Received: { Ans: , MgmtId: 7363452993625, via: 3, Ver: v1,
Flags: 10, { GetVmStatsAnswer } }
===START=== 10.252.242.121 -- GET
command=findHostsForMigration&VirtualMachineId=4f417cd8-055e-4efe-a466-3fba321f1666&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826924517
2013-05-06 18:51:32,468 DEBUG [cloud.storage.StorageManagerImpl]
(catalina-exec-10:null) Checking pool: 1 for volume allocation
[Vol[3|vm=3|ROOT]], maxSize : 11804569632768, totalAllocatedSize : 66748535808,
askingSize : 0, allocated disable threshold: 0.85
2013-05-06 18:51:32,542 DEBUG [cloud.storage.StorageManagerImpl]
(catalina-exec-10:null) Checking pool: 2 for volume allocation
[Vol[3|vm=3|ROOT]], maxSize : 11804569632768, totalAllocatedSize : 73190986752,
askingSize : 0, allocated disable threshold: 0.85
2013-05-06 18:51:32,597 DEBUG [cloud.storage.StorageManagerImpl]
(catalina-exec-10:null) Checking pool: 1 for volume allocation
[Vol[7|vm=3|DATADISK]], maxSize : 11804569632768, totalAllocatedSize :
66748535808, askingSize : 0, allocated disable threshold: 0.85
2013-05-06 18:51:32,670 DEBUG [cloud.storage.StorageManagerImpl]
(catalina-exec-10:null) Checking pool: 2 for volume allocation
[Vol[7|vm=3|DATADISK]], maxSize : 11804569632768, totalAllocatedSize :
73190986752, askingSize : 0, allocated disable threshold: 0.85
2013-05-06 18:51:32,780 DEBUG [cloud.storage.StorageManagerImpl]
(catalina-exec-10:null) Checking pool: 3 for volume allocation
[Vol[3|vm=3|ROOT]], maxSize : 11804569632768, totalAllocatedSize : 92518339584,
askingSize : 0, allocated disable threshold: 0.85
2013-05-06 18:51:32,866 DEBUG [cloud.storage.StorageManagerImpl]
(catalina-exec-10:null) Checking pool: 3 for volume allocation
[Vol[7|vm=3|DATADISK]], maxSize : 11804569632768, totalAllocatedSize :
92518339584, askingSize : 0, allocated disable threshold: 0.85
2013-05-06 18:51:32,875 DEBUG [allocator.impl.FirstFitAllocator]
(catalina-exec-10:null) FirstFitAllocator has 2 hosts to check for allocation:
[Host[-3-Routing], Host[-2-Routing]]
2013-05-06 18:51:32,882 DEBUG [allocator.impl.FirstFitAllocator]
(catalina-exec-10:null) Found 2 hosts for allocation after prioritization:
[Host[-3-Routing], Host[-2-Routing]]
2013-05-06 18:51:32,882 DEBUG [allocator.impl.FirstFitAllocator]
(catalina-exec-10:null) Looking for speed=500Mhz, Ram=512
2013-05-06 18:51:32,892 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) Checking if host: 3 has enough capacity for requested
CPU: 500 and requested RAM: 536870912 , cpuOverprovisioningFactor: 1.0
2013-05-06 18:51:32,896 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) Hosts's actual total CPU: 9580 and CPU after applying
overprovisioning: 9580
2013-05-06 18:51:32,897 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) considerReservedCapacity isfalse , not considering
reserved capacity for calculating free capacity
2013-05-06 18:51:32,897 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) Free CPU: 8480 , Requested CPU: 500
2013-05-06 18:51:32,897 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) Free RAM: 14982197248 , Requested RAM: 536870912
2013-05-06 18:51:32,897 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) Host has enough CPU and RAM available
2013-05-06 18:51:32,897 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) STATS: Can alloc CPU from host: 3, used: 1100,
reserved: 0, actual total: 9580, total with overprovisioning: 9580; requested
cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: false
2013-05-06 18:51:32,897 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) STATS: Can alloc MEM from host: 3, used: 1207959552,
reserved: 0, total: 16190156800; requested mem:
536870912,alloc_from_last_host?:false ,considerReservedCapacity?: false
2013-05-06 18:51:32,898 DEBUG [allocator.impl.FirstFitAllocator]
(catalina-exec-10:null) Found a suitable host, adding to list: 3
2013-05-06 18:51:32,907 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) Checking if host: 2 has enough capacity for requested
CPU: 500 and requested RAM: 536870912 , cpuOverprovisioningFactor: 1.0
2013-05-06 18:51:32,912 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) Hosts's actual total CPU: 9576 and CPU after applying
overprovisioning: 9576
2013-05-06 18:51:32,912 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) considerReservedCapacity isfalse , not considering
reserved capacity for calculating free capacity
2013-05-06 18:51:32,912 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) Free CPU: 9076 , Requested CPU: 500
2013-05-06 18:51:32,912 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) Free RAM: 15921721344 , Requested RAM: 536870912
2013-05-06 18:51:32,912 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) Host has enough CPU and RAM available
2013-05-06 18:51:32,912 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) STATS: Can alloc CPU from host: 2, used: 500, reserved:
0, actual total: 9576, total with overprovisioning: 9576; requested
cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: false
2013-05-06 18:51:32,912 DEBUG [cloud.capacity.CapacityManagerImpl]
(catalina-exec-10:null) STATS: Can alloc MEM from host: 2, used: 268435456,
reserved: 0, total: 16190156800; requested mem:
536870912,alloc_from_last_host?:false ,considerReservedCapacity?: false
2013-05-06 18:51:32,913 DEBUG [allocator.impl.FirstFitAllocator]
(catalina-exec-10:null) Found a suitable host, adding to list: 2
2013-05-06 18:51:32,913 DEBUG [allocator.impl.FirstFitAllocator]
(catalina-exec-10:null) Host Allocator returning 2 suitable hosts
2013-05-06 18:51:32,913 DEBUG [cloud.server.ManagementServerImpl]
(catalina-exec-10:null) Hosts having capacity and suitable for migration:
[Host[-3-Routing], Host[-2-Routing]]
2013-05-06 18:51:32,947 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null)
===END=== 10.252.242.121 -- GET
command=findHostsForMigration&VirtualMachineId=4f417cd8-055e-4efe-a466-3fba321f1666&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826924517
2013-05-06 18:51:34,531 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 3 routers to update status.
2013-05-06 18:51:34,534 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
2013-05-06 18:51:34,649 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 3 routers to update status.
2013-05-06 18:51:34,651 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
2013-05-06 18:51:36,896 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null)
===START=== 10.252.242.121 -- GET
command=migrateVirtualMachineWithVolume&hostid=180882a5-aa3e-4252-b42d-f405d3225a08&virtualmachineid=4f417cd8-055e-4efe-a466-3fba321f1666&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826929022
2013-05-06 18:51:36,953 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-44:job-284) Executing
org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd
for job-284
2013-05-06 18:51:36,955 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-1:null) submit async job-284, details: AsyncJobVO {id:284,
userId: 2, accountId: 2, sessionKey: null, instanceType: None, instanceId:
null, cmd:
org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd,
cmdOriginator: null, cmdInfo:
{"response":"json","sessionkey":"cSc24xTjuz69EQZS4m5DA9c3Tpc\u003d","virtualmachineid":"4f417cd8-055e-4efe-a466-3fba321f1666","hostid":"180882a5-aa3e-4252-b42d-f405d3225a08","ctxUserId":"2","httpmethod":"GET","_":"1367826929022","ctxAccountId":"2","ctxStartEventId":"1341"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
processStatus: 0, resultCode: 0, result: null, initMsid: 7363452993625,
completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-05-06 18:51:36,959 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null)
===END=== 10.252.242.121 -- GET
command=migrateVirtualMachineWithVolume&hostid=180882a5-aa3e-4252-b42d-f405d3225a08&virtualmachineid=4f417cd8-055e-4efe-a466-3fba321f1666&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826929022
2013-05-06 18:51:37,107 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-44:job-284) Checking pool: 3 for volume allocation
[Vol[3|vm=3|ROOT]], maxSize : 11804569632768, totalAllocatedSize : 92518339584,
askingSize : 0, allocated disable threshold: 0.85
2013-05-06 18:51:37,207 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-44:job-284) Checking pool: 3 for volume allocation
[Vol[7|vm=3|DATADISK]], maxSize : 11804569632768, totalAllocatedSize :
92518339584, askingSize : 0, allocated disable threshold: 0.85
2013-05-06 18:51:37,249 DEBUG [cloud.network.NetworkModelImpl]
(Job-Executor-44:job-284) Service SecurityGroup is not supported in the network
id=204
2013-05-06 18:51:37,256 DEBUG [cloud.storage.VolumeManagerImpl]
(Job-Executor-44:job-284) Preparing 2 volumes for VM[User|v]
2013-05-06 18:51:37,398 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-44:job-284) VM state transitted from :Running to Migrating with
event: MigrationRequestedvm's original host id: 1 new host id: 3 host id before
state transition: 1
2013-05-06 18:51:37,412 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-44:job-284) Hosts's actual total CPU: 9580 and CPU after applying
overprovisioning: 9580
2013-05-06 18:51:37,412 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-44:job-284) We are allocating VM, increasing the used capacity of
this host:3
2013-05-06 18:51:37,412 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-44:job-284) Current Used CPU: 1100 , Free CPU:8480 ,Requested
CPU: 500
2013-05-06 18:51:37,412 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-44:job-284) Current Used RAM: 1207959552 , Free RAM:14982197248
,Requested RAM: 536870912
2013-05-06 18:51:37,413 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-44:job-284) CPU STATS after allocation: for host: 3, old used:
1100, old reserved: 0, actual total: 9580, total with overprovisioning: 9580;
new used:1600, reserved:0; requested cpu:500,alloc_from_last:false
2013-05-06 18:51:37,413 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-44:job-284) RAM STATS after allocation: for host: 3, old used:
1207959552, old reserved: 0, total: 16190156800; new used: 1744830464,
reserved: 0; requested mem: 536870912,alloc_from_last:false
2013-05-06 18:51:37,543 DEBUG [agent.transport.Request]
(Job-Executor-44:job-284) Seq 3-1946102642: Sending { Cmd , MgmtId:
7363452993625, via: 3, Ver: v1, Flags: 100111,
[{"MigrateWithStorageReceiveCommand":{"vm":{"id":3,"name":"i-2-3-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"CentOS
5.3
(64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"b1861919b4daa27","params":{},"uuid":"4f417cd8-055e-4efe-a466-3fba321f1666","disks":[{"id":3,"name":"ROOT-3","mountPoint":"/export/home/automation/adv/primary","path":"d1dd1588-1d15-41fc-8cc7-9eb4b1ea9400","size":21474836480,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"55b65d1f-db5d-3b61-a01c-c2c285dbc469","deviceId":0},{"id":7,"name":"fsnap","mountPoint":"/export/home/automation/adv/primary","path":"0d735f7b-f237-4e83-8170-849944301d3b","size":21474836480,"type":"DATADISK","storagePoolType":"NetworkFilesystem","storagePoolUuid":"55b65d1f-db5d-3b61-a01c-c2c285dbc469","deviceId":1}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"49ab752f-4ed5-4bb8-9436-ba91f0cb0c91","ip":"10.1.1.25","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:1c:d3:00:01","dns1":"10.103.128.16","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1066","isolationUri":"vlan://1066","isSecurityGroupEnabled":false}]},"volumeToFiler":{"Vol[7|DATADISK|0d735f7b-f237-4e83-8170-849944301d3b|21474836480]":{"id":3,"uuid":"24cc9a0e-cf6c-30d7-9d17-5be24f28dbfc","host":"10.147.28.7","path":"/export/home/automation/adv/pri_2","port":2049,"type":"NetworkFilesystem"},"Vol[3|ROOT|d1dd1588-1d15-41fc-8cc7-9eb4b1ea9400|21474836480]":{"id":3,"uuid":"24cc9a0e-cf6c-30d7-9d17-5be24f28dbfc","host":"10.147.28.7","path":"/export/home/automation/adv/pri_2","port":2049,"type":"NetworkFilesystem"}},"wait":0}}]
}
2013-05-06 18:51:37,545 DEBUG [agent.transport.Request]
(Job-Executor-44:job-284) Seq 3-1946102642: Executing: { Cmd , MgmtId:
7363452993625, via: 3, Ver: v1, Flags: 100111,
[{"MigrateWithStorageReceiveCommand":{"vm":{"id":3,"name":"i-2-3-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"CentOS
5.3
(64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"b1861919b4daa27","params":{},"uuid":"4f417cd8-055e-4efe-a466-3fba321f1666","disks":[{"id":3,"name":"ROOT-3","mountPoint":"/export/home/automation/adv/primary","path":"d1dd1588-1d15-41fc-8cc7-9eb4b1ea9400","size":21474836480,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"55b65d1f-db5d-3b61-a01c-c2c285dbc469","deviceId":0},{"id":7,"name":"fsnap","mountPoint":"/export/home/automation/adv/primary","path":"0d735f7b-f237-4e83-8170-849944301d3b","size":21474836480,"type":"DATADISK","storagePoolType":"NetworkFilesystem","storagePoolUuid":"55b65d1f-db5d-3b61-a01c-c2c285dbc469","deviceId":1}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"49ab752f-4ed5-4bb8-9436-ba91f0cb0c91","ip":"10.1.1.25","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:1c:d3:00:01","dns1":"10.103.128.16","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1066","isolationUri":"vlan://1066","isSecurityGroupEnabled":false}]},"volumeToFiler":{"Vol[7|DATADISK|0d735f7b-f237-4e83-8170-849944301d3b|21474836480]":{"id":3,"uuid":"24cc9a0e-cf6c-30d7-9d17-5be24f28dbfc","host":"10.147.28.7","path":"/export/home/automation/adv/pri_2","port":2049,"type":"NetworkFilesystem"},"Vol[3|ROOT|d1dd1588-1d15-41fc-8cc7-9eb4b1ea9400|21474836480]":{"id":3,"uuid":"24cc9a0e-cf6c-30d7-9d17-5be24f28dbfc","host":"10.147.28.7","path":"/export/home/automation/adv/pri_2","port":2049,"type":"NetworkFilesystem"}},"wait":0}}]
}
2013-05-06 18:51:37,545 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-33:null) Seq 3-1946102642: Executing request
2013-05-06 18:51:37,640 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-33:null) SR retrieved for 24cc9a0e-cf6c-30d7-9d17-5be24f28dbfc
2013-05-06 18:51:37,653 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-33:null) Checking 24cc9a0e-cf6c-30d7-9d17-5be24f28dbfc or SR
d6afa8fe-7efe-c1ef-c9c5-d2c291264a66 on
XS[00764661-54a6-4d72-b9ae-fccd5d787eb8-10.147.40.20]
2013-05-06 18:51:37,669 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-33:null) SR retrieved for 24cc9a0e-cf6c-30d7-9d17-5be24f28dbfc
2013-05-06 18:51:37,681 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-33:null) Checking 24cc9a0e-cf6c-30d7-9d17-5be24f28dbfc or SR
d6afa8fe-7efe-c1ef-c9c5-d2c291264a66 on
XS[00764661-54a6-4d72-b9ae-fccd5d787eb8-10.147.40.20]
2013-05-06 18:51:37,740 DEBUG [xen.resource.CitrixResourceBase]
(DirectAgent-33:null) Found a network called
VLAN-3bdb6062-aff5-a3e9-b3c6-724289b3c0b5-1066 on host=10.147.40.20;
Network=13b75a5a-cd83-b72c-63bb-175d14cf7244;
pif=5b5d507e-e03a-3d92-a38d-0cffe00a9cf2
2013-05-06 18:51:37,786 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-33:null) Seq 3-1946102642: Response Received:
2013-05-06 18:51:37,787 DEBUG [agent.transport.Request] (DirectAgent-33:null)
Seq 3-1946102642: Processing: { Ans: , MgmtId: 7363452993625, via: 3, Ver: v1,
Flags: 110,
[{"MigrateWithStorageReceiveAnswer":{"volumeToSr":{"Vol[7|DATADISK|0d735f7b-f237-4e83-8170-849944301d3b|21474836480]":{"ref":"OpaqueRef:8ad4a2c1-c0ba-6581-fc1a-428898e9808c"},"Vol[3|ROOT|d1dd1588-1d15-41fc-8cc7-9eb4b1ea9400|21474836480]":{"ref":"OpaqueRef:8ad4a2c1-c0ba-6581-fc1a-428898e9808c"}},"nicToNetwork":{"[Nic:Guest-10.1.1.25-vlan://1066]":{"ref":"OpaqueRef:e67419ed-5ab7-96c3-8c4b-f4919c71da1d"}},"token":{"session_id":"OpaqueRef:1eefb328-9af3-7e95-065b-5e37cc39f2c9","host":"OpaqueRef:66683eb7-0651-0ce8-4a2b-674f8a64b70b","SM":"http://10.147.40.20/services/SM?session_id=OpaqueRef:1eefb328-9af3-7e95-065b-5e37cc39f2c9","master":"http://10.147.40.20/","xenops":"http://10.147.40.20/services/xenops?session_id=OpaqueRef:1eefb328-9af3-7e95-065b-5e37cc39f2c9"},"result":true,"wait":0}}]
}
2013-05-06 18:51:37,788 DEBUG [agent.transport.Request]
(Job-Executor-44:job-284) Seq 3-1946102642: Received: { Ans: , MgmtId:
7363452993625, via: 3, Ver: v1, Flags: 110, { MigrateWithStorageReceiveAnswer }
}
2013-05-06 18:51:37,793 DEBUG [agent.transport.Request]
(Job-Executor-44:job-284) Seq 1-1011950821: Sending { Cmd , MgmtId:
7363452993625, via: 1, Ver: v1, Flags: 100111,
[{"MigrateWithStorageSendCommand":{"vm":{"id":3,"name":"i-2-3-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"CentOS
5.3
(64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"b1861919b4daa27","params":{},"uuid":"4f417cd8-055e-4efe-a466-3fba321f1666","disks":[{"id":3,"name":"ROOT-3","mountPoint":"/export/home/automation/adv/primary","path":"d1dd1588-1d15-41fc-8cc7-9eb4b1ea9400","size":21474836480,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"55b65d1f-db5d-3b61-a01c-c2c285dbc469","deviceId":0},{"id":7,"name":"fsnap","mountPoint":"/export/home/automation/adv/primary","path":"0d735f7b-f237-4e83-8170-849944301d3b","size":21474836480,"type":"DATADISK","storagePoolType":"NetworkFilesystem","storagePoolUuid":"55b65d1f-db5d-3b61-a01c-c2c285dbc469","deviceId":1}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"49ab752f-4ed5-4bb8-9436-ba91f0cb0c91","ip":"10.1.1.25","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:1c:d3:00:01","dns1":"10.103.128.16","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1066","isolationUri":"vlan://1066","isSecurityGroupEnabled":false}]},"volumeToSr":{"Vol[7|DATADISK|0d735f7b-f237-4e83-8170-849944301d3b|21474836480]":{"ref":"OpaqueRef:8ad4a2c1-c0ba-6581-fc1a-428898e9808c"},"Vol[3|ROOT|d1dd1588-1d15-41fc-8cc7-9eb4b1ea9400|21474836480]":{"ref":"OpaqueRef:8ad4a2c1-c0ba-6581-fc1a-428898e9808c"}},"nicToNetwork":{"[Nic:Guest-10.1.1.25-vlan://1066]":{"ref":"OpaqueRef:e67419ed-5ab7-96c3-8c4b-f4919c71da1d"}},"token":{"session_id":"OpaqueRef:1eefb328-9af3-7e95-065b-5e37cc39f2c9","host":"OpaqueRef:66683eb7-0651-0ce8-4a2b-674f8a64b70b","SM":"http://10.147.40.20/services/SM?session_id=OpaqueRef:1eefb328-9af3-7e95-065b-5e37cc39f2c9","master":"http://10.147.40.20/","xenops":"http://10.147.40.20/services/xenops?session_id=OpaqueRef:1eefb328-9af3-7e95-065b-5e37cc39f2c9"},"wait":0}}]
}
2013-05-06 18:51:37,793 DEBUG [agent.manager.AgentAttache]
(DirectAgent-33:null) Seq 3-1946102642: No more commands found
2013-05-06 18:51:37,795 DEBUG [agent.transport.Request]
(Job-Executor-44:job-284) Seq 1-1011950821: Executing: { Cmd , MgmtId:
7363452993625, via: 1, Ver: v1, Flags: 100111,
[{"MigrateWithStorageSendCommand":{"vm":{"id":3,"name":"i-2-3-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"arch":"x86_64","os":"CentOS
5.3
(64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"b1861919b4daa27","params":{},"uuid":"4f417cd8-055e-4efe-a466-3fba321f1666","disks":[{"id":3,"name":"ROOT-3","mountPoint":"/export/home/automation/adv/primary","path":"d1dd1588-1d15-41fc-8cc7-9eb4b1ea9400","size":21474836480,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"55b65d1f-db5d-3b61-a01c-c2c285dbc469","deviceId":0},{"id":7,"name":"fsnap","mountPoint":"/export/home/automation/adv/primary","path":"0d735f7b-f237-4e83-8170-849944301d3b","size":21474836480,"type":"DATADISK","storagePoolType":"NetworkFilesystem","storagePoolUuid":"55b65d1f-db5d-3b61-a01c-c2c285dbc469","deviceId":1}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"49ab752f-4ed5-4bb8-9436-ba91f0cb0c91","ip":"10.1.1.25","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:1c:d3:00:01","dns1":"10.103.128.16","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://1066","isolationUri":"vlan://1066","isSecurityGroupEnabled":false}]},"volumeToSr":{"Vol[7|DATADISK|0d735f7b-f237-4e83-8170-849944301d3b|21474836480]":{"ref":"OpaqueRef:8ad4a2c1-c0ba-6581-fc1a-428898e9808c"},"Vol[3|ROOT|d1dd1588-1d15-41fc-8cc7-9eb4b1ea9400|21474836480]":{"ref":"OpaqueRef:8ad4a2c1-c0ba-6581-fc1a-428898e9808c"}},"nicToNetwork":{"[Nic:Guest-10.1.1.25-vlan://1066]":{"ref":"OpaqueRef:e67419ed-5ab7-96c3-8c4b-f4919c71da1d"}},"token":{"session_id":"OpaqueRef:1eefb328-9af3-7e95-065b-5e37cc39f2c9","host":"OpaqueRef:66683eb7-0651-0ce8-4a2b-674f8a64b70b","SM":"http://10.147.40.20/services/SM?session_id=OpaqueRef:1eefb328-9af3-7e95-065b-5e37cc39f2c9","master":"http://10.147.40.20/","xenops":"http://10.147.40.20/services/xenops?session_id=OpaqueRef:1eefb328-9af3-7e95-065b-5e37cc39f2c9"},"wait":0}}]
}
2013-05-06 18:51:37,795 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-425:null) Seq 1-1011950821: Executing request
2013-05-06 18:51:40,019 DEBUG [cloud.api.ApiServlet] (catalina-exec-19:null)
===START=== 10.252.242.121 -- GET
command=queryAsyncJobResult&jobId=974c8445-3958-44a9-9b92-fdfe5236a0b1&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826932151
2013-05-06 18:51:40,054 DEBUG [cloud.api.ApiServlet] (catalina-exec-19:null)
===END=== 10.252.242.121 -- GET
command=queryAsyncJobResult&jobId=974c8445-3958-44a9-9b92-fdfe5236a0b1&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826932151
2013-05-06 18:51:42,762 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-33:null) Ping from 1
2013-05-06 18:51:43,022 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null)
===START=== 10.252.242.121 -- GET
command=queryAsyncJobResult&jobId=974c8445-3958-44a9-9b92-fdfe5236a0b1&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826935151
2013-05-06 18:51:43,058 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null)
===END=== 10.252.242.121 -- GET
command=queryAsyncJobResult&jobId=974c8445-3958-44a9-9b92-fdfe5236a0b1&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826935151
2013-05-06 18:51:43,382 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-8:null) Ping from 7
2013-05-06 18:51:43,861 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-179:null) Seq 1-1011941380: Executing request
2013-05-06 18:51:44,130 WARN [xen.resource.CitrixResourceBase]
(DirectAgent-179:null) Ignoring vm i-2-3-VM because of a lag in stopping the vm.
2013-05-06 18:51:44,131 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-179:null) Seq 1-1011941380: Response Received:
2013-05-06 18:51:44,132 DEBUG [agent.transport.Request] (DirectAgent-179:null)
Seq 1-1011941380: Processing: { Ans: , MgmtId: 7363452993625, via: 1, Ver: v1,
Flags: 10,
[{"ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}]
}
2013-05-06 18:51:46,020 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null)
===START=== 10.252.242.121 -- GET
command=queryAsyncJobResult&jobId=974c8445-3958-44a9-9b92-fdfe5236a0b1&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826938151
2013-05-06 18:51:46,056 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null)
===END=== 10.252.242.121 -- GET
command=queryAsyncJobResult&jobId=974c8445-3958-44a9-9b92-fdfe5236a0b1&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826938151
2013-05-06 18:51:49,024 DEBUG [cloud.api.ApiServlet] (catalina-exec-17:null)
===START=== 10.252.242.121 -- GET
command=queryAsyncJobResult&jobId=974c8445-3958-44a9-9b92-fdfe5236a0b1&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826941152
2013-05-06 18:51:49,058 DEBUG [cloud.api.ApiServlet] (catalina-exec-17:null)
===END=== 10.252.242.121 -- GET
command=queryAsyncJobResult&jobId=974c8445-3958-44a9-9b92-fdfe5236a0b1&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826941152
2013-05-06 18:51:52,031 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null)
===START=== 10.252.242.121 -- GET
command=queryAsyncJobResult&jobId=974c8445-3958-44a9-9b92-fdfe5236a0b1&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826944153
2013-05-06 18:51:52,065 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null)
===END=== 10.252.242.121 -- GET
command=queryAsyncJobResult&jobId=974c8445-3958-44a9-9b92-fdfe5236a0b1&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826944153
2013-05-06 18:51:55,060 DEBUG [cloud.api.ApiServlet] (catalina-exec-16:null)
===START=== 10.252.242.121 -- GET
command=queryAsyncJobResult&jobId=974c8445-3958-44a9-9b92-fdfe5236a0b1&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826947155
2013-05-06 18:51:55,095 DEBUG [cloud.api.ApiServlet] (catalina-exec-16:null)
===END=== 10.252.242.121 -- GET
command=queryAsyncJobResult&jobId=974c8445-3958-44a9-9b92-fdfe5236a0b1&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826947155
2013-05-06 18:51:56,433 DEBUG [cloud.server.StatsCollector]
(StatsCollector-1:null) HostStatsCollector is running...
2013-05-06 18:51:56,448 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-493:null) Seq 1-1011950822: Executing request
2013-05-06 18:51:56,683 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-493:null) Seq 1-1011950822: Response Received:
2013-05-06 18:51:56,684 DEBUG [agent.transport.Request] (StatsCollector-1:null)
Seq 1-1011950822: Received: { Ans: , MgmtId: 7363452993625, via: 1, Ver: v1,
Flags: 10, { GetHostStatsAnswer } }
2013-05-06 18:51:56,695 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-211:null) Seq 2-1149048187: Executing request
2013-05-06 18:51:56,786 DEBUG [cloud.server.StatsCollector]
(StatsCollector-2:null) StorageCollector is running...
2013-05-06 18:51:56,848 DEBUG [agent.transport.Request] (StatsCollector-2:null)
Seq 7-483140689: Received: { Ans: , MgmtId: 7363452993625, via: 7, Ver: v1,
Flags: 10, { GetStorageStatsAnswer } }
2013-05-06 18:51:56,946 DEBUG [agent.transport.Request] (StatsCollector-2:null)
Seq 7-483140690: Received: { Ans: , MgmtId: 7363452993625, via: 7, Ver: v1,
Flags: 10, { GetStorageStatsAnswer } }
2013-05-06 18:51:57,113 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-211:null) Seq 2-1149048187: Response Received:
2013-05-06 18:51:57,114 DEBUG [agent.transport.Request] (StatsCollector-1:null)
Seq 2-1149048187: Received: { Ans: , MgmtId: 7363452993625, via: 2, Ver: v1,
Flags: 10, { GetHostStatsAnswer } }
2013-05-06 18:51:57,125 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-244:null) Seq 3-1946102643: Executing request
2013-05-06 18:51:57,348 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-244:null) Seq 3-1946102643: Response Received:
2013-05-06 18:51:57,349 DEBUG [agent.transport.Request] (StatsCollector-1:null)
Seq 3-1946102643: Received: { Ans: , MgmtId: 7363452993625, via: 3, Ver: v1,
Flags: 10, { GetHostStatsAnswer } }
2013-05-06 18:51:58,034 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null)
===START=== 10.252.242.121 -- GET
command=queryAsyncJobResult&jobId=974c8445-3958-44a9-9b92-fdfe5236a0b1&response=json&sessionkey=cSc24xTjuz69EQZS4m5DA9c3Tpc%3D&_=1367826950155
^C
[root@auto-tc ~]#
--
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
