You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Nagaraju (JIRA)" <ji...@apache.org> on 2015/08/20 08:16:45 UTC
[jira] [Created] (CLOUDSTACK-8752) Unable to create instance
Nagaraju created CLOUDSTACK-8752:
------------------------------------
Summary: Unable to create instance
Key: CLOUDSTACK-8752
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-8752
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Reporter: Nagaraju
Getting below error while creating Instances,
Job failed due to exception Resource [Host:7] is unreachable: Host 7: Unable to start instance due to Unable to send command. Upgrade in progress. Please contact administrator.
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy189.applyDhcpEntry(Unknown Source)
at com.cloud.network.element.VirtualRouterElement.addDhcpEntry(VirtualRouterElement.java:905)
at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepareElement(NetworkOrchestrator.java:1222)
at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepareNic(NetworkOrchestrator.java:1344)
at org.apache.cloudstack.engine.orchestration.NetworkOrchestrator.prepare(NetworkOrchestrator.java:1280)
at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:986)
... 20 more
2015-08-20 11:37:04,444 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-12:ctx-10feefbf job-261/job-263) Complete async job-263, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyABpqYXZhLmxhbmcuUnVudGltZUV4Y2VwdGlvbp5fBkcKNIPlAgAAeHIAE2phdmEubGFuZy5FeGNlcHRpb27Q_R8-GjscxAIAAHhyABNqYXZhLmxhbmcuVGhyb3dhYmxl1cY1Jzl3uMsDAARMAAVjYXVzZXQAFUxqYXZhL2xhbmcvVGhyb3dhYmxlO0wADWRldGFpbE1lc3NhZ2V0ABJMamF2YS9sYW5nL1N0cmluZztbAApzdGFja1RyYWNldAAeW0xqYXZhL2xhbmcvU3RhY2tUcmFjZUVsZW1lbnQ7TAAUc3VwcHJlc3NlZEV4Y2VwdGlvbnN0ABBMamF2YS91dGlsL0xpc3Q7eHBxAH4AB3QAsEpvYiBmYWlsZWQgZHVlIHRvIGV4Y2VwdGlvbiBSZXNvdXJjZSBbSG9zdDo3XSBpcyB1bnJlYWNoYWJsZTogSG9zdCA3OiBVbmFibGUgdG8gc3RhcnQgaW5zdGFuY2UgZHVlIHRvIFVuYWJsZSB0byBzZW5kIGNvbW1hbmQuIFVwZ3JhZGUgaW4gcHJvZ3Jlc3MuIFBsZWFzZSBjb250YWN0IGFkbWluaXN0cmF0b3IudXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAANc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAESQAKbGluZU51bWJlckwADmRlY2xhcmluZ0NsYXNzcQB-AARMAAhmaWxlTmFtZXEAfgAETAAKbWV0aG9kTmFtZXEAfgAEeHAAAABydAAgY29tLmNsb3VkLnZtLlZtV29ya0pvYkRpc3BhdGNoZXJ0ABhWbVdvcmtKb2JEaXNwYXRjaGVyLmphdmF0AAZydW5Kb2JzcQB-AAsAAAH2dAA_b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmZyYW1ld29yay5qb2JzLmltcGwuQXN5bmNKb2JNYW5hZ2VySW1wbCQ1dAAYQXN5bmNKb2JNYW5hZ2VySW1wbC5qYXZhdAAMcnVuSW5Db250ZXh0c3EAfgALAAAAMXQAPm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZSQxdAAbTWFuYWdlZENvbnRleHRSdW5uYWJsZS5qYXZhdAADcnVuc3EAfgALAAAAOHQAQm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHQkMXQAGkRlZmF1bHRNYW5hZ2VkQ29udGV4dC5qYXZhdAAEY2FsbHNxAH4ACwAAAGd0AEBvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0cQB-ABp0AA9jYWxsV2l0aENvbnRleHRzcQB-AAsAAAA1cQB-AB1xAH4AGnQADnJ1bldpdGhDb250ZXh0c3EAfgALAAAALnQAPG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZXEAfgAWcQB-ABdzcQB-AAsAAAHLcQB-ABFxAH4AEnEAfgAXc3EAfgALAAAB13QALmphdmEudXRpbC5jb25jdXJyZW50LkV4ZWN1dG9ycyRSdW5uYWJsZUFkYXB0ZXJ0AA5FeGVjdXRvcnMuamF2YXEAfgAbc3EAfgALAAABBnQAH2phdmEudXRpbC5jb25jdXJyZW50LkZ1dHVyZVRhc2t0AA9GdXR1cmVUYXNrLmphdmFxAH4AF3NxAH4ACwAABHl0ACdqYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3J0ABdUaHJlYWRQb29sRXhlY3V0b3IuamF2YXQACXJ1bldvcmtlcnNxAH4ACwAAAmd0AC5qYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3IkV29ya2VycQB-ACxxAH4AF3NxAH4ACwAAAul0ABBqYXZhLmxhbmcuVGhyZWFkdAALVGhyZWFkLmphdmFxAH4AF3NyACZqYXZhLnV0aWwuQ29sbGVjdGlvbnMkVW5tb2RpZmlhYmxlTGlzdPwPJTG17I4QAgABTAAEbGlzdHEAfgAGeHIALGphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVDb2xsZWN0aW9uGUIAgMte9x4CAAFMAAFjdAAWTGphdmEvdXRpbC9Db2xsZWN0aW9uO3hwc3IAE2phdmEudXRpbC5BcnJheUxpc3R4gdIdmcdhnQMAAUkABHNpemV4cAAAAAB3BAAAAAB4cQB-ADh4
2015-08-20 11:37:04,448 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-12:ctx-10feefbf job-261/job-263) Done executing com.cloud.vm.VmWorkStart for job-263
2015-08-20 11:37:04,455 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-1:ctx-f4f06ab8 job-261 ctx-825af81f) Destroying vm VM[User|i-2-36-VM] as it failed to create on Host with Id:null
2015-08-20 11:37:04,458 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl] (Work-Job-Executor-12:ctx-10feefbf job-261/job-263) Sync queue (157) is currently empty
2015-08-20 11:37:04,458 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-12:ctx-10feefbf job-261/job-263) Remove job-263 from job monitoring
2015-08-20 11:37:04,465 DEBUG [c.c.c.CapacityManagerImpl] (API-Job-Executor-1:ctx-f4f06ab8 job-261 ctx-825af81f) VM state transitted from :Stopped to Error with event: OperationFailedToErrorvm's original host id: null new host id: null host id before state transition: null
2015-08-20 11:37:04,476 WARN [o.a.c.alerts] (API-Job-Executor-1:ctx-f4f06ab8 job-261 ctx-825af81f) alertType:: 8 // dataCenterId:: 1 // podId:: 1 // clusterId:: null // message:: Failed to deploy Vm with Id: 36, on Host with Id: null
2015-08-20 11:37:04,495 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-1:ctx-f4f06ab8 job-261) Unexpected exception while executing org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin
java.lang.RuntimeException: Job failed due to exception Resource [Host:7] is unreachable: Host 7: Unable to start instance due to Unable to send command. Upgrade in progress. Please contact administrator.
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:114)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:502)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:459)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-08-20 11:37:04,496 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-1:ctx-f4f06ab8 job-261) Complete async job-261, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Job failed due to exception Resource [Host:7] is unreachable: Host 7: Unable to start instance due to Unable to send command. Upgrade in progress. Please contact administrator."}
2015-08-20 11:37:04,499 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-1:ctx-f4f06ab8 job-261) Done executing org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin for job-261
2015-08-20 11:37:04,501 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-1:ctx-f4f06ab8 job-261) Remove job-261 from job monitoring
2015-08-20 11:37:06,743 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) SeqA 2-732: Processing Seq 2-732: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": [\n {\n \"id\": 1,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5902,\n \"tag\": \"d0ad00bd-e38a-4a36-a52c-20f4c36fdb76\",\n \"createTime\": 1440050788775,\n \"lastUsedTime\": 1440050792657\n }\n ]\n}","wait":0}}] }
2015-08-20 11:37:06,746 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) SeqA 2-732: Sending Seq 2-732: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:37:06,912 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-d348636d) ===START=== 10.204.207.174 -- GET command=queryAsyncJobResult&jobId=aecf67f8-7b4e-42c5-b9bb-4ff7fd5a5bb8&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050828560
2015-08-20 11:37:06,921 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-d348636d ctx-dbc32959) ===END=== 10.204.207.174 -- GET command=queryAsyncJobResult&jobId=aecf67f8-7b4e-42c5-b9bb-4ff7fd5a5bb8&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050828560
2015-08-20 11:37:06,929 DEBUG [c.c.a.ApiServlet] (catalina-exec-11:ctx-d554b39e) ===START=== 10.204.207.174 -- GET command=listVirtualMachines&id=09774230-c47f-4ed8-8011-83c725c0f83e&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050828578
2015-08-20 11:37:06,945 DEBUG [c.c.a.ApiServlet] (catalina-exec-11:ctx-d554b39e ctx-fb00aff8) ===END=== 10.204.207.174 -- GET command=listVirtualMachines&id=09774230-c47f-4ed8-8011-83c725c0f83e&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050828578
2015-08-20 11:37:08,745 DEBUG [c.c.s.StatsCollector] (StatsCollector-1:ctx-c4408072) HostStatsCollector is running...
2015-08-20 11:37:08,749 INFO [c.c.a.t.Request] (StatsCollector-1:ctx-c4408072) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:37:08,756 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-15:null) Ping from 7
2015-08-20 11:37:08,756 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null) Process host VM state report from ping process. host: 7
2015-08-20 11:37:08,760 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null) Process VM state report. host: 7, number of records in report: 3
2015-08-20 11:37:08,760 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null) VM state report. host: 7, vm id: 35, power state: PowerOn
2015-08-20 11:37:08,761 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null) VM power state does not change, skip DB writing. vm id: 35
2015-08-20 11:37:08,761 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null) VM state report. host: 7, vm id: 2, power state: PowerOn
2015-08-20 11:37:08,762 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null) VM power state does not change, skip DB writing. vm id: 2
2015-08-20 11:37:08,763 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null) VM state report. host: 7, vm id: 7, power state: PowerOn
2015-08-20 11:37:08,764 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null) VM power state does not change, skip DB writing. vm id: 7
2015-08-20 11:37:08,766 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null) Done with process of VM state report. host: 7
2015-08-20 11:37:09,310 DEBUG [o.a.c.f.j.d.VmWorkJobDaoImpl] (Vm-Operations-Cleanup-1:ctx-30abd237) Expunge completed work job-262
2015-08-20 11:37:09,313 DEBUG [o.a.c.f.j.d.VmWorkJobDaoImpl] (Vm-Operations-Cleanup-1:ctx-30abd237) Expunge completed work job-263
2015-08-20 11:37:09,343 INFO [c.c.a.t.Request] (AgentManager-Handler-1:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:37:09,344 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-c4408072) Seq 7-3655796997518000321: Received: { Ans: , MgmtId: 52234440052, via: 7, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
2015-08-20 11:37:10,415 DEBUG [c.c.a.m.ClusteredAgentAttache] (AgentManager-Handler-3:null) Seq 7-7765331657493577899: Routing from 52234911571
2015-08-20 11:37:10,951 INFO [c.c.a.t.Request] (AgentManager-Handler-2:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:37:10,951 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-2:null) Seq 7-7765331657493577899: MgmtId 52234911571: Resp: Routing to peer
2015-08-20 11:37:11,744 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-4:null) SeqA 2-733: Processing Seq 2-733: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": [\n {\n \"id\": 1,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5902,\n \"tag\": \"d0ad00bd-e38a-4a36-a52c-20f4c36fdb76\",\n \"createTime\": 1440050788775,\n \"lastUsedTime\": 1440050792657\n }\n ]\n}","wait":0}}] }
2015-08-20 11:37:11,747 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-4:null) SeqA 2-733: Sending Seq 2-733: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:37:14,055 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-a7528b4c) ===START=== 10.204.207.174 -- GET command=listZones&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=1&_=1440050835661
2015-08-20 11:37:14,058 WARN [c.c.a.d.ParamGenericValidationWorker] (catalina-exec-20:ctx-a7528b4c ctx-33ad2ca3) Received unknown parameters for command listZones. Unknown parameters : listall
2015-08-20 11:37:14,063 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-a7528b4c ctx-33ad2ca3) ===END=== 10.204.207.174 -- GET command=listZones&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=1&_=1440050835661
2015-08-20 11:37:14,099 DEBUG [c.c.a.ApiServlet] (catalina-exec-17:ctx-c053b924) ===START=== 10.204.207.174 -- GET command=listPods&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=1&_=1440050835749
2015-08-20 11:37:14,102 WARN [c.c.a.d.ParamGenericValidationWorker] (catalina-exec-17:ctx-c053b924 ctx-ed0e660a) Received unknown parameters for command listPods. Unknown parameters : listall
2015-08-20 11:37:14,105 DEBUG [c.c.a.ApiServlet] (catalina-exec-17:ctx-c053b924 ctx-ed0e660a) ===END=== 10.204.207.174 -- GET command=listPods&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=1&_=1440050835749
2015-08-20 11:37:14,114 DEBUG [c.c.a.ApiServlet] (catalina-exec-10:ctx-c7512e61) ===START=== 10.204.207.174 -- GET command=listClusters&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=1&_=1440050835761
2015-08-20 11:37:14,116 WARN [c.c.a.d.ParamGenericValidationWorker] (catalina-exec-10:ctx-c7512e61 ctx-94c667b4) Received unknown parameters for command listClusters. Unknown parameters : listall
2015-08-20 11:37:14,120 DEBUG [c.c.a.ApiServlet] (catalina-exec-10:ctx-c7512e61 ctx-94c667b4) ===END=== 10.204.207.174 -- GET command=listClusters&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=1&_=1440050835761
2015-08-20 11:37:14,128 DEBUG [c.c.a.ApiServlet] (catalina-exec-25:ctx-6032ac97) ===START=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&listAll=true&page=1&pagesize=1&_=1440050835776
2015-08-20 11:37:14,131 WARN [c.c.a.d.ParamGenericValidationWorker] (catalina-exec-25:ctx-6032ac97 ctx-340db8e9) Received unknown parameters for command listHosts. Unknown parameters : listall
2015-08-20 11:37:14,131 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-25:ctx-6032ac97 ctx-340db8e9) >>>Searching for hosts>>>
2015-08-20 11:37:14,135 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-25:ctx-6032ac97 ctx-340db8e9) >>>Generating Response>>>
2015-08-20 11:37:14,138 DEBUG [c.c.a.ApiServlet] (catalina-exec-25:ctx-6032ac97 ctx-340db8e9) ===END=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&listAll=true&page=1&pagesize=1&_=1440050835776
2015-08-20 11:37:14,146 DEBUG [c.c.a.ApiServlet] (catalina-exec-8:ctx-02742177) ===START=== 10.204.207.174 -- GET command=listStoragePools&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=1&_=1440050835794
2015-08-20 11:37:14,149 WARN [c.c.a.d.ParamGenericValidationWorker] (catalina-exec-8:ctx-02742177 ctx-43e8e9f6) Received unknown parameters for command listStoragePools. Unknown parameters : listall
2015-08-20 11:37:14,154 DEBUG [c.c.a.ApiServlet] (catalina-exec-8:ctx-02742177 ctx-43e8e9f6) ===END=== 10.204.207.174 -- GET command=listStoragePools&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=1&_=1440050835794
2015-08-20 11:37:14,163 DEBUG [c.c.a.ApiServlet] (catalina-exec-23:ctx-3d56e732) ===START=== 10.204.207.174 -- GET command=listImageStores&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=SecondaryStorage&listAll=true&page=1&pagesize=1&_=1440050835810
2015-08-20 11:37:14,166 WARN [c.c.a.d.ParamGenericValidationWorker] (catalina-exec-23:ctx-3d56e732 ctx-d5701158) Received unknown parameters for command listImageStores. Unknown parameters : listall type
2015-08-20 11:37:14,169 DEBUG [c.c.a.ApiServlet] (catalina-exec-23:ctx-3d56e732 ctx-d5701158) ===END=== 10.204.207.174 -- GET command=listImageStores&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=SecondaryStorage&listAll=true&page=1&pagesize=1&_=1440050835810
2015-08-20 11:37:14,178 DEBUG [c.c.a.ApiServlet] (catalina-exec-16:ctx-f0223bcc) ===START=== 10.204.207.174 -- GET command=listSystemVms&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=1&_=1440050835826
2015-08-20 11:37:14,181 WARN [c.c.a.d.ParamGenericValidationWorker] (catalina-exec-16:ctx-f0223bcc ctx-7f4e8fe9) Received unknown parameters for command listSystemVms. Unknown parameters : listall
2015-08-20 11:37:14,203 DEBUG [c.c.a.ApiServlet] (catalina-exec-16:ctx-f0223bcc ctx-7f4e8fe9) ===END=== 10.204.207.174 -- GET command=listSystemVms&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=1&_=1440050835826
2015-08-20 11:37:14,211 DEBUG [c.c.a.ApiServlet] (catalina-exec-15:ctx-6f780d0f) ===START=== 10.204.207.174 -- GET command=listRouters&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=1&_=1440050835859
2015-08-20 11:37:14,219 DEBUG [c.c.a.ApiServlet] (catalina-exec-15:ctx-6f780d0f ctx-5bd10e69) ===END=== 10.204.207.174 -- GET command=listRouters&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=1&_=1440050835859
2015-08-20 11:37:14,227 DEBUG [c.c.a.ApiServlet] (catalina-exec-19:ctx-0ccab1a9) ===START=== 10.204.207.174 -- GET command=listRouters&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&projectid=-1&page=1&pagesize=1&_=1440050835875
2015-08-20 11:37:14,231 DEBUG [c.c.a.ApiServlet] (catalina-exec-19:ctx-0ccab1a9 ctx-95913834) ===END=== 10.204.207.174 -- GET command=listRouters&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&projectid=-1&page=1&pagesize=1&_=1440050835875
2015-08-20 11:37:14,238 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-cd828d80) ===START=== 10.204.207.174 -- GET command=listCapacity&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050835886
2015-08-20 11:37:14,248 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-cd828d80 ctx-4e086474) ===END=== 10.204.207.174 -- GET command=listCapacity&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050835886
2015-08-20 11:37:14,255 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-e7be544d) ===START=== 10.204.207.174 -- GET command=listHypervisors&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050835905
2015-08-20 11:37:14,258 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-e7be544d ctx-f47a3f15) ===END=== 10.204.207.174 -- GET command=listHypervisors&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050835905
2015-08-20 11:37:14,268 DEBUG [c.c.a.ApiServlet] (catalina-exec-11:ctx-ace27285) ===START=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&hypervisor=Hyperv&page=1&pagesize=20&_=1440050835917
2015-08-20 11:37:14,270 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-11:ctx-ace27285 ctx-d5ddfc29) >>>Searching for hosts>>>
2015-08-20 11:37:14,272 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-11:ctx-ace27285 ctx-d5ddfc29) >>>Generating Response>>>
2015-08-20 11:37:14,272 DEBUG [c.c.a.ApiServlet] (catalina-exec-11:ctx-ace27285 ctx-d5ddfc29) ===END=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&hypervisor=Hyperv&page=1&pagesize=20&_=1440050835917
2015-08-20 11:37:14,282 DEBUG [c.c.a.ApiServlet] (catalina-exec-22:ctx-8af03409) ===START=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&hypervisor=KVM&page=1&pagesize=20&_=1440050835928
2015-08-20 11:37:14,288 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-22:ctx-8af03409 ctx-1bb0425b) >>>Searching for hosts>>>
2015-08-20 11:37:14,292 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-22:ctx-8af03409 ctx-1bb0425b) >>>Generating Response>>>
2015-08-20 11:37:14,294 DEBUG [c.c.a.ApiServlet] (catalina-exec-22:ctx-8af03409 ctx-1bb0425b) ===END=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&hypervisor=KVM&page=1&pagesize=20&_=1440050835928
2015-08-20 11:37:14,303 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-1be2adaf) ===START=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&hypervisor=XenServer&page=1&pagesize=20&_=1440050835950
2015-08-20 11:37:14,305 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-20:ctx-1be2adaf ctx-1ff36d38) >>>Searching for hosts>>>
2015-08-20 11:37:14,307 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-20:ctx-1be2adaf ctx-1ff36d38) >>>Generating Response>>>
2015-08-20 11:37:14,307 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-1be2adaf ctx-1ff36d38) ===END=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&hypervisor=XenServer&page=1&pagesize=20&_=1440050835950
2015-08-20 11:37:14,317 DEBUG [c.c.a.ApiServlet] (catalina-exec-17:ctx-b6868463) ===START=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&hypervisor=VMware&page=1&pagesize=20&_=1440050835963
2015-08-20 11:37:14,319 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-17:ctx-b6868463 ctx-513e3af8) >>>Searching for hosts>>>
2015-08-20 11:37:14,321 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-17:ctx-b6868463 ctx-513e3af8) >>>Generating Response>>>
2015-08-20 11:37:14,321 DEBUG [c.c.a.ApiServlet] (catalina-exec-17:ctx-b6868463 ctx-513e3af8) ===END=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&hypervisor=VMware&page=1&pagesize=20&_=1440050835963
2015-08-20 11:37:14,329 DEBUG [c.c.a.ApiServlet] (catalina-exec-10:ctx-4626dc08) ===START=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&hypervisor=BareMetal&page=1&pagesize=20&_=1440050835977
2015-08-20 11:37:14,331 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-10:ctx-4626dc08 ctx-e03a0f6a) >>>Searching for hosts>>>
2015-08-20 11:37:14,333 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-10:ctx-4626dc08 ctx-e03a0f6a) >>>Generating Response>>>
2015-08-20 11:37:14,333 DEBUG [c.c.a.ApiServlet] (catalina-exec-10:ctx-4626dc08 ctx-e03a0f6a) ===END=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&hypervisor=BareMetal&page=1&pagesize=20&_=1440050835977
2015-08-20 11:37:14,343 DEBUG [c.c.a.ApiServlet] (catalina-exec-25:ctx-359d8cce) ===START=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&hypervisor=Ovm&page=1&pagesize=20&_=1440050835990
2015-08-20 11:37:14,346 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-25:ctx-359d8cce ctx-72eefc15) >>>Searching for hosts>>>
2015-08-20 11:37:14,347 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-25:ctx-359d8cce ctx-72eefc15) >>>Generating Response>>>
2015-08-20 11:37:14,348 DEBUG [c.c.a.ApiServlet] (catalina-exec-25:ctx-359d8cce ctx-72eefc15) ===END=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&hypervisor=Ovm&page=1&pagesize=20&_=1440050835990
2015-08-20 11:37:14,354 DEBUG [c.c.a.ApiServlet] (catalina-exec-8:ctx-525765e8) ===START=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&hypervisor=LXC&page=1&pagesize=20&_=1440050836003
2015-08-20 11:37:14,357 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-8:ctx-525765e8 ctx-bf8f2ba4) >>>Searching for hosts>>>
2015-08-20 11:37:14,358 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-8:ctx-525765e8 ctx-bf8f2ba4) >>>Generating Response>>>
2015-08-20 11:37:14,359 DEBUG [c.c.a.ApiServlet] (catalina-exec-8:ctx-525765e8 ctx-bf8f2ba4) ===END=== 10.204.207.174 -- GET command=listHosts&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&type=routing&hypervisor=LXC&page=1&pagesize=20&_=1440050836003
2015-08-20 11:37:15,697 DEBUG [c.c.a.ApiServlet] (catalina-exec-23:ctx-44d891b0) ===START=== 10.204.207.174 -- GET command=listRouters&listAll=true&page=1&pagesize=20&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050837330
2015-08-20 11:37:15,705 DEBUG [c.c.a.ApiServlet] (catalina-exec-23:ctx-44d891b0 ctx-d36ef836) ===END=== 10.204.207.174 -- GET command=listRouters&listAll=true&page=1&pagesize=20&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050837330
2015-08-20 11:37:15,764 DEBUG [c.c.a.ApiServlet] (catalina-exec-16:ctx-10e95c70) ===START=== 10.204.207.174 -- GET command=listRouters&listAll=true&page=1&pagesize=20&projectid=-1&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050837371
2015-08-20 11:37:15,768 DEBUG [c.c.a.ApiServlet] (catalina-exec-16:ctx-10e95c70 ctx-018c126d) ===END=== 10.204.207.174 -- GET command=listRouters&listAll=true&page=1&pagesize=20&projectid=-1&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050837371
2015-08-20 11:37:16,745 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-5:null) SeqA 2-734: Processing Seq 2-734: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": [\n {\n \"id\": 1,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5902,\n \"tag\": \"d0ad00bd-e38a-4a36-a52c-20f4c36fdb76\",\n \"createTime\": 1440050788775,\n \"lastUsedTime\": 1440050792657\n }\n ]\n}","wait":0}}] }
2015-08-20 11:37:16,748 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-5:null) SeqA 2-734: Sending Seq 2-734: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:37:17,031 DEBUG [c.c.a.ApiServlet] (catalina-exec-19:ctx-303ca26f) ===START=== 10.204.207.174 -- GET command=listRouters&id=69bfda5c-ac2a-4149-8cfa-5045cc10e751&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050838668
2015-08-20 11:37:17,044 DEBUG [c.c.a.ApiServlet] (catalina-exec-19:ctx-303ca26f ctx-fa6fc163) ===END=== 10.204.207.174 -- GET command=listRouters&id=69bfda5c-ac2a-4149-8cfa-5045cc10e751&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050838668
2015-08-20 11:37:17,062 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-8ed98f43) ===START=== 10.204.207.174 -- GET command=listZones&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&id=e06e01b7-2d91-4883-bd58-65b9f969c7a1&_=1440050838702
2015-08-20 11:37:17,068 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-8ed98f43 ctx-5ed25a8e) ===END=== 10.204.207.174 -- GET command=listZones&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&id=e06e01b7-2d91-4883-bd58-65b9f969c7a1&_=1440050838702
2015-08-20 11:37:18,393 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-ba758887) Zone 1 is ready to launch console proxy
2015-08-20 11:37:18,438 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-38acfe06) Zone 1 is ready to launch secondary storage VM
2015-08-20 11:37:18,494 DEBUG [c.c.a.t.Request] (catalina-exec-18:null) Seq 7-3655796997518000322: Sending { Cmd , MgmtId: 52234440052, via: 7(cstkvm1.bnglab.psecure.net), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.GetVncPortCommand":{"id":7,"name":"r-7-VM","wait":0}}] }
2015-08-20 11:37:18,501 DEBUG [c.c.a.t.Request] (AgentManager-Handler-6:null) Seq 7-3655796997518000322: Processing: { Ans: , MgmtId: 52234440052, via: 7, Ver: v1, Flags: 10, [{"com.cloud.agent.api.GetVncPortAnswer":{"address":"10.204.206.7","port":5900,"result":true,"wait":0}}] }
2015-08-20 11:37:18,501 DEBUG [c.c.a.t.Request] (catalina-exec-18:null) Seq 7-3655796997518000322: Received: { Ans: , MgmtId: 52234440052, via: 7, Ver: v1, Flags: 10, { GetVncPortAnswer } }
2015-08-20 11:37:18,501 DEBUG [c.c.s.ConsoleProxyServlet] (catalina-exec-18:null) Port info 10.204.206.7
2015-08-20 11:37:18,501 INFO [c.c.s.ConsoleProxyServlet] (catalina-exec-18:null) Parse host info returned from executing GetVNCPortCommand. host info: 10.204.206.7
2015-08-20 11:37:18,503 DEBUG [c.c.s.ConsoleProxyServlet] (catalina-exec-18:null) Compose console url: http://10.204.195.2/ajax?token=MqCfdEAlZxsMfICo9a_aYMvbuCvs9LkBTM6rvToynEFbS8S3Wh8ymkmIBJz5MyZHC7mrkXGn-UHoRt054GtpVIlGeDSEm0gL41lDXoGi7iQ5TxK7UmYV2m8FeVQ-dCZW8F2k6rVoOO7hAZCLUNm0AwVDtkmWT4LsMKDvZX33BNb7B2I6mLtLVp1WtsTdo1j32VE5lkhidKIOckhQV41P4xLuthgLhGLkZzxi53YZv6t5SL2VCMfktT-1ZVlgi8HEuumZXP9cCyvOpymZCbqSpQ
2015-08-20 11:37:18,503 DEBUG [c.c.s.ConsoleProxyServlet] (catalina-exec-18:null) the console url is :: <html><title>r-7-VM</title><frameset><frame src="http://10.204.195.2/ajax?token=MqCfdEAlZxsMfICo9a_aYMvbuCvs9LkBTM6rvToynEFbS8S3Wh8ymkmIBJz5MyZHC7mrkXGn-UHoRt054GtpVIlGeDSEm0gL41lDXoGi7iQ5TxK7UmYV2m8FeVQ-dCZW8F2k6rVoOO7hAZCLUNm0AwVDtkmWT4LsMKDvZX33BNb7B2I6mLtLVp1WtsTdo1j32VE5lkhidKIOckhQV41P4xLuthgLhGLkZzxi53YZv6t5SL2VCMfktT-1ZVlgi8HEuumZXP9cCyvOpymZCbqSpQ"></frame></frameset></html>
2015-08-20 11:37:18,628 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-7:null) SeqA 2-735: Processing Seq 2-735: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleAccessAuthenticationCommand":{"_host":"10.204.206.7","_port":"5900","_vmId":"69bfda5c-ac2a-4149-8cfa-5045cc10e751","_sid":"5835355b81e507d9","_ticket":"BoC2MbztvG2luFzvWEx+fTdfZi4=","_isReauthenticating":false,"wait":0}}] }
2015-08-20 11:37:18,628 DEBUG [c.c.c.AgentHookBase] (AgentManager-Handler-7:null) Console authentication. Ticket in url for 10.204.206.7:5900-69bfda5c-ac2a-4149-8cfa-5045cc10e751 is BoC2MbztvG2luFzvWEx+fTdfZi4=
2015-08-20 11:37:18,629 DEBUG [c.c.c.AgentHookBase] (AgentManager-Handler-7:null) Console authentication. Ticket in 1 minute boundary for 10.204.206.7:5900-69bfda5c-ac2a-4149-8cfa-5045cc10e751 is BoC2MbztvG2luFzvWEx+fTdfZi4=
2015-08-20 11:37:18,631 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-7:null) SeqA 2-735: Sending Seq 2-735: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.ConsoleAccessAuthenticationAnswer":{"_success":true,"_isReauthenticating":false,"_port":0,"result":true,"wait":0}}] }
2015-08-20 11:37:18,676 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-8:null) SeqA 2-736: Processing Seq 2-736: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": [\n {\n \"id\": 2,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5900,\n \"tag\": \"69bfda5c-ac2a-4149-8cfa-5045cc10e751\",\n \"createTime\": 1440050838666,\n \"lastUsedTime\": 1440050838666\n },\n {\n \"id\": 1,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5902,\n \"tag\": \"d0ad00bd-e38a-4a36-a52c-20f4c36fdb76\",\n \"createTime\": 1440050788775,\n \"lastUsedTime\": 1440050792657\n }\n ]\n}","wait":0}}] }
2015-08-20 11:37:18,679 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-8:null) SeqA 2-736: Sending Seq 2-736: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:37:19,419 DEBUG [c.c.s.StatsCollector] (StatsCollector-4:ctx-2ef2d068) AutoScaling Monitor is running...
2015-08-20 11:37:19,512 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-e2b89591) VmStatsCollector is running...
2015-08-20 11:37:21,748 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) SeqA 2-737: Processing Seq 2-737: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": [\n {\n \"id\": 2,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5900,\n \"tag\": \"69bfda5c-ac2a-4149-8cfa-5045cc10e751\",\n \"createTime\": 1440050838666,\n \"lastUsedTime\": 1440050841195\n },\n {\n \"id\": 1,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5902,\n \"tag\": \"d0ad00bd-e38a-4a36-a52c-20f4c36fdb76\",\n \"createTime\": 1440050788775,\n \"lastUsedTime\": 1440050792657\n }\n ]\n}","wait":0}}] }
2015-08-20 11:37:21,750 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) SeqA 2-737: Sending Seq 2-737: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:37:22,726 DEBUG [c.c.a.ApiServlet] (catalina-exec-22:ctx-b010f571) ===START=== 10.204.207.174 -- GET command=listVirtualMachines&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=20&_=1440050844344
2015-08-20 11:37:22,738 DEBUG [c.c.a.ApiServlet] (catalina-exec-22:ctx-b010f571 ctx-bdf931b6) ===END=== 10.204.207.174 -- GET command=listVirtualMachines&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=20&_=1440050844344
2015-08-20 11:37:24,134 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-e619c19a) ===START=== 10.204.207.174 -- GET command=listZones&id=e06e01b7-2d91-4883-bd58-65b9f969c7a1&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050845779
2015-08-20 11:37:24,141 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-e619c19a ctx-25cd64fb) ===END=== 10.204.207.174 -- GET command=listZones&id=e06e01b7-2d91-4883-bd58-65b9f969c7a1&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050845779
2015-08-20 11:37:24,162 DEBUG [c.c.a.ApiServlet] (catalina-exec-17:ctx-94808e75) ===START=== 10.204.207.174 -- GET command=listVirtualMachines&id=09774230-c47f-4ed8-8011-83c725c0f83e&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050845807
2015-08-20 11:37:24,174 DEBUG [c.c.a.ApiServlet] (catalina-exec-17:ctx-94808e75 ctx-1354898b) ===END=== 10.204.207.174 -- GET command=listVirtualMachines&id=09774230-c47f-4ed8-8011-83c725c0f83e&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050845807
2015-08-20 11:37:24,253 DEBUG [c.c.a.ApiServlet] (catalina-exec-10:ctx-59967bee) ===START=== 10.204.207.174 -- GET command=listOsTypes&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050845843
2015-08-20 11:37:24,372 DEBUG [c.c.a.ApiServlet] (catalina-exec-10:ctx-59967bee ctx-6d8a4b44) ===END=== 10.204.207.174 -- GET command=listOsTypes&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&_=1440050845843
2015-08-20 11:37:29,290 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-f68eda5d) StorageCollector is running...
2015-08-20 11:37:29,294 INFO [c.c.a.t.Request] (StatsCollector-3:ctx-f68eda5d) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:37:29,343 INFO [c.c.a.t.Request] (AgentManager-Handler-11:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:37:29,343 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-f68eda5d) Seq 8-3243436156636889171: Received: { Ans: , MgmtId: 52234440052, via: 8, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2015-08-20 11:37:29,344 INFO [c.c.a.t.Request] (StatsCollector-3:ctx-f68eda5d) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:37:29,419 INFO [c.c.a.t.Request] (AgentManager-Handler-10:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:37:29,419 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-f68eda5d) Seq 7-3655796997518000323: Received: { Ans: , MgmtId: 52234440052, via: 7, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2015-08-20 11:37:30,584 DEBUG [c.c.a.ApiServlet] (catalina-exec-8:ctx-51748f6a) ===START=== 10.204.207.174 -- GET command=listVirtualMachines&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=20&_=1440050852210
2015-08-20 11:37:30,600 DEBUG [c.c.a.ApiServlet] (catalina-exec-8:ctx-51748f6a ctx-cf1aa49f) ===END=== 10.204.207.174 -- GET command=listVirtualMachines&response=json&sessionkey=2yoq8PLv%2BZJeL9o%2BVSPfa8nADqA%3D&listAll=true&page=1&pagesize=20&_=1440050852210
2015-08-20 11:37:31,749 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-12:null) SeqA 2-738: Processing Seq 2-738: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": [\n {\n \"id\": 2,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5900,\n \"tag\": \"69bfda5c-ac2a-4149-8cfa-5045cc10e751\",\n \"createTime\": 1440050838666,\n \"lastUsedTime\": 1440050841195\n },\n {\n \"id\": 1,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5902,\n \"tag\": \"d0ad00bd-e38a-4a36-a52c-20f4c36fdb76\",\n \"createTime\": 1440050788775,\n \"lastUsedTime\": 1440050792657\n }\n ]\n}","wait":0}}] }
2015-08-20 11:37:31,752 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-12:null) SeqA 2-738: Sending Seq 2-738: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:37:34,266 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-23273b5d) Found 0 routers to update status.
2015-08-20 11:37:34,267 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-23273b5d) Found 0 networks to update RvR status.
2015-08-20 11:37:34,348 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b768fd27) Running Capacity Checker ...
2015-08-20 11:37:34,348 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b768fd27) recalculating system capacity
2015-08-20 11:37:34,348 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b768fd27) Executing cpu/ram capacity update
2015-08-20 11:37:34,352 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-b768fd27) Found 3 VMs on host 7
2015-08-20 11:37:34,353 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-b768fd27) Found 0 VM, not running on host 7
2015-08-20 11:37:34,354 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-b768fd27) No need to calibrate cpu capacity, host:7 usedCpu: 1500 reservedCpu: 0
2015-08-20 11:37:34,354 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-b768fd27) No need to calibrate memory capacity, host:7 usedMem: 1879048192 reservedMem: 0
2015-08-20 11:37:34,356 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b768fd27) Done executing cpu/ram capacity update
2015-08-20 11:37:34,356 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b768fd27) Executing storage capacity update
2015-08-20 11:37:34,359 DEBUG [c.c.s.StorageManagerImpl] (CapacityChecker:ctx-b768fd27) Found storage pool primary of type NetworkFilesystem with overprovisioning factor 2
2015-08-20 11:37:34,360 DEBUG [c.c.s.StorageManagerImpl] (CapacityChecker:ctx-b768fd27) Total over provisioned capacity calculated is 2 * 2164516192256
2015-08-20 11:37:34,360 DEBUG [c.c.s.StorageManagerImpl] (CapacityChecker:ctx-b768fd27) Total over provisioned capacity of the pool primary id: 1 is 4329032384512
2015-08-20 11:37:34,361 DEBUG [c.c.s.StorageManagerImpl] (CapacityChecker:ctx-b768fd27) Successfully set Capacity - 4329032384512 for capacity type - 3 , DataCenterId - 1, HostOrPoolId - 1, PodId 1
2015-08-20 11:37:34,361 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b768fd27) Done executing storage capacity update
2015-08-20 11:37:34,362 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b768fd27) Executing capacity updates for public ip and Vlans
2015-08-20 11:37:34,365 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (HostReservationReleaseChecker:ctx-c87857a2) Checking if any host reservation can be released ...
2015-08-20 11:37:34,369 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (HostReservationReleaseChecker:ctx-c87857a2) Cannot release reservation, Found 3 VMs Running on host 7
2015-08-20 11:37:34,369 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (HostReservationReleaseChecker:ctx-c87857a2) Done running HostReservationReleaseChecker ...
2015-08-20 11:37:34,375 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b768fd27) Done capacity updates for public ip and Vlans
2015-08-20 11:37:34,375 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b768fd27) Executing capacity updates for private ip
2015-08-20 11:37:34,378 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b768fd27) Done executing capacity updates for private ip
2015-08-20 11:37:34,378 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b768fd27) Done recalculating system capacity
2015-08-20 11:37:34,388 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b768fd27) Done running Capacity Checker ...
2015-08-20 11:37:34,634 DEBUG [c.c.a.m.ClusteredAgentAttache] (AgentManager-Handler-13:null) Seq 8-5494110070415294540: Routing from 52234911571
2015-08-20 11:37:34,681 INFO [c.c.a.t.Request] (AgentManager-Handler-14:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:37:34,681 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-14:null) Seq 8-5494110070415294540: MgmtId 52234911571: Resp: Routing to peer
2015-08-20 11:37:34,684 DEBUG [c.c.a.m.ClusteredAgentAttache] (AgentManager-Handler-15:null) Seq 7-7765331657493577900: Routing from 52234911571
2015-08-20 11:37:34,759 INFO [c.c.a.t.Request] (AgentManager-Handler-1:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:37:34,759 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-1:null) Seq 7-7765331657493577900: MgmtId 52234911571: Resp: Routing to peer
^C
[root@cstmgt1 ~]#
[root@cstmgt1 ~]# tail -f /var/log/cloudstack/management/management-server.log
2015-08-20 11:38:16,758 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) SeqA 2-748: Processing Seq 2-748: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": [\n {\n \"id\": 2,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5900,\n \"tag\": \"69bfda5c-ac2a-4149-8cfa-5045cc10e751\",\n \"createTime\": 1440050838666,\n \"lastUsedTime\": 1440050841195\n },\n {\n \"id\": 1,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5902,\n \"tag\": \"d0ad00bd-e38a-4a36-a52c-20f4c36fdb76\",\n \"createTime\": 1440050788775,\n \"lastUsedTime\": 1440050792657\n }\n ]\n}","wait":0}}] }
2015-08-20 11:38:16,761 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) SeqA 2-748: Sending Seq 2-748: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:38:18,392 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-1747e8a1) Zone 1 is ready to launch console proxy
2015-08-20 11:38:18,444 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-4c5e7ed7) Zone 1 is ready to launch secondary storage VM
2015-08-20 11:38:19,421 DEBUG [c.c.s.StatsCollector] (StatsCollector-4:ctx-c7f9b9ee) AutoScaling Monitor is running...
2015-08-20 11:38:19,514 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-94f61ede) VmStatsCollector is running...
2015-08-20 11:38:21,759 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-3:null) SeqA 2-749: Processing Seq 2-749: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": [\n {\n \"id\": 2,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5900,\n \"tag\": \"69bfda5c-ac2a-4149-8cfa-5045cc10e751\",\n \"createTime\": 1440050838666,\n \"lastUsedTime\": 1440050841195\n },\n {\n \"id\": 1,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5902,\n \"tag\": \"d0ad00bd-e38a-4a36-a52c-20f4c36fdb76\",\n \"createTime\": 1440050788775,\n \"lastUsedTime\": 1440050792657\n }\n ]\n}","wait":0}}] }
2015-08-20 11:38:21,762 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-3:null) SeqA 2-749: Sending Seq 2-749: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:38:26,761 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) SeqA 2-750: Processing Seq 2-750: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": [\n {\n \"id\": 2,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5900,\n \"tag\": \"69bfda5c-ac2a-4149-8cfa-5045cc10e751\",\n \"createTime\": 1440050838666,\n \"lastUsedTime\": 1440050841195\n },\n {\n \"id\": 1,\n \"clientInfo\": \"\",\n \"host\": \"10.204.206.7\",\n \"port\": 5902,\n \"tag\": \"d0ad00bd-e38a-4a36-a52c-20f4c36fdb76\",\n \"createTime\": 1440050788775,\n \"lastUsedTime\": 1440050792657\n }\n ]\n}","wait":0}}] }
2015-08-20 11:38:26,763 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) SeqA 2-750: Sending Seq 2-750: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:38:29,419 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-1702c2f5) StorageCollector is running...
2015-08-20 11:38:29,423 INFO [c.c.a.t.Request] (StatsCollector-3:ctx-1702c2f5) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:38:29,471 INFO [c.c.a.t.Request] (AgentManager-Handler-4:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:38:29,471 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-1702c2f5) Seq 8-3243436156636889172: Received: { Ans: , MgmtId: 52234440052, via: 8, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2015-08-20 11:38:29,473 INFO [c.c.a.t.Request] (StatsCollector-3:ctx-1702c2f5) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:38:29,508 INFO [c.c.a.t.Request] (AgentManager-Handler-5:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:38:29,508 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-1702c2f5) Seq 7-3655796997518000325: Received: { Ans: , MgmtId: 52234440052, via: 7, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2015-08-20 11:38:34,266 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-22e7cee0) Found 0 routers to update status.
2015-08-20 11:38:34,267 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-22e7cee0) Found 0 networks to update RvR status.
2015-08-20 11:38:34,771 DEBUG [c.c.a.m.ClusteredAgentAttache] (AgentManager-Handler-6:null) Seq 8-5494110070415294541: Routing from 52234911571
2015-08-20 11:38:34,818 INFO [c.c.a.t.Request] (AgentManager-Handler-7:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:38:34,818 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-7:null) Seq 8-5494110070415294541: MgmtId 52234911571: Resp: Routing to peer
2015-08-20 11:38:34,822 DEBUG [c.c.a.m.ClusteredAgentAttache] (AgentManager-Handler-8:null) Seq 7-7765331657493577902: Routing from 522349115712015-08-20 11:38:34,896 INFO [c.c.a.t.Request] (AgentManager-Handler-9:null) not building log message for '[{}]', _cmds.length == 12015-08-20 11:38:34,896 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-9:null) Seq 7-7765331657493577902: MgmtId 52234911571: Resp: Routing to peer^C[root@cstmgt1 ~]#
[root@cstmgt1 ~]# tail -f /var/log/cloudstack/management/management-server.log
2015-08-20 11:44:12,867 INFO [c.c.a.t.Request] (StatsCollector-1:ctx-2d3baa8a) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:44:13,451 INFO [c.c.a.t.Request] (AgentManager-Handler-13:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:44:13,451 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-2d3baa8a) Seq 7-3655796997518000339: Received: { Ans: , MgmtId: 52234440052, via: 7, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
2015-08-20 11:44:14,247 DEBUG [c.c.a.m.ClusteredAgentAttache] (AgentManager-Handler-14:null) Seq 7-7765331657493577913: Routing from 52234911571
2015-08-20 11:44:14,784 INFO [c.c.a.t.Request] (AgentManager-Handler-15:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:44:14,784 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-15:null) Seq 7-7765331657493577913: MgmtId 52234911571: Resp: Routing to peer
2015-08-20 11:44:18,393 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-b5be580d) Zone 1 is ready to launch console proxy
2015-08-20 11:44:18,438 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-0a83fc2d) Zone 1 is ready to launch secondary storage VM
2015-08-20 11:44:19,426 DEBUG [c.c.s.StatsCollector] (StatsCollector-4:ctx-5970b6fc) AutoScaling Monitor is running...
2015-08-20 11:44:19,525 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-8f9bffff) VmStatsCollector is running...
2015-08-20 11:44:21,816 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) SeqA 2-799: Processing Seq 2-799: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
2015-08-20 11:44:21,818 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) SeqA 2-799: Sending Seq 2-799: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:44:29,969 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-551a2108) StorageCollector is running...
2015-08-20 11:44:29,973 INFO [c.c.a.t.Request] (StatsCollector-3:ctx-551a2108) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:44:30,021 INFO [c.c.a.t.Request] (AgentManager-Handler-3:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:44:30,021 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-551a2108) Seq 8-3243436156636889178: Received: { Ans: , MgmtId: 52234440052, via: 8, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2015-08-20 11:44:30,023 INFO [c.c.a.t.Request] (StatsCollector-3:ctx-551a2108) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:44:30,059 INFO [c.c.a.t.Request] (AgentManager-Handler-2:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:44:30,059 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-551a2108) Seq 7-3655796997518000340: Received: { Ans: , MgmtId: 52234440052, via: 7, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2015-08-20 11:44:31,817 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-4:null) SeqA 2-800: Processing Seq 2-800: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
2015-08-20 11:44:31,820 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-4:null) SeqA 2-800: Sending Seq 2-800: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:44:34,266 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-0f4035cc) Found 0 routers to update status.
2015-08-20 11:44:34,267 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-0f4035cc) Found 0 networks to update RvR status.
2015-08-20 11:44:35,519 DEBUG [c.c.a.m.ClusteredAgentAttache] (AgentManager-Handler-5:null) Seq 8-5494110070415294547: Routing from 52234911571
2015-08-20 11:44:35,565 INFO [c.c.a.t.Request] (AgentManager-Handler-6:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:44:35,565 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-6:null) Seq 8-5494110070415294547: MgmtId 52234911571: Resp: Routing to peer
2015-08-20 11:44:35,568 DEBUG [c.c.a.m.ClusteredAgentAttache] (AgentManager-Handler-7:null) Seq 7-7765331657493577914: Routing from 52234911571
2015-08-20 11:44:35,642 INFO [c.c.a.t.Request] (AgentManager-Handler-8:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:44:35,642 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-8:null) Seq 7-7765331657493577914: MgmtId 52234911571: Resp: Routing to peer
2015-08-20 11:44:41,821 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) SeqA 2-801: Processing Seq 2-801: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
2015-08-20 11:44:41,823 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) SeqA 2-801: Sending Seq 2-801: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:44:48,393 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-c8987476) Zone 1 is ready to launch console proxy
2015-08-20 11:44:48,438 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-eccbd242) Zone 1 is ready to launch secondary storage VM
2015-08-20 11:44:50,965 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-11:null) Ping from 2
2015-08-20 11:44:51,820 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-10:null) SeqA 2-803: Processing Seq 2-803: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
2015-08-20 11:44:51,823 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-10:null) SeqA 2-803: Sending Seq 2-803: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:44:59,958 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-12:null) Ping from 8
2015-08-20 11:45:01,822 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-13:null) SeqA 2-804: Processing Seq 2-804: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
2015-08-20 11:45:01,824 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-13:null) SeqA 2-804: Sending Seq 2-804: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:45:04,266 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-b305257a) Found 0 routers to update status.
2015-08-20 11:45:04,267 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-b305257a) Found 0 networks to update RvR status.
2015-08-20 11:45:04,375 INFO [c.c.v.UserVmManagerImpl] (UserVm-Scavenger-1:ctx-dde46165) Found 1 vms to expunge.
2015-08-20 11:45:04,379 WARN [o.a.c.f.j.AsyncJobExecutionContext] (UserVm-Scavenger-1:ctx-dde46165) Job is executed without a context, setup psudo job for the executing thread
2015-08-20 11:45:04,386 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (UserVm-Scavenger-1:ctx-dde46165) Sync job-269 execution on object VmWorkJobQueue.37
2015-08-20 11:45:04,387 WARN [c.c.u.d.Merovingian2] (UserVm-Scavenger-1:ctx-dde46165) Was unable to find lock for the key vm_instance37 and thread id 1691200887
2015-08-20 11:45:06,220 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-36c76f22) Execute sync-queue item: SyncQueueItemVO {id:16, queueId: 160, contentType: AsyncJob, contentId: 269, lastProcessMsid: null, lastprocessNumber: null, lastProcessTime: null, created: Thu Aug 20 11:45:04 IST 2015}
2015-08-20 11:45:06,221 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-36c76f22) Schedule queued job-269
2015-08-20 11:45:06,224 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-16:ctx-9f064f07 job-268/job-269) Add job-269 into job monitoring
2015-08-20 11:45:06,224 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-9f064f07 job-268/job-269) Executing AsyncJobVO {id:269, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAAJXQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 52234440052, completeMsid: null, lastUpdated: null, lastPolled: null, created: Thu Aug 20 11:45:04 IST 2015}
2015-08-20 11:45:06,224 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-16:ctx-9f064f07 job-268/job-269) Run VM work job: com.cloud.vm.VmWorkStop for VM 37, job origin: 268
2015-08-20 11:45:06,225 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-16:ctx-9f064f07 job-268/job-269 ctx-b64b499d) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":1,"accountId":1,"vmId":37,"handlerName":"VirtualMachineManagerImpl"}
2015-08-20 11:45:06,227 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-16:ctx-9f064f07 job-268/job-269 ctx-b64b499d) Stopped called on VM[User|i-2-37-VM] but the state is Error
2015-08-20 11:45:06,227 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-16:ctx-9f064f07 job-268/job-269 ctx-b64b499d) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":1,"accountId":1,"vmId":37,"handlerName":"VirtualMachineManagerImpl"}
2015-08-20 11:45:06,227 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-9f064f07 job-268/job-269 ctx-b64b499d) Complete async job-269, jobStatus: SUCCEEDED, resultCode: 0, result: null
2015-08-20 11:45:06,231 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-16:ctx-9f064f07 job-268/job-269) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 37, job origin: 268
2015-08-20 11:45:06,231 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-16:ctx-9f064f07 job-268/job-269) Done executing com.cloud.vm.VmWorkStop for job-269
2015-08-20 11:45:06,239 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl] (Work-Job-Executor-16:ctx-9f064f07 job-268/job-269) Sync queue (160) is currently empty
2015-08-20 11:45:06,240 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-16:ctx-9f064f07 job-268/job-269) Remove job-269 from job monitoring
2015-08-20 11:45:06,240 DEBUG [c.c.c.CapacityManagerImpl] (UserVm-Scavenger-1:ctx-dde46165) VM state transitted from :Error to Expunging with event: ExpungeOperationvm's original host id: null new host id: null host id before state transition: null
2015-08-20 11:45:06,240 DEBUG [c.c.v.VirtualMachineManagerImpl] (UserVm-Scavenger-1:ctx-dde46165) Destroying vm VM[User|i-2-37-VM]
2015-08-20 11:45:06,240 DEBUG [c.c.v.VirtualMachineManagerImpl] (UserVm-Scavenger-1:ctx-dde46165) Cleaning up NICS
2015-08-20 11:45:06,241 DEBUG [o.a.c.e.o.NetworkOrchestrator] (UserVm-Scavenger-1:ctx-dde46165) Cleaning network for vm: 37
2015-08-20 11:45:06,244 DEBUG [c.c.n.NetworkModelImpl] (UserVm-Scavenger-1:ctx-dde46165) Service SecurityGroup is not supported in the network id=204
2015-08-20 11:45:06,247 DEBUG [o.a.c.e.o.NetworkOrchestrator] (UserVm-Scavenger-1:ctx-dde46165) Asking VirtualRouter to release Nic[117-37-null-10.96.162.2]
2015-08-20 11:45:06,251 DEBUG [c.c.n.g.DirectNetworkGuru] (UserVm-Scavenger-1:ctx-dde46165) Deallocate network: networkId: 204, ip: 10.96.162.2
2015-08-20 11:45:06,268 DEBUG [c.c.n.g.DirectNetworkGuru] (UserVm-Scavenger-1:ctx-dde46165) remove nic 117 secondary ip
2015-08-20 11:45:06,270 DEBUG [o.a.c.e.o.NetworkOrchestrator] (UserVm-Scavenger-1:ctx-dde46165) Removed nic id=117
2015-08-20 11:45:06,271 DEBUG [o.a.c.e.o.NetworkOrchestrator] (UserVm-Scavenger-1:ctx-dde46165) Revoving nic secondary ip entry ...
2015-08-20 11:45:06,271 DEBUG [c.c.v.VirtualMachineManagerImpl] (UserVm-Scavenger-1:ctx-dde46165) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage
2015-08-20 11:45:06,271 DEBUG [o.a.c.e.o.VolumeOrchestrator] (UserVm-Scavenger-1:ctx-dde46165) Cleaning storage for vm: 37
2015-08-20 11:45:06,273 DEBUG [c.c.v.VirtualMachineManagerImpl] (UserVm-Scavenger-1:ctx-dde46165) Expunged VM[User|i-2-37-VM]
2015-08-20 11:45:06,273 DEBUG [c.c.v.UserVmManagerImpl] (UserVm-Scavenger-1:ctx-dde46165) Starting cleaning up vm VM[User|i-2-37-VM] resources...
2015-08-20 11:45:06,282 DEBUG [c.c.n.f.FirewallManagerImpl] (UserVm-Scavenger-1:ctx-dde46165) No firewall rules are found for vm id=37
2015-08-20 11:45:06,285 DEBUG [c.c.v.UserVmManagerImpl] (UserVm-Scavenger-1:ctx-dde46165) Firewall rules are removed successfully as a part of vm id=37 expunge
2015-08-20 11:45:06,288 DEBUG [c.c.n.r.RulesManagerImpl] (UserVm-Scavenger-1:ctx-dde46165) No port forwarding rules are found for vm id=37
2015-08-20 11:45:06,288 DEBUG [c.c.v.UserVmManagerImpl] (UserVm-Scavenger-1:ctx-dde46165) Port forwarding rules are removed successfully as a part of vm id=37 expunge
2015-08-20 11:45:06,291 DEBUG [c.c.v.UserVmManagerImpl] (UserVm-Scavenger-1:ctx-dde46165) Removed vm id=37 from all load balancers as a part of expunge process
2015-08-20 11:45:06,291 DEBUG [c.c.v.UserVmManagerImpl] (UserVm-Scavenger-1:ctx-dde46165) Successfully cleaned up vm VM[User|i-2-37-VM] resources as a part of expunge process
2015-08-20 11:45:08,741 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) Ping from 7
2015-08-20 11:45:08,741 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) Process host VM state report from ping process. host: 7
2015-08-20 11:45:08,745 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) Process VM state report. host: 7, number of records in report: 3
2015-08-20 11:45:08,745 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) VM state report. host: 7, vm id: 35, power state: PowerOn
2015-08-20 11:45:08,747 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) VM power state does not change, skip DB writing. vm id: 35
2015-08-20 11:45:08,747 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) VM state report. host: 7, vm id: 2, power state: PowerOn
2015-08-20 11:45:08,748 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) VM power state does not change, skip DB writing. vm id: 2
2015-08-20 11:45:08,748 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) VM state report. host: 7, vm id: 7, power state: PowerOn
2015-08-20 11:45:08,750 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) VM power state does not change, skip DB writing. vm id: 7
2015-08-20 11:45:08,752 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) Done with process of VM state report. host: 7
2015-08-20 11:45:09,310 DEBUG [o.a.c.f.j.d.VmWorkJobDaoImpl] (Vm-Operations-Cleanup-1:ctx-772e8efe) Expunge completed work job-269
2015-08-20 11:45:09,329 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-d03b3290) Resetting hosts suitable for reconnect
2015-08-20 11:45:09,330 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-d03b3290) Completed resetting hosts suitable for reconnect
2015-08-20 11:45:09,330 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-d03b3290) Acquiring hosts for clusters already owned by this management server
2015-08-20 11:45:09,330 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-d03b3290) Completed acquiring hosts for clusters already owned by this management server
2015-08-20 11:45:09,330 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-d03b3290) Acquiring hosts for clusters not owned by any management server
2015-08-20 11:45:09,330 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-d03b3290) Completed acquiring hosts for clusters not owned by any management server
2015-08-20 11:45:11,824 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-15:null) SeqA 2-805: Processing Seq 2-805: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
2015-08-20 11:45:11,826 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-15:null) SeqA 2-805: Sending Seq 2-805: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:45:13,452 DEBUG [c.c.s.StatsCollector] (StatsCollector-1:ctx-8ea0ed57) HostStatsCollector is running...
2015-08-20 11:45:13,457 INFO [c.c.a.t.Request] (StatsCollector-1:ctx-8ea0ed57) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:45:14,035 INFO [c.c.a.t.Request] (AgentManager-Handler-1:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:45:14,035 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-8ea0ed57) Seq 7-3655796997518000341: Received: { Ans: , MgmtId: 52234440052, via: 7, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
2015-08-20 11:45:14,792 DEBUG [c.c.a.m.ClusteredAgentAttache] (AgentManager-Handler-3:null) Seq 7-7765331657493577915: Routing from 52234911571
2015-08-20 11:45:15,328 INFO [c.c.a.t.Request] (AgentManager-Handler-2:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:45:15,328 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-2:null) Seq 7-7765331657493577915: MgmtId 52234911571: Resp: Routing to peer
2015-08-20 11:45:18,392 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-a5dbd4d2) Zone 1 is ready to launch console proxy
2015-08-20 11:45:18,437 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-b67e244b) Zone 1 is ready to launch secondary storage VM
2015-08-20 11:45:19,427 DEBUG [c.c.s.StatsCollector] (StatsCollector-4:ctx-bb57fbe2) AutoScaling Monitor is running...
2015-08-20 11:45:19,527 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-5d254dad) VmStatsCollector is running...
2015-08-20 11:45:21,828 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-4:null) SeqA 2-806: Processing Seq 2-806: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
2015-08-20 11:45:21,830 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-4:null) SeqA 2-806: Sending Seq 2-806: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:45:30,060 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-09c72b75) StorageCollector is running...
2015-08-20 11:45:30,064 INFO [c.c.a.t.Request] (StatsCollector-3:ctx-09c72b75) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:45:30,112 INFO [c.c.a.t.Request] (AgentManager-Handler-5:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:45:30,112 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-09c72b75) Seq 8-3243436156636889179: Received: { Ans: , MgmtId: 52234440052, via: 8, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2015-08-20 11:45:30,113 INFO [c.c.a.t.Request] (StatsCollector-3:ctx-09c72b75) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:45:30,150 INFO [c.c.a.t.Request] (AgentManager-Handler-6:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:45:30,150 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-09c72b75) Seq 7-3655796997518000342: Received: { Ans: , MgmtId: 52234440052, via: 7, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
2015-08-20 11:45:31,826 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-7:null) SeqA 2-807: Processing Seq 2-807: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] }
2015-08-20 11:45:31,828 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-7:null) SeqA 2-807: Sending Seq 2-807: { Ans: , MgmtId: 52234440052, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-08-20 11:45:34,266 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-66bc0219) Found 0 routers to update status.
2015-08-20 11:45:34,267 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-66bc0219) Found 0 networks to update RvR status.
2015-08-20 11:45:35,648 DEBUG [c.c.a.m.ClusteredAgentAttache] (AgentManager-Handler-8:null) Seq 8-5494110070415294548: Routing from 52234911571
2015-08-20 11:45:35,695 INFO [c.c.a.t.Request] (AgentManager-Handler-9:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:45:35,695 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-9:null) Seq 8-5494110070415294548: MgmtId 52234911571: Resp: Routing to peer
2015-08-20 11:45:35,699 DEBUG [c.c.a.m.ClusteredAgentAttache] (AgentManager-Handler-11:null) Seq 7-7765331657493577916: Routing from 52234911571
2015-08-20 11:45:35,772 INFO [c.c.a.t.Request] (AgentManager-Handler-10:null) not building log message for '[{}]', _cmds.length == 1
2015-08-20 11:45:35,772 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-10:null) Seq 7-7765331657493577916: MgmtId 52234911571: Resp: Routing to peer
^C
[root@cstmgt1 ~]#
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)