2018-07-24 06:58:20,721 DEBUG [c.c.a.ApiServlet] (qtp788117692-19:ctx-f7f82b81) (logid:6fcf04f0) ===START=== 10.2.2.198 -- GET signatureversion=3&hostid=c2b60f1d-85b2-4a36-8608-522919722cc7&expires=2018-07-24T07%3A08%3A20%2B0000&apiKey=LIN6rqXuaJwMPfGYFh13qDwYz5VNNz1J2J6qIOWcd3oLQOq0WtD4CwRundBL6rzXToa3lQOC_vKjI3nkHtiD8Q&command=provisionCertificate&reconnect=true&signature=4eUWJhZcwXd39NR4en9zaKojjQQ%3D&response=json 2018-07-24 06:58:20,723 DEBUG [c.c.a.ApiServer] (qtp788117692-19:ctx-f7f82b81 ctx-db1c754d) (logid:6fcf04f0) CIDRs from which account 'Acct[96b3bfc9-8f09-11e8-890d-06d1ac0107be-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0 2018-07-24 06:58:20,734 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-53:ctx-91fe107d job-70) (logid:df3c6582) Add job-70 into job monitoring 2018-07-24 06:58:20,736 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (qtp788117692-19:ctx-f7f82b81 ctx-db1c754d ctx-be641d09) (logid:6fcf04f0) submit async job-70, details: AsyncJobVO {id:70, userId: 2, accountId: 2, instanceType: Host, instanceId: null, cmd: org.apache.cloudstack.api.command.admin.ca.ProvisionCertificateCmd, cmdInfo: {"expires":"2018-07-24T07:08:20+0000","apiKey":"LIN6rqXuaJwMPfGYFh13qDwYz5VNNz1J2J6qIOWcd3oLQOq0WtD4CwRundBL6rzXToa3lQOC_vKjI3nkHtiD8Q","signature":"4eUWJhZcwXd39NR4en9zaKojjQQ\u003d","hostid":"c2b60f1d-85b2-4a36-8608-522919722cc7","httpmethod":"GET","ctxAccountId":"2","cmdEventType":"CA.CERTIFICATE.PROVISION","reconnect":"true","signatureversion":"3","response":"json","ctxUserId":"2","ctxStartEventId":"206","ctxDetails":"{\"interface com.cloud.host.Host\":\"c2b60f1d-85b2-4a36-8608-522919722cc7\"}"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 7497603680190, completeMsid: null, lastUpdated: null, lastPolled: null, created: null} 2018-07-24 06:58:20,736 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-53:ctx-91fe107d job-70) (logid:3635f8ad) Executing AsyncJobVO {id:70, userId: 2, accountId: 2, instanceType: Host, instanceId: null, cmd: org.apache.cloudstack.api.command.admin.ca.ProvisionCertificateCmd, cmdInfo: {"expires":"2018-07-24T07:08:20+0000","apiKey":"LIN6rqXuaJwMPfGYFh13qDwYz5VNNz1J2J6qIOWcd3oLQOq0WtD4CwRundBL6rzXToa3lQOC_vKjI3nkHtiD8Q","signature":"4eUWJhZcwXd39NR4en9zaKojjQQ\u003d","hostid":"c2b60f1d-85b2-4a36-8608-522919722cc7","httpmethod":"GET","ctxAccountId":"2","cmdEventType":"CA.CERTIFICATE.PROVISION","reconnect":"true","signatureversion":"3","response":"json","ctxUserId":"2","ctxStartEventId":"206","ctxDetails":"{\"interface com.cloud.host.Host\":\"c2b60f1d-85b2-4a36-8608-522919722cc7\"}"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 7497603680190, completeMsid: null, lastUpdated: null, lastPolled: null, created: null} 2018-07-24 06:58:20,737 DEBUG [c.c.a.ApiServlet] (qtp788117692-19:ctx-f7f82b81 ctx-db1c754d ctx-be641d09) (logid:6fcf04f0) ===END=== 10.2.2.198 -- GET signatureversion=3&hostid=c2b60f1d-85b2-4a36-8608-522919722cc7&expires=2018-07-24T07%3A08%3A20%2B0000&apiKey=LIN6rqXuaJwMPfGYFh13qDwYz5VNNz1J2J6qIOWcd3oLQOq0WtD4CwRundBL6rzXToa3lQOC_vKjI3nkHtiD8Q&command=provisionCertificate&reconnect=true&signature=4eUWJhZcwXd39NR4en9zaKojjQQ%3D&response=json 2018-07-24 06:58:20,746 DEBUG [c.c.a.t.Request] (API-Job-Executor-53:ctx-91fe107d job-70 ctx-cf1a17fe) (logid:3635f8ad) Seq 1-5179702521429491723: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca.SetupKeyStoreCommand":{"handleByAgent":true,"accessDetails":{},"wait":60}}] } 2018-07-24 06:58:22,437 DEBUG [c.c.a.t.Request] (AgentManager-Handler-7:null) (logid:) Seq 1-5179702521429491723: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 10, [{"org.apache.cloudstack.ca.SetupKeystoreAnswer":{"result":true,"wait":0}}] } 2018-07-24 06:58:22,437 DEBUG [c.c.a.t.Request] (API-Job-Executor-53:ctx-91fe107d job-70 ctx-cf1a17fe) (logid:3635f8ad) Seq 1-5179702521429491723: Received: { Ans: , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 10, { SetupKeystoreAnswer } } 2018-07-24 06:58:22,457 DEBUG [c.c.a.t.Request] (API-Job-Executor-53:ctx-91fe107d job-70 ctx-cf1a17fe) (logid:3635f8ad) Seq 1-5179702521429491724: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.ca.SetupCertificateCommand":{"handleByAgent":true,"accessDetails":{},"wait":60}}] } 2018-07-24 06:58:22,671 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-6:null) (logid:) Ping from 3(s-2-VM) 2018-07-24 06:58:22,747 DEBUG [c.c.a.ApiServlet] (qtp788117692-19:ctx-7f8769fe) (logid:b1e2a92a) ===START=== 10.2.2.198 -- GET signatureversion=3&apiKey=LIN6rqXuaJwMPfGYFh13qDwYz5VNNz1J2J6qIOWcd3oLQOq0WtD4CwRundBL6rzXToa3lQOC_vKjI3nkHtiD8Q&expires=2018-07-24T07%3A08%3A22%2B0000&jobid=3635f8ad-20db-48fc-9083-0392cef3dc9c&command=queryAsyncJobResult&signature=2mRyZUM68e5I3FVAqOCmhCkzXGo%3D&response=json 2018-07-24 06:58:22,749 DEBUG [c.c.a.ApiServer] (qtp788117692-19:ctx-7f8769fe ctx-dfd8677f) (logid:b1e2a92a) CIDRs from which account 'Acct[96b3bfc9-8f09-11e8-890d-06d1ac0107be-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0 2018-07-24 06:58:22,757 DEBUG [c.c.a.ApiServlet] (qtp788117692-19:ctx-7f8769fe ctx-dfd8677f ctx-82edd2fe) (logid:b1e2a92a) ===END=== 10.2.2.198 -- GET signatureversion=3&apiKey=LIN6rqXuaJwMPfGYFh13qDwYz5VNNz1J2J6qIOWcd3oLQOq0WtD4CwRundBL6rzXToa3lQOC_vKjI3nkHtiD8Q&expires=2018-07-24T07%3A08%3A22%2B0000&jobid=3635f8ad-20db-48fc-9083-0392cef3dc9c&command=queryAsyncJobResult&signature=2mRyZUM68e5I3FVAqOCmhCkzXGo%3D&response=json 2018-07-24 06:58:23,380 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-4:null) (logid:) SeqA 4-266: Processing Seq 4-266: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] } 2018-07-24 06:58:23,383 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-4:null) (logid:) SeqA 4-266: Sending Seq 4-266: { Ans: , MgmtId: 7497603680190, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } 2018-07-24 06:58:24,201 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) (logid:) Ping from 2(trl-1553-k-M7-bstoyanov-kvm2) 2018-07-24 06:58:24,201 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid:) Process host VM state report from ping process. host: 2 2018-07-24 06:58:24,203 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid:) Process VM state report. host: 2, number of records in report: 2 2018-07-24 06:58:24,203 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid:) VM state report. host: 2, vm id: 1, power state: PowerOn 2018-07-24 06:58:24,204 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid:) VM power state does not change, skip DB writing. vm id: 1 2018-07-24 06:58:24,204 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid:) VM state report. host: 2, vm id: 2, power state: PowerOn 2018-07-24 06:58:24,205 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid:) VM power state does not change, skip DB writing. vm id: 2 2018-07-24 06:58:24,207 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid:) Done with process of VM state report. host: 2 2018-07-24 06:58:24,764 DEBUG [c.c.a.ApiServlet] (qtp788117692-19:ctx-204f7c6e) (logid:5c85672f) ===START=== 10.2.2.198 -- GET signatureversion=3&apiKey=LIN6rqXuaJwMPfGYFh13qDwYz5VNNz1J2J6qIOWcd3oLQOq0WtD4CwRundBL6rzXToa3lQOC_vKjI3nkHtiD8Q&expires=2018-07-24T07%3A08%3A24%2B0000&jobid=3635f8ad-20db-48fc-9083-0392cef3dc9c&command=queryAsyncJobResult&signature=YMdwGj0jus6Y7C3HUTcu3ploNiQ%3D&response=json 2018-07-24 06:58:24,767 DEBUG [c.c.a.ApiServer] (qtp788117692-19:ctx-204f7c6e ctx-7198e776) (logid:5c85672f) CIDRs from which account 'Acct[96b3bfc9-8f09-11e8-890d-06d1ac0107be-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0 2018-07-24 06:58:24,776 DEBUG [c.c.a.ApiServlet] (qtp788117692-19:ctx-204f7c6e ctx-7198e776 ctx-831d2e6c) (logid:5c85672f) ===END=== 10.2.2.198 -- GET signatureversion=3&apiKey=LIN6rqXuaJwMPfGYFh13qDwYz5VNNz1J2J6qIOWcd3oLQOq0WtD4CwRundBL6rzXToa3lQOC_vKjI3nkHtiD8Q&expires=2018-07-24T07%3A08%3A24%2B0000&jobid=3635f8ad-20db-48fc-9083-0392cef3dc9c&command=queryAsyncJobResult&signature=YMdwGj0jus6Y7C3HUTcu3ploNiQ%3D&response=json 2018-07-24 06:58:25,196 DEBUG [c.c.a.t.Request] (AgentManager-Handler-8:null) (logid:) Seq 1-5179702521429491724: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 10, [{"org.apache.cloudstack.ca.SetupCertificateAnswer":{"result":true,"wait":0}}] } 2018-07-24 06:58:25,197 DEBUG [c.c.a.t.Request] (API-Job-Executor-53:ctx-91fe107d job-70 ctx-cf1a17fe) (logid:3635f8ad) Seq 1-5179702521429491724: Received: { Ans: , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 10, { SetupCertificateAnswer } } 2018-07-24 06:58:25,197 INFO [o.a.c.c.CAManagerImpl] (API-Job-Executor-53:ctx-91fe107d job-70 ctx-cf1a17fe) (logid:3635f8ad) Successfully setup certificate on host, reconnecting with agent with id=1, name=trl-1553-k-M7-bstoyanov-kvm1, address=null 2018-07-24 06:58:25,198 INFO [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Host 1 is disconnecting with event ShutdownRequested 2018-07-24 06:58:25,198 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) The next status of agent 1is Disconnected, current status is Up 2018-07-24 06:58:25,198 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Deregistering link for 1 with state Disconnected 2018-07-24 06:58:25,198 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Remove Agent : 1 2018-07-24 06:58:25,198 DEBUG [c.c.a.m.ConnectedAgentAttache] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Processing Disconnect. 2018-07-24 06:58:25,198 DEBUG [c.c.a.m.AgentAttache] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Seq 1-5179702521429491713: Sending disconnect to class com.cloud.network.security.SecurityGroupListener 2018-07-24 06:58:25,198 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.hypervisor.xenserver.discoverer.XcpServerDiscoverer 2018-07-24 06:58:25,198 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.hypervisor.hyperv.discoverer.HypervServerDiscoverer 2018-07-24 06:58:25,198 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.storage.secondary.SecondaryStorageListener 2018-07-24 06:58:25,198 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.vm.ClusteredVirtualMachineManagerImpl 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.network.security.SecurityGroupListener 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.deploy.DeploymentPlanningManagerImpl 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.hypervisor.vmware.manager.VmwareManagerImpl 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.storage.listener.StoragePoolMonitor 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: org.apache.cloudstack.engine.orchestration.NetworkOrchestrator 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.network.router.VirtualNetworkApplianceManagerImpl 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.storage.LocalStoragePoolListener 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.consoleproxy.ConsoleProxyListener 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.capacity.StorageCapacityListener 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.capacity.ComputeCapacityListener 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.network.NetworkUsageManagerImpl$DirectNetworkStatsListener 2018-07-24 06:58:25,199 DEBUG [c.c.n.NetworkUsageManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Disconnected called on 1 with status Disconnected 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.agent.manager.AgentManagerImpl$BehindOnPingListener 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.agent.manager.AgentManagerImpl$SetHostParamsListener 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.network.router.VpcVirtualNetworkApplianceManagerImpl 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.storage.download.DownloadListener 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Sending Disconnect to listener: com.cloud.storage.upload.UploadListener 2018-07-24 06:58:25,199 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Transition:[Resource state = Enabled, Agent event = ShutdownRequested, Host id = 1, name = trl-1553-k-M7-bstoyanov-kvm1] 2018-07-24 06:58:25,204 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentTaskPool-4:ctx-722aa2df) (logid:f66d3f31) Notifying other nodes of to disconnect 2018-07-24 06:58:25,205 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-53:ctx-91fe107d job-70 ctx-cf1a17fe) (logid:3635f8ad) Complete async job-70, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.SuccessResponse/null/{"success":true} 2018-07-24 06:58:25,206 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-53:ctx-91fe107d job-70 ctx-cf1a17fe) (logid:3635f8ad) Publish async job-70 complete on message bus 2018-07-24 06:58:25,206 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-53:ctx-91fe107d job-70 ctx-cf1a17fe) (logid:3635f8ad) Wake up jobs related to job-70 2018-07-24 06:58:25,206 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-53:ctx-91fe107d job-70 ctx-cf1a17fe) (logid:3635f8ad) Update db status for job-70 2018-07-24 06:58:25,207 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-53:ctx-91fe107d job-70 ctx-cf1a17fe) (logid:3635f8ad) Wake up jobs joined with job-70 and disjoin all subjobs created from job- 70 2018-07-24 06:58:25,229 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-53:ctx-91fe107d job-70) (logid:3635f8ad) Done executing org.apache.cloudstack.api.command.admin.ca.ProvisionCertificateCmd for job-70 2018-07-24 06:58:25,229 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-53:ctx-91fe107d job-70) (logid:3635f8ad) Remove job-70 from job monitoring 2018-07-24 06:58:26,784 DEBUG [c.c.a.ApiServlet] (qtp788117692-19:ctx-e807298f) (logid:f87b1621) ===START=== 10.2.2.198 -- GET signatureversion=3&apiKey=LIN6rqXuaJwMPfGYFh13qDwYz5VNNz1J2J6qIOWcd3oLQOq0WtD4CwRundBL6rzXToa3lQOC_vKjI3nkHtiD8Q&expires=2018-07-24T07%3A08%3A26%2B0000&jobid=3635f8ad-20db-48fc-9083-0392cef3dc9c&command=queryAsyncJobResult&signature=45lZkjWQ8%2B2UrktURQfHlaEh9Io%3D&response=json 2018-07-24 06:58:26,787 DEBUG [c.c.a.ApiServer] (qtp788117692-19:ctx-e807298f ctx-e4021d65) (logid:f87b1621) CIDRs from which account 'Acct[96b3bfc9-8f09-11e8-890d-06d1ac0107be-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0 2018-07-24 06:58:26,795 DEBUG [c.c.a.ApiServlet] (qtp788117692-19:ctx-e807298f ctx-e4021d65 ctx-365d0f96) (logid:f87b1621) ===END=== 10.2.2.198 -- GET signatureversion=3&apiKey=LIN6rqXuaJwMPfGYFh13qDwYz5VNNz1J2J6qIOWcd3oLQOq0WtD4CwRundBL6rzXToa3lQOC_vKjI3nkHtiD8Q&expires=2018-07-24T07%3A08%3A26%2B0000&jobid=3635f8ad-20db-48fc-9083-0392cef3dc9c&command=queryAsyncJobResult&signature=45lZkjWQ8%2B2UrktURQfHlaEh9Io%3D&response=json 2018-07-24 06:58:26,932 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-ed63de8a) (logid:4b7aa354) Begin cleanup expired async-jobs 2018-07-24 06:58:26,935 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-ed63de8a) (logid:4b7aa354) End cleanup expired async-jobs 2018-07-24 06:58:27,013 DEBUG [c.c.a.t.Request] (AgentManager-Handler-10:null) (logid:) Seq 1-3: Scheduling the first command { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 1, [{"com.cloud.agent.api.StartupRoutingCommand":{"cpuSockets":3,"cpus":3,"speed":2300,"memory":7515590656,"dom0MinMemory":1073741824,"poolSync":false,"supportsClonedVolumes":false,"caps":"hvm,snapshot","pool":"/root","hypervisorType":"KVM","hostDetails":{"Host.OS.Kernel.Version":"3.10.0-693.11.1.el7.x86_64","com.cloud.network.Networks.RouterPrivateIpStrategy":"HostLocal","Host.OS.Version":"7.4.1708","secured":"false","Host.OS":"CentOS"},"hostTags":[],"groupDetails":{},"type":"Routing","dataCenter":"1","pod":"1","cluster":"1","guid":"f3dc98e6-fea8-39bc-b98f-b00dc8c5ef28-LibvirtComputingResource","name":"trl-1553-k-M7-bstoyanov-kvm1","id":1,"version":"4.12.0.0-SNAPSHOT","iqn":"iqn.1994-05.com.redhat:cd656ffc7be5","privateIpAddress":"10.2.2.194","privateMacAddress":"06:7f:4c:01:07:ba","privateNetmask":"255.255.0.0","storageIpAddress":"10.2.2.194","storageNetmask":"255.255.0.0","storageMacAddress":"06:7f:4c:01:07:ba","resourceName":"LibvirtComputingResource","gatewayIpAddress":"10.2.254.254","msHostList":"10.2.2.198","wait":0}},{"com.cloud.agent.api.StartupStorageCommand":{"totalSize":0,"poolInfo":{"uuid":"1dadd203-4f15-402c-8178-356d7fc51b13","host":"10.2.2.194","localPath":"/var/lib/libvirt/images","hostPath":"/var/lib/libvirt/images","poolType":"Filesystem","capacityBytes":20935868416,"availableBytes":19152867328},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"1","pod":"1","guid":"f3dc98e6-fea8-39bc-b98f-b00dc8c5ef28-LibvirtComputingResource","name":"trl-1553-k-M7-bstoyanov-kvm1","id":1,"version":"4.12.0.0-SNAPSHOT","resourceName":"LibvirtComputingResource","msHostList":"10.2.2.198","wait":0}}] } 2018-07-24 06:58:27,013 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-3: Processing the first command { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 1, [{"com.cloud.agent.api.StartupRoutingCommand":{"cpuSockets":3,"cpus":3,"speed":2300,"memory":7515590656,"dom0MinMemory":1073741824,"poolSync":false,"supportsClonedVolumes":false,"caps":"hvm,snapshot","pool":"/root","hypervisorType":"KVM","hostDetails":{"Host.OS.Kernel.Version":"3.10.0-693.11.1.el7.x86_64","com.cloud.network.Networks.RouterPrivateIpStrategy":"HostLocal","Host.OS.Version":"7.4.1708","secured":"false","Host.OS":"CentOS"},"hostTags":[],"groupDetails":{},"type":"Routing","dataCenter":"1","pod":"1","cluster":"1","guid":"f3dc98e6-fea8-39bc-b98f-b00dc8c5ef28-LibvirtComputingResource","name":"trl-1553-k-M7-bstoyanov-kvm1","id":1,"version":"4.12.0.0-SNAPSHOT","iqn":"iqn.1994-05.com.redhat:cd656ffc7be5","privateIpAddress":"10.2.2.194","privateMacAddress":"06:7f:4c:01:07:ba","privateNetmask":"255.255.0.0","storageIpAddress":"10.2.2.194","storageNetmask":"255.255.0.0","storageMacAddress":"06:7f:4c:01:07:ba","resourceName":"LibvirtComputingResource","gatewayIpAddress":"10.2.254.254","msHostList":"10.2.2.198","wait":0}},{"com.cloud.agent.api.StartupStorageCommand":{"totalSize":0,"poolInfo":{"uuid":"1dadd203-4f15-402c-8178-356d7fc51b13","host":"10.2.2.194","localPath":"/var/lib/libvirt/images","hostPath":"/var/lib/libvirt/images","poolType":"Filesystem","capacityBytes":20935868416,"availableBytes":19152867328},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"1","pod":"1","guid":"f3dc98e6-fea8-39bc-b98f-b00dc8c5ef28-LibvirtComputingResource","name":"trl-1553-k-M7-bstoyanov-kvm1","id":1,"version":"4.12.0.0-SNAPSHOT","resourceName":"LibvirtComputingResource","msHostList":"10.2.2.198","wait":0}}] } 2018-07-24 06:58:27,015 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to CiscoVnmcElement 2018-07-24 06:58:27,015 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to NetscalerElement 2018-07-24 06:58:27,015 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to JuniperSRXExternalFirewallElement 2018-07-24 06:58:27,015 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to HypervServerDiscoverer 2018-07-24 06:58:27,015 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to BaremetalPxeManagerImpl 2018-07-24 06:58:27,015 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to XcpServerDiscoverer 2018-07-24 06:58:27,015 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to NiciraNvp 2018-07-24 06:58:27,015 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to Ovm3Discoverer 2018-07-24 06:58:27,015 DEBUG [c.c.h.o.r.Ovm3Discoverer] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) createHostVOForConnectedAgent: Host[-1-Routing] 2018-07-24 06:58:27,015 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to PremiumSecondaryStorageManagerImpl 2018-07-24 06:58:27,015 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to F5ExternalLoadBalancerElement 2018-07-24 06:58:27,015 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to Ovs 2018-07-24 06:58:27,015 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to VmwareServerDiscoverer 2018-07-24 06:58:27,015 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to ConsoleProxyManagerImpl 2018-07-24 06:58:27,015 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to KvmServerDiscoverer 2018-07-24 06:58:27,025 DEBUG [c.c.r.ResourceState] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Resource state update: [id = 1; name = trl-1553-k-M7-bstoyanov-kvm1; old state = Enabled; event = InternalCreated; new state = Enabled] 2018-07-24 06:58:27,026 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Transition:[Resource state = Enabled, Agent event = AgentConnected, Host id = 1, name = trl-1553-k-M7-bstoyanov-kvm1] 2018-07-24 06:58:27,032 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) create ClusteredAgentAttache for 1 2018-07-24 06:58:27,033 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: XcpServerDiscoverer 2018-07-24 06:58:27,033 DEBUG [c.c.h.x.d.XcpServerDiscoverer] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Not XenServer so moving on. 2018-07-24 06:58:27,033 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: HypervServerDiscoverer 2018-07-24 06:58:27,033 DEBUG [c.c.h.h.d.HypervServerDiscoverer] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Not Hyper-V hypervisor, so moving on. 2018-07-24 06:58:27,033 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: SecondaryStorageListener 2018-07-24 06:58:27,033 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: ClusteredVirtualMachineManagerImpl 2018-07-24 06:58:27,033 DEBUG [c.c.v.VirtualMachineManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Received startup command from hypervisor host. host id: 1 2018-07-24 06:58:27,033 INFO [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Reset VM power state sync for host: 1 2018-07-24 06:58:27,035 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: SecurityGroupListener 2018-07-24 06:58:27,035 INFO [c.c.n.s.SecurityGroupListener] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Received a host startup notification 2018-07-24 06:58:27,035 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-1808476725365964801: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.CleanupNetworkRulesCmd":{"interval":2044,"wait":0}}] } 2018-07-24 06:58:27,035 INFO [c.c.n.s.SecurityGroupListener] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Scheduled network rules cleanup, interval=2044 2018-07-24 06:58:27,035 INFO [c.c.n.s.SecurityGroupListener] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Received a host startup notification 2018-07-24 06:58:27,035 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: DeploymentPlanningManagerImpl 2018-07-24 06:58:27,036 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: VmwareManagerImpl 2018-07-24 06:58:27,036 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: StoragePoolMonitor 2018-07-24 06:58:27,038 DEBUG [c.c.s.l.StoragePoolMonitor] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Host 1 connected, connecting host to shared pool id 1 and sending storage pool information ... 2018-07-24 06:58:27,038 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Adding pool null to host 1 2018-07-24 06:58:27,040 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-1808476725365964802: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifyStoragePoolCommand":{"add":true,"pool":{"id":1,"uuid":"70c81596-64ae-391d-94fe-10440f1fd924","host":"10.2.0.16","path":"/acs/primary/trl-1553-k-M7-bstoyanov/trl-1553-k-M7-bstoyanov-kvm-pri1","port":2049,"type":"NetworkFilesystem"},"localPath":"/mnt//70c81596-64ae-391d-94fe-10440f1fd924","wait":0}}] } 2018-07-24 06:58:27,069 DEBUG [c.c.a.t.Request] (AgentManager-Handler-9:null) (logid:) Seq 1-1808476725365964801: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } 2018-07-24 06:58:27,069 DEBUG [c.c.a.t.Request] (AgentManager-Handler-13:null) (logid:) Seq 1-1808476725365964802: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ModifyStoragePoolAnswer":{"poolInfo":{"host":"10.2.0.16","localPath":"/mnt//70c81596-64ae-391d-94fe-10440f1fd924","hostPath":"/acs/primary/trl-1553-k-M7-bstoyanov/trl-1553-k-M7-bstoyanov-kvm-pri1","poolType":"NetworkFilesystem","capacityBytes":7514055770112,"availableBytes":6230542123008},"templateInfo":{},"result":true,"wait":0}}] } 2018-07-24 06:58:27,069 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-1808476725365964802: Received: { Ans: , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 10, { ModifyStoragePoolAnswer } } 2018-07-24 06:58:27,071 INFO [o.a.c.s.d.p.DefaultHostListener] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Connection established between storage pool org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@37d8b699 and host 1 2018-07-24 06:58:27,072 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Found storage pool trl-1553-k-M7-bstoyanov-kvm-pri1 of type NetworkFilesystem with overprovisioning factor 2 2018-07-24 06:58:27,072 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Total over provisioned capacity calculated is 2 * 7514055770112 2018-07-24 06:58:27,072 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Total over provisioned capacity of the pool trl-1553-k-M7-bstoyanov-kvm-pri1 id: 1 is 15028111540224 2018-07-24 06:58:27,073 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Successfully set Capacity - 15028111540224 for capacity type - 3 , DataCenterId - 1, HostOrPoolId - 1, PodId 1 2018-07-24 06:58:27,073 DEBUG [c.c.s.l.StoragePoolMonitor] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Host 1 connected, connecting host to shared pool id 2 and sending storage pool information ... 2018-07-24 06:58:27,073 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Adding pool null to host 1 2018-07-24 06:58:27,074 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-1808476725365964803: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifyStoragePoolCommand":{"add":true,"pool":{"id":2,"uuid":"e1bc16c2-1053-3c0c-bd7a-5dbd76d5ce47","host":"10.2.0.16","path":"/acs/primary/trl-1553-k-M7-bstoyanov/trl-1553-k-M7-bstoyanov-kvm-pri2","port":2049,"type":"NetworkFilesystem"},"localPath":"/mnt//e1bc16c2-1053-3c0c-bd7a-5dbd76d5ce47","wait":0}}] } 2018-07-24 06:58:27,173 DEBUG [c.c.a.t.Request] (AgentManager-Handler-12:null) (logid:) Seq 1-1808476725365964803: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ModifyStoragePoolAnswer":{"poolInfo":{"host":"10.2.0.16","localPath":"/mnt//e1bc16c2-1053-3c0c-bd7a-5dbd76d5ce47","hostPath":"/acs/primary/trl-1553-k-M7-bstoyanov/trl-1553-k-M7-bstoyanov-kvm-pri2","poolType":"NetworkFilesystem","capacityBytes":7514055770112,"availableBytes":6231770005504},"templateInfo":{},"result":true,"wait":0}}] } 2018-07-24 06:58:27,174 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-1808476725365964803: Received: { Ans: , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 10, { ModifyStoragePoolAnswer } } 2018-07-24 06:58:27,175 INFO [o.a.c.s.d.p.DefaultHostListener] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Connection established between storage pool org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@37294ef9 and host 1 2018-07-24 06:58:27,177 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Found storage pool trl-1553-k-M7-bstoyanov-kvm-pri2 of type NetworkFilesystem with overprovisioning factor 2 2018-07-24 06:58:27,177 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Total over provisioned capacity calculated is 2 * 7514055770112 2018-07-24 06:58:27,177 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Total over provisioned capacity of the pool trl-1553-k-M7-bstoyanov-kvm-pri2 id: 2 is 15028111540224 2018-07-24 06:58:27,177 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Successfully set Capacity - 15028111540224 for capacity type - 3 , DataCenterId - 1, HostOrPoolId - 2, PodId 1 2018-07-24 06:58:27,177 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: NetworkOrchestrator 2018-07-24 06:58:27,177 DEBUG [o.a.c.e.o.NetworkOrchestrator] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Host's hypervisorType is: KVM 2018-07-24 06:58:27,179 DEBUG [o.a.c.e.o.NetworkOrchestrator] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending CheckNetworkCommand to check the Network is setup correctly on Agent 2018-07-24 06:58:27,180 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-1808476725365964804: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.CheckNetworkCommand":{"networkInfoList":[{"physicalNetworkId":200,"privateNetworkName":"cloudbr0","storageNetworkName":"cloudbr0"},{"physicalNetworkId":201,"publicNetworkName":"cloudbr1","guestNetworkName":"cloudbr1"}],"wait":0}}] } 2018-07-24 06:58:27,223 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-18:null) (logid:) Ping from 1(trl-1553-k-M7-bstoyanov-kvm1) 2018-07-24 06:58:27,223 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-18:null) (logid:) Process host VM state report from ping process. host: 1 2018-07-24 06:58:27,223 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-18:null) (logid:) Process VM state report. host: 1, number of records in report: 0 2018-07-24 06:58:27,224 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-18:null) (logid:) Done with process of VM state report. host: 1 2018-07-24 06:58:27,225 INFO [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-18:null) (logid:) PingMap for agent: 1 will not be updated because agent is no longer in the PingMap 2018-07-24 06:58:27,226 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-18:null) (logid:) Not processing PingRoutingCommand for agent id=0; can't find the host in the DB 2018-07-24 06:58:27,228 DEBUG [c.c.a.t.Request] (AgentManager-Handler-15:null) (logid:) Seq 1-1808476725365964804: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.CheckNetworkAnswer":{"_reconnect":false,"result":true,"wait":0}}] } 2018-07-24 06:58:27,228 DEBUG [c.c.a.m.AgentAttache] (AgentManager-Handler-15:null) (logid:) Seq 1-1808476725365964804: No more commands found 2018-07-24 06:58:27,228 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-1808476725365964804: Received: { Ans: , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 110, { CheckNetworkAnswer } } 2018-07-24 06:58:27,228 DEBUG [o.a.c.e.o.NetworkOrchestrator] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Network setup is correct on Agent 2018-07-24 06:58:27,228 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: SshKeysDistriMonitor 2018-07-24 06:58:27,230 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-1808476725365964805: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifySshKeysCommand":{"wait":0}}] } 2018-07-24 06:58:27,230 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: VirtualNetworkApplianceManagerImpl 2018-07-24 06:58:27,231 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: LocalStoragePoolListener 2018-07-24 06:58:27,231 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: ConsoleProxyListener 2018-07-24 06:58:27,231 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: StorageCapacityListener 2018-07-24 06:58:27,231 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: ComputeCapacityListener 2018-07-24 06:58:27,232 DEBUG [c.c.c.CapacityManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Found 0 VMs on host 1 2018-07-24 06:58:27,234 DEBUG [c.c.c.CapacityManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Found 0 VM, not running on host 1 2018-07-24 06:58:27,235 DEBUG [c.c.c.CapacityManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) No need to calibrate cpu capacity, host:1 usedCpuCore: 0 reservedCpuCore: 0 2018-07-24 06:58:27,235 DEBUG [c.c.c.CapacityManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) No need to calibrate cpu capacity, host:1 usedCpu: 0 reservedCpu: 0 2018-07-24 06:58:27,235 DEBUG [c.c.c.CapacityManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) No need to calibrate memory capacity, host:1 usedMem: 0 reservedMem: 0 2018-07-24 06:58:27,240 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: DirectNetworkStatsListener 2018-07-24 06:58:27,240 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: BehindOnPingListener 2018-07-24 06:58:27,240 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: SetHostParamsListener 2018-07-24 06:58:27,240 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-1808476725365964806: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.SetHostParamsCommand":{"params":{"router.aggregation.command.each.timeout":"600"},"wait":0}}] } 2018-07-24 06:58:27,240 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: SshKeysDistriMonitor 2018-07-24 06:58:27,242 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-1808476725365964807: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifySshKeysCommand":{"wait":0}}] } 2018-07-24 06:58:27,243 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: VpcVirtualNetworkApplianceManagerImpl 2018-07-24 06:58:27,243 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: DownloadListener 2018-07-24 06:58:27,244 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Sending Connect to listener: UploadListener 2018-07-24 06:58:27,245 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-1808476725365964808: Waiting for Seq 1808476725365964806 Scheduling: { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.ReadyCommand":{"dcId":1,"hostId":1,"wait":0}}] } 2018-07-24 06:58:27,288 DEBUG [c.c.a.t.Request] (AgentManager-Handler-17:null) (logid:) Seq 1-1808476725365964805: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } 2018-07-24 06:58:27,288 DEBUG [c.c.a.t.Request] (AgentManager-Handler-16:null) (logid:) Seq 1-1808476725365964807: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } 2018-07-24 06:58:27,288 DEBUG [c.c.a.t.Request] (AgentManager-Handler-20:null) (logid:) Seq 1-1808476725365964806: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } 2018-07-24 06:58:27,288 DEBUG [c.c.a.m.AgentAttache] (AgentManager-Handler-20:null) (logid:) Seq 1-1808476725365964808: Sending now. is current sequence. 2018-07-24 06:58:27,288 INFO [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-20:null) (logid:) SeqA 1-1808476725365964806: Response is not processed: Seq 1-1808476725365964806: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } 2018-07-24 06:58:27,339 DEBUG [c.c.a.t.Request] (AgentManager-Handler-3:null) (logid:) Seq 1-1808476725365964808: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.ReadyAnswer":{"result":true,"wait":0}}] } 2018-07-24 06:58:27,339 DEBUG [c.c.a.m.AgentAttache] (AgentManager-Handler-3:null) (logid:) Seq 1-1808476725365964808: No more commands found 2018-07-24 06:58:27,339 DEBUG [c.c.a.t.Request] (AgentManager-Handler-1:null) (logid:) Seq 1-1808476725365964801: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"details":"","wait":0}}] } 2018-07-24 06:58:27,339 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-1808476725365964808: Received: { Ans: , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 110, { ReadyAnswer } } 2018-07-24 06:58:27,339 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Transition:[Resource state = Enabled, Agent event = Ready, Host id = 1, name = trl-1553-k-M7-bstoyanov-kvm1] 2018-07-24 06:58:27,346 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-1808476725365964809: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.ReadyCommand":{"dcId":1,"hostId":1,"wait":0}}] } 2018-07-24 06:58:27,437 DEBUG [c.c.a.t.Request] (AgentManager-Handler-2:null) (logid:) Seq 1-1808476725365964809: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.ReadyAnswer":{"result":true,"wait":0}}] } 2018-07-24 06:58:27,437 DEBUG [c.c.a.m.AgentAttache] (AgentManager-Handler-2:null) (logid:) Seq 1-1808476725365964809: No more commands found 2018-07-24 06:58:27,437 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-41:ctx-f172c2e3) (logid:53a07183) Seq 1-1808476725365964809: Received: { Ans: , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 110, { ReadyAnswer } } 2018-07-24 06:58:28,389 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-5:null) (logid:) SeqA 4-267: Processing Seq 4-267: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] } 2018-07-24 06:58:28,392 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-5:null) (logid:) SeqA 4-267: Sending Seq 4-267: { Ans: , MgmtId: 7497603680190, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } 2018-07-24 06:58:29,019 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-c925920d) (logid:ced08733) StorageCollector is running... 2018-07-24 06:58:29,023 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (StatsCollector-2:ctx-c925920d) (logid:ced08733) getCommandHostDelegation: class com.cloud.agent.api.GetStorageStatsCommand 2018-07-24 06:58:29,023 DEBUG [c.c.h.XenServerGuru] (StatsCollector-2:ctx-c925920d) (logid:ced08733) We are returning the default host to execute commands because the command is not of Copy type. 2018-07-24 06:58:29,530 DEBUG [c.c.a.t.Request] (StatsCollector-2:ctx-c925920d) (logid:ced08733) Seq 3-3913909551161671713: Received: { Ans: , MgmtId: 7497603680190, via: 3(s-2-VM), Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2018-07-24 06:58:29,531 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (StatsCollector-2:ctx-c925920d) (logid:ced08733) getCommandHostDelegation: class com.cloud.agent.api.GetStorageStatsCommand 2018-07-24 06:58:29,531 DEBUG [c.c.h.XenServerGuru] (StatsCollector-2:ctx-c925920d) (logid:ced08733) We are returning the default host to execute commands because the command is not of Copy type. 2018-07-24 06:58:29,926 DEBUG [c.c.a.t.Request] (StatsCollector-2:ctx-c925920d) (logid:ced08733) Seq 1-1808476725365964810: Received: { Ans: , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2018-07-24 06:58:29,927 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (StatsCollector-2:ctx-c925920d) (logid:ced08733) getCommandHostDelegation: class com.cloud.agent.api.GetStorageStatsCommand 2018-07-24 06:58:29,927 DEBUG [c.c.h.XenServerGuru] (StatsCollector-2:ctx-c925920d) (logid:ced08733) We are returning the default host to execute commands because the command is not of Copy type. 2018-07-24 06:58:30,113 DEBUG [c.c.a.t.Request] (StatsCollector-2:ctx-c925920d) (logid:ced08733) Seq 2-2107403150632681497: Received: { Ans: , MgmtId: 7497603680190, via: 2(trl-1553-k-M7-bstoyanov-kvm2), Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2018-07-24 06:58:30,158 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-4:null) (logid:) SeqA 1--1: Processing Seq 1--1: { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 111, [{"com.cloud.agent.api.ShutdownCommand":{"reason":"sig.kill","detail":"Restarting due to new X509 certificates","wait":0}}] } 2018-07-24 06:58:30,158 INFO [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-4:null) (logid:) Host 1 has informed us that it is shutting down with reason sig.kill and detail Restarting due to new X509 certificates 2018-07-24 06:58:30,158 INFO [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Host 1 is disconnecting with event ShutdownRequested 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) The next status of agent 1is Disconnected, current status is Up 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Deregistering link for 1 with state Disconnected 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Remove Agent : 1 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.ConnectedAgentAttache] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Processing Disconnect. 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentAttache] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Seq 1-1808476725365964801: Sending disconnect to class com.cloud.network.security.SecurityGroupListener 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.hypervisor.xenserver.discoverer.XcpServerDiscoverer 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.hypervisor.hyperv.discoverer.HypervServerDiscoverer 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.storage.secondary.SecondaryStorageListener 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.vm.ClusteredVirtualMachineManagerImpl 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.network.security.SecurityGroupListener 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.deploy.DeploymentPlanningManagerImpl 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.hypervisor.vmware.manager.VmwareManagerImpl 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.storage.listener.StoragePoolMonitor 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: org.apache.cloudstack.engine.orchestration.NetworkOrchestrator 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.network.router.VirtualNetworkApplianceManagerImpl 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.storage.LocalStoragePoolListener 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.consoleproxy.ConsoleProxyListener 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.capacity.StorageCapacityListener 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.capacity.ComputeCapacityListener 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.network.NetworkUsageManagerImpl$DirectNetworkStatsListener 2018-07-24 06:58:30,159 DEBUG [c.c.n.NetworkUsageManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Disconnected called on 1 with status Disconnected 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.agent.manager.AgentManagerImpl$BehindOnPingListener 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.agent.manager.AgentManagerImpl$SetHostParamsListener 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.network.router.VpcVirtualNetworkApplianceManagerImpl 2018-07-24 06:58:30,159 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.storage.download.DownloadListener 2018-07-24 06:58:30,160 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Sending Disconnect to listener: com.cloud.storage.upload.UploadListener 2018-07-24 06:58:30,160 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Transition:[Resource state = Enabled, Agent event = ShutdownRequested, Host id = 1, name = trl-1553-k-M7-bstoyanov-kvm1] 2018-07-24 06:58:30,163 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentTaskPool-5:ctx-9c94dd1f) (logid:cf771f51) Notifying other nodes of to disconnect 2018-07-24 06:58:31,096 DEBUG [c.c.a.ApiServlet] (qtp788117692-19:ctx-f8643fc2) (logid:3bf6ad07) ===START=== 10.1.0.1 -- GET command=listHosts&response=json&type=routing&listAll=true&page=1&pagesize=20&_=1532415558435 2018-07-24 06:58:31,098 DEBUG [c.c.a.ApiServer] (qtp788117692-19:ctx-f8643fc2 ctx-85ee502e) (logid:3bf6ad07) CIDRs from which account 'Acct[96b3bfc9-8f09-11e8-890d-06d1ac0107be-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0 2018-07-24 06:58:31,100 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp788117692-19:ctx-f8643fc2 ctx-85ee502e) (logid:3bf6ad07) Received unknown parameters for command listHosts. Unknown parameters : listall 2018-07-24 06:58:31,100 DEBUG [c.c.a.q.QueryManagerImpl] (qtp788117692-19:ctx-f8643fc2 ctx-85ee502e) (logid:3bf6ad07) >>>Searching for hosts>>> 2018-07-24 06:58:31,105 DEBUG [c.c.a.q.QueryManagerImpl] (qtp788117692-19:ctx-f8643fc2 ctx-85ee502e) (logid:3bf6ad07) >>>Generating Response>>> 2018-07-24 06:58:31,111 DEBUG [c.c.a.ApiServlet] (qtp788117692-19:ctx-f8643fc2 ctx-85ee502e) (logid:3bf6ad07) ===END=== 10.1.0.1 -- GET command=listHosts&response=json&type=routing&listAll=true&page=1&pagesize=20&_=1532415558435 2018-07-24 06:58:34,709 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-52b462d0) (logid:e3180f15) Zone 1 is ready to launch console proxy 2018-07-24 06:58:34,815 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-20303fe7) (logid:1d0387c5) Zone 1 is ready to launch secondary storage VM 2018-07-24 06:58:36,826 DEBUG [c.c.a.ApiServlet] (qtp788117692-12:ctx-b0e032c8) (logid:80ed8d89) ===START=== 10.1.0.1 -- GET command=listHosts&response=json&type=routing&listAll=true&page=1&pagesize=20&_=1532415564219 2018-07-24 06:58:36,828 DEBUG [c.c.a.ApiServer] (qtp788117692-12:ctx-b0e032c8 ctx-e7145c99) (logid:80ed8d89) CIDRs from which account 'Acct[96b3bfc9-8f09-11e8-890d-06d1ac0107be-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0 2018-07-24 06:58:36,830 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp788117692-12:ctx-b0e032c8 ctx-e7145c99) (logid:80ed8d89) Received unknown parameters for command listHosts. Unknown parameters : listall 2018-07-24 06:58:36,830 DEBUG [c.c.a.q.QueryManagerImpl] (qtp788117692-12:ctx-b0e032c8 ctx-e7145c99) (logid:80ed8d89) >>>Searching for hosts>>> 2018-07-24 06:58:36,831 DEBUG [c.c.a.q.QueryManagerImpl] (qtp788117692-12:ctx-b0e032c8 ctx-e7145c99) (logid:80ed8d89) >>>Generating Response>>> 2018-07-24 06:58:36,837 DEBUG [c.c.a.ApiServlet] (qtp788117692-12:ctx-b0e032c8 ctx-e7145c99) (logid:80ed8d89) ===END=== 10.1.0.1 -- GET command=listHosts&response=json&type=routing&listAll=true&page=1&pagesize=20&_=1532415564219 2018-07-24 06:58:36,932 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-6836dd1b) (logid:4209891d) Begin cleanup expired async-jobs 2018-07-24 06:58:36,934 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-6836dd1b) (logid:4209891d) End cleanup expired async-jobs 2018-07-24 06:58:37,385 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) (logid:) Ping from 4(v-1-VM) 2018-07-24 06:58:37,855 DEBUG [c.c.a.ApiServlet] (qtp788117692-19:ctx-066e791e) (logid:0c32547c) ===START=== 10.1.0.1 -- GET command=listHosts&response=json&type=routing&listAll=true&page=1&pagesize=20&_=1532415565248 2018-07-24 06:58:37,857 DEBUG [c.c.a.ApiServer] (qtp788117692-19:ctx-066e791e ctx-3b3f37a4) (logid:0c32547c) CIDRs from which account 'Acct[96b3bfc9-8f09-11e8-890d-06d1ac0107be-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0 2018-07-24 06:58:37,858 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp788117692-19:ctx-066e791e ctx-3b3f37a4) (logid:0c32547c) Received unknown parameters for command listHosts. Unknown parameters : listall 2018-07-24 06:58:37,858 DEBUG [c.c.a.q.QueryManagerImpl] (qtp788117692-19:ctx-066e791e ctx-3b3f37a4) (logid:0c32547c) >>>Searching for hosts>>> 2018-07-24 06:58:37,860 DEBUG [c.c.a.q.QueryManagerImpl] (qtp788117692-19:ctx-066e791e ctx-3b3f37a4) (logid:0c32547c) >>>Generating Response>>> 2018-07-24 06:58:37,865 DEBUG [c.c.a.ApiServlet] (qtp788117692-19:ctx-066e791e ctx-3b3f37a4) (logid:0c32547c) ===END=== 10.1.0.1 -- GET command=listHosts&response=json&type=routing&listAll=true&page=1&pagesize=20&_=1532415565248 2018-07-24 06:58:38,377 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-8:null) (logid:) SeqA 4-269: Processing Seq 4-269: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"{\n \"connections\": []\n}","wait":0}}] } 2018-07-24 06:58:38,381 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-8:null) (logid:) SeqA 4-269: Sending Seq 4-269: { Ans: , MgmtId: 7497603680190, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } 2018-07-24 06:58:38,381 DEBUG [c.c.a.t.Request] (AgentManager-Handler-10:null) (logid:) Seq 1-0: Scheduling the first command { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 1, [{"com.cloud.agent.api.StartupRoutingCommand":{"cpuSockets":3,"cpus":3,"speed":2300,"memory":7515590656,"dom0MinMemory":1073741824,"poolSync":false,"supportsClonedVolumes":false,"caps":"hvm,snapshot","pool":"/root","hypervisorType":"KVM","hostDetails":{"Host.OS.Kernel.Version":"3.10.0-693.11.1.el7.x86_64","com.cloud.network.Networks.RouterPrivateIpStrategy":"HostLocal","Host.OS.Version":"7.4.1708","secured":"false","Host.OS":"CentOS"},"hostTags":[],"groupDetails":{},"type":"Routing","dataCenter":"1","pod":"1","cluster":"1","guid":"f3dc98e6-fea8-39bc-b98f-b00dc8c5ef28-LibvirtComputingResource","name":"trl-1553-k-M7-bstoyanov-kvm1","id":1,"version":"4.12.0.0-SNAPSHOT","iqn":"iqn.1994-05.com.redhat:cd656ffc7be5","privateIpAddress":"10.2.2.194","privateMacAddress":"06:7f:4c:01:07:ba","privateNetmask":"255.255.0.0","storageIpAddress":"10.2.2.194","storageNetmask":"255.255.0.0","storageMacAddress":"06:7f:4c:01:07:ba","resourceName":"LibvirtComputingResource","gatewayIpAddress":"10.2.254.254","msHostList":"10.2.2.198","wait":0}},{"com.cloud.agent.api.StartupStorageCommand":{"totalSize":0,"poolInfo":{"uuid":"1dadd203-4f15-402c-8178-356d7fc51b13","host":"10.2.2.194","localPath":"/var/lib/libvirt/images","hostPath":"/var/lib/libvirt/images","poolType":"Filesystem","capacityBytes":20935868416,"availableBytes":19152867328},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"1","pod":"1","guid":"f3dc98e6-fea8-39bc-b98f-b00dc8c5ef28-LibvirtComputingResource","name":"trl-1553-k-M7-bstoyanov-kvm1","id":1,"version":"4.12.0.0-SNAPSHOT","resourceName":"LibvirtComputingResource","msHostList":"10.2.2.198","wait":0}}] } 2018-07-24 06:58:38,382 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-0: Processing the first command { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 1, [{"com.cloud.agent.api.StartupRoutingCommand":{"cpuSockets":3,"cpus":3,"speed":2300,"memory":7515590656,"dom0MinMemory":1073741824,"poolSync":false,"supportsClonedVolumes":false,"caps":"hvm,snapshot","pool":"/root","hypervisorType":"KVM","hostDetails":{"Host.OS.Kernel.Version":"3.10.0-693.11.1.el7.x86_64","com.cloud.network.Networks.RouterPrivateIpStrategy":"HostLocal","Host.OS.Version":"7.4.1708","secured":"false","Host.OS":"CentOS"},"hostTags":[],"groupDetails":{},"type":"Routing","dataCenter":"1","pod":"1","cluster":"1","guid":"f3dc98e6-fea8-39bc-b98f-b00dc8c5ef28-LibvirtComputingResource","name":"trl-1553-k-M7-bstoyanov-kvm1","id":1,"version":"4.12.0.0-SNAPSHOT","iqn":"iqn.1994-05.com.redhat:cd656ffc7be5","privateIpAddress":"10.2.2.194","privateMacAddress":"06:7f:4c:01:07:ba","privateNetmask":"255.255.0.0","storageIpAddress":"10.2.2.194","storageNetmask":"255.255.0.0","storageMacAddress":"06:7f:4c:01:07:ba","resourceName":"LibvirtComputingResource","gatewayIpAddress":"10.2.254.254","msHostList":"10.2.2.198","wait":0}},{"com.cloud.agent.api.StartupStorageCommand":{"totalSize":0,"poolInfo":{"uuid":"1dadd203-4f15-402c-8178-356d7fc51b13","host":"10.2.2.194","localPath":"/var/lib/libvirt/images","hostPath":"/var/lib/libvirt/images","poolType":"Filesystem","capacityBytes":20935868416,"availableBytes":19152867328},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"1","pod":"1","guid":"f3dc98e6-fea8-39bc-b98f-b00dc8c5ef28-LibvirtComputingResource","name":"trl-1553-k-M7-bstoyanov-kvm1","id":1,"version":"4.12.0.0-SNAPSHOT","resourceName":"LibvirtComputingResource","msHostList":"10.2.2.198","wait":0}}] } 2018-07-24 06:58:38,384 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to CiscoVnmcElement 2018-07-24 06:58:38,384 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to NetscalerElement 2018-07-24 06:58:38,384 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to JuniperSRXExternalFirewallElement 2018-07-24 06:58:38,384 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to HypervServerDiscoverer 2018-07-24 06:58:38,384 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to BaremetalPxeManagerImpl 2018-07-24 06:58:38,384 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to XcpServerDiscoverer 2018-07-24 06:58:38,384 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to NiciraNvp 2018-07-24 06:58:38,384 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to Ovm3Discoverer 2018-07-24 06:58:38,384 DEBUG [c.c.h.o.r.Ovm3Discoverer] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) createHostVOForConnectedAgent: Host[-1-Routing] 2018-07-24 06:58:38,384 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to PremiumSecondaryStorageManagerImpl 2018-07-24 06:58:38,384 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to F5ExternalLoadBalancerElement 2018-07-24 06:58:38,384 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to Ovs 2018-07-24 06:58:38,384 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to VmwareServerDiscoverer 2018-07-24 06:58:38,384 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to ConsoleProxyManagerImpl 2018-07-24 06:58:38,384 DEBUG [c.c.r.ResourceManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Dispatching resource state event CREATE_HOST_VO_FOR_CONNECTED to KvmServerDiscoverer 2018-07-24 06:58:38,395 DEBUG [c.c.r.ResourceState] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Resource state update: [id = 1; name = trl-1553-k-M7-bstoyanov-kvm1; old state = Enabled; event = InternalCreated; new state = Enabled] 2018-07-24 06:58:38,395 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Transition:[Resource state = Enabled, Agent event = AgentConnected, Host id = 1, name = trl-1553-k-M7-bstoyanov-kvm1] 2018-07-24 06:58:38,401 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) create ClusteredAgentAttache for 1 2018-07-24 06:58:38,402 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: XcpServerDiscoverer 2018-07-24 06:58:38,402 DEBUG [c.c.h.x.d.XcpServerDiscoverer] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Not XenServer so moving on. 2018-07-24 06:58:38,402 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: HypervServerDiscoverer 2018-07-24 06:58:38,402 DEBUG [c.c.h.h.d.HypervServerDiscoverer] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Not Hyper-V hypervisor, so moving on. 2018-07-24 06:58:38,402 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: SecondaryStorageListener 2018-07-24 06:58:38,402 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: ClusteredVirtualMachineManagerImpl 2018-07-24 06:58:38,402 DEBUG [c.c.v.VirtualMachineManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Received startup command from hypervisor host. host id: 1 2018-07-24 06:58:38,402 INFO [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Reset VM power state sync for host: 1 2018-07-24 06:58:38,406 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: SecurityGroupListener 2018-07-24 06:58:38,406 INFO [c.c.n.s.SecurityGroupListener] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Received a host startup notification 2018-07-24 06:58:38,407 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-4102216310581100545: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.CleanupNetworkRulesCmd":{"interval":1825,"wait":0}}] } 2018-07-24 06:58:38,407 INFO [c.c.n.s.SecurityGroupListener] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Scheduled network rules cleanup, interval=1825 2018-07-24 06:58:38,407 INFO [c.c.n.s.SecurityGroupListener] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Received a host startup notification 2018-07-24 06:58:38,407 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: DeploymentPlanningManagerImpl 2018-07-24 06:58:38,408 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: VmwareManagerImpl 2018-07-24 06:58:38,408 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: StoragePoolMonitor 2018-07-24 06:58:38,409 DEBUG [c.c.s.l.StoragePoolMonitor] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Host 1 connected, connecting host to shared pool id 1 and sending storage pool information ... 2018-07-24 06:58:38,409 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Adding pool null to host 1 2018-07-24 06:58:38,411 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-4102216310581100546: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifyStoragePoolCommand":{"add":true,"pool":{"id":1,"uuid":"70c81596-64ae-391d-94fe-10440f1fd924","host":"10.2.0.16","path":"/acs/primary/trl-1553-k-M7-bstoyanov/trl-1553-k-M7-bstoyanov-kvm-pri1","port":2049,"type":"NetworkFilesystem"},"localPath":"/mnt//70c81596-64ae-391d-94fe-10440f1fd924","wait":0}}] } 2018-07-24 06:58:38,419 DEBUG [c.c.a.t.Request] (AgentManager-Handler-9:null) (logid:) Seq 1-4102216310581100545: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } 2018-07-24 06:58:38,427 DEBUG [c.c.a.t.Request] (AgentManager-Handler-13:null) (logid:) Seq 1-4102216310581100546: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ModifyStoragePoolAnswer":{"poolInfo":{"host":"10.2.0.16","localPath":"/mnt//70c81596-64ae-391d-94fe-10440f1fd924","hostPath":"/acs/primary/trl-1553-k-M7-bstoyanov/trl-1553-k-M7-bstoyanov-kvm-pri1","poolType":"NetworkFilesystem","capacityBytes":7514055770112,"availableBytes":6231612719104},"templateInfo":{},"result":true,"wait":0}}] } 2018-07-24 06:58:38,427 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-4102216310581100546: Received: { Ans: , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 10, { ModifyStoragePoolAnswer } } 2018-07-24 06:58:38,432 INFO [o.a.c.s.d.p.DefaultHostListener] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Connection established between storage pool org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@3fe507a4 and host 1 2018-07-24 06:58:38,434 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Found storage pool trl-1553-k-M7-bstoyanov-kvm-pri1 of type NetworkFilesystem with overprovisioning factor 2 2018-07-24 06:58:38,434 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Total over provisioned capacity calculated is 2 * 7514055770112 2018-07-24 06:58:38,434 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Total over provisioned capacity of the pool trl-1553-k-M7-bstoyanov-kvm-pri1 id: 1 is 15028111540224 2018-07-24 06:58:38,434 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Successfully set Capacity - 15028111540224 for capacity type - 3 , DataCenterId - 1, HostOrPoolId - 1, PodId 1 2018-07-24 06:58:38,434 DEBUG [c.c.s.l.StoragePoolMonitor] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Host 1 connected, connecting host to shared pool id 2 and sending storage pool information ... 2018-07-24 06:58:38,434 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Adding pool null to host 1 2018-07-24 06:58:38,436 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-4102216310581100547: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifyStoragePoolCommand":{"add":true,"pool":{"id":2,"uuid":"e1bc16c2-1053-3c0c-bd7a-5dbd76d5ce47","host":"10.2.0.16","path":"/acs/primary/trl-1553-k-M7-bstoyanov/trl-1553-k-M7-bstoyanov-kvm-pri2","port":2049,"type":"NetworkFilesystem"},"localPath":"/mnt//e1bc16c2-1053-3c0c-bd7a-5dbd76d5ce47","wait":0}}] } 2018-07-24 06:58:38,540 DEBUG [c.c.a.t.Request] (AgentManager-Handler-12:null) (logid:) Seq 1-4102216310581100547: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ModifyStoragePoolAnswer":{"poolInfo":{"host":"10.2.0.16","localPath":"/mnt//e1bc16c2-1053-3c0c-bd7a-5dbd76d5ce47","hostPath":"/acs/primary/trl-1553-k-M7-bstoyanov/trl-1553-k-M7-bstoyanov-kvm-pri2","poolType":"NetworkFilesystem","capacityBytes":7514055770112,"availableBytes":6231770005504},"templateInfo":{},"result":true,"wait":0}}] } 2018-07-24 06:58:38,540 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-4102216310581100547: Received: { Ans: , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 10, { ModifyStoragePoolAnswer } } 2018-07-24 06:58:38,541 INFO [o.a.c.s.d.p.DefaultHostListener] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Connection established between storage pool org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@7b4c41eb and host 1 2018-07-24 06:58:38,543 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Found storage pool trl-1553-k-M7-bstoyanov-kvm-pri2 of type NetworkFilesystem with overprovisioning factor 2 2018-07-24 06:58:38,543 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Total over provisioned capacity calculated is 2 * 7514055770112 2018-07-24 06:58:38,543 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Total over provisioned capacity of the pool trl-1553-k-M7-bstoyanov-kvm-pri2 id: 2 is 15028111540224 2018-07-24 06:58:38,543 DEBUG [c.c.s.StorageManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Successfully set Capacity - 15028111540224 for capacity type - 3 , DataCenterId - 1, HostOrPoolId - 2, PodId 1 2018-07-24 06:58:38,543 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: NetworkOrchestrator 2018-07-24 06:58:38,544 DEBUG [o.a.c.e.o.NetworkOrchestrator] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Host's hypervisorType is: KVM 2018-07-24 06:58:38,546 DEBUG [o.a.c.e.o.NetworkOrchestrator] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending CheckNetworkCommand to check the Network is setup correctly on Agent 2018-07-24 06:58:38,546 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-4102216310581100548: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.CheckNetworkCommand":{"networkInfoList":[{"physicalNetworkId":200,"privateNetworkName":"cloudbr0","storageNetworkName":"cloudbr0"},{"physicalNetworkId":201,"publicNetworkName":"cloudbr1","guestNetworkName":"cloudbr1"}],"wait":0}}] } 2018-07-24 06:58:38,640 DEBUG [c.c.a.t.Request] (AgentManager-Handler-18:null) (logid:) Seq 1-4102216310581100548: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.CheckNetworkAnswer":{"_reconnect":false,"result":true,"wait":0}}] } 2018-07-24 06:58:38,640 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-15:null) (logid:) Ping from 1(trl-1553-k-M7-bstoyanov-kvm1) 2018-07-24 06:58:38,640 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-4102216310581100548: Received: { Ans: , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 110, { CheckNetworkAnswer } } 2018-07-24 06:58:38,640 DEBUG [o.a.c.e.o.NetworkOrchestrator] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Network setup is correct on Agent 2018-07-24 06:58:38,640 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: SshKeysDistriMonitor 2018-07-24 06:58:38,640 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null) (logid:) Process host VM state report from ping process. host: 1 2018-07-24 06:58:38,640 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null) (logid:) Process VM state report. host: 1, number of records in report: 0 2018-07-24 06:58:38,640 DEBUG [c.c.a.m.AgentAttache] (AgentManager-Handler-18:null) (logid:) Seq 1-4102216310581100548: No more commands found 2018-07-24 06:58:38,641 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-15:null) (logid:) Done with process of VM state report. host: 1 2018-07-24 06:58:38,642 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-4102216310581100549: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifySshKeysCommand":{"wait":0}}] } 2018-07-24 06:58:38,642 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: VirtualNetworkApplianceManagerImpl 2018-07-24 06:58:38,642 INFO [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-15:null) (logid:) PingMap for agent: 1 will not be updated because agent is no longer in the PingMap 2018-07-24 06:58:38,642 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-15:null) (logid:) Not processing PingRoutingCommand for agent id=0; can't find the host in the DB 2018-07-24 06:58:38,643 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: LocalStoragePoolListener 2018-07-24 06:58:38,643 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: ConsoleProxyListener 2018-07-24 06:58:38,643 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: StorageCapacityListener 2018-07-24 06:58:38,643 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: ComputeCapacityListener 2018-07-24 06:58:38,644 DEBUG [c.c.c.CapacityManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Found 0 VMs on host 1 2018-07-24 06:58:38,645 DEBUG [c.c.c.CapacityManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Found 0 VM, not running on host 1 2018-07-24 06:58:38,646 DEBUG [c.c.c.CapacityManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) No need to calibrate cpu capacity, host:1 usedCpuCore: 0 reservedCpuCore: 0 2018-07-24 06:58:38,647 DEBUG [c.c.c.CapacityManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) No need to calibrate cpu capacity, host:1 usedCpu: 0 reservedCpu: 0 2018-07-24 06:58:38,647 DEBUG [c.c.c.CapacityManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) No need to calibrate memory capacity, host:1 usedMem: 0 reservedMem: 0 2018-07-24 06:58:38,649 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: DirectNetworkStatsListener 2018-07-24 06:58:38,649 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: BehindOnPingListener 2018-07-24 06:58:38,649 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: SetHostParamsListener 2018-07-24 06:58:38,650 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-4102216310581100550: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.SetHostParamsCommand":{"params":{"router.aggregation.command.each.timeout":"600"},"wait":0}}] } 2018-07-24 06:58:38,650 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: SshKeysDistriMonitor 2018-07-24 06:58:38,652 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-4102216310581100551: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifySshKeysCommand":{"wait":0}}] } 2018-07-24 06:58:38,652 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: VpcVirtualNetworkApplianceManagerImpl 2018-07-24 06:58:38,653 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: DownloadListener 2018-07-24 06:58:38,654 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Sending Connect to listener: UploadListener 2018-07-24 06:58:38,655 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-4102216310581100552: Waiting for Seq 4102216310581100550 Scheduling: { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.ReadyCommand":{"dcId":1,"hostId":1,"wait":0}}] } 2018-07-24 06:58:38,697 DEBUG [c.c.a.t.Request] (AgentManager-Handler-17:null) (logid:) Seq 1-4102216310581100549: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } 2018-07-24 06:58:38,697 DEBUG [c.c.a.t.Request] (AgentManager-Handler-20:null) (logid:) Seq 1-4102216310581100551: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } 2018-07-24 06:58:38,697 DEBUG [c.c.a.t.Request] (AgentManager-Handler-16:null) (logid:) Seq 1-4102216310581100550: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } 2018-07-24 06:58:38,697 DEBUG [c.c.a.m.AgentAttache] (AgentManager-Handler-16:null) (logid:) Seq 1-4102216310581100552: Sending now. is current sequence. 2018-07-24 06:58:38,698 INFO [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-16:null) (logid:) SeqA 1-4102216310581100550: Response is not processed: Seq 1-4102216310581100550: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } 2018-07-24 06:58:38,746 DEBUG [c.c.a.t.Request] (AgentManager-Handler-3:null) (logid:) Seq 1-4102216310581100545: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"details":"","wait":0}}] } 2018-07-24 06:58:38,746 DEBUG [c.c.a.t.Request] (AgentManager-Handler-1:null) (logid:) Seq 1-4102216310581100552: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.ReadyAnswer":{"result":true,"wait":0}}] } 2018-07-24 06:58:38,746 DEBUG [c.c.a.m.AgentAttache] (AgentManager-Handler-1:null) (logid:) Seq 1-4102216310581100552: No more commands found 2018-07-24 06:58:38,746 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-4102216310581100552: Received: { Ans: , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 110, { ReadyAnswer } } 2018-07-24 06:58:38,746 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Transition:[Resource state = Enabled, Agent event = Ready, Host id = 1, name = trl-1553-k-M7-bstoyanov-kvm1] 2018-07-24 06:58:38,758 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-4102216310581100553: Sending { Cmd , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.ReadyCommand":{"dcId":1,"hostId":1,"wait":0}}] } 2018-07-24 06:58:38,804 DEBUG [c.c.a.t.Request] (AgentManager-Handler-2:null) (logid:) Seq 1-4102216310581100553: Processing: { Ans: , MgmtId: 7497603680190, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.ReadyAnswer":{"result":true,"wait":0}}] } 2018-07-24 06:58:38,804 DEBUG [c.c.a.m.AgentAttache] (AgentManager-Handler-2:null) (logid:) Seq 1-4102216310581100553: No more commands found 2018-07-24 06:58:38,804 DEBUG [c.c.a.t.Request] (AgentConnectTaskPool-42:ctx-cd0deb15) (logid:729a1689) Seq 1-4102216310581100553: Received: { Ans: , MgmtId: 7497603680190, via: 1(trl-1553-k-M7-bstoyanov-kvm1), Ver: v1, Flags: 110, { ReadyAnswer } } 2018-07-24 06:58:39,636 DEBUG [c.c.a.ApiServlet] (qtp788117692-19:ctx-6a63dae6) (logid:f8a225e4) ===START=== 10.2.2.198 -- GET signatureversion=3&apiKey=LIN6rqXuaJwMPfGYFh13qDwYz5VNNz1J2J6qIOWcd3oLQOq0WtD4CwRundBL6rzXToa3lQOC_vKjI3nkHtiD8Q&expires=2018-07-24T07%3A08%3A39%2B0000&command=listHosts&signature=8urkC690IpkwpUHkFHhGgp93gyY%3D&response=json 2018-07-24 06:58:39,638 DEBUG [c.c.a.ApiServer] (qtp788117692-19:ctx-6a63dae6 ctx-2b0751ee) (logid:f8a225e4) CIDRs from which account 'Acct[96b3bfc9-8f09-11e8-890d-06d1ac0107be-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0 2018-07-24 06:58:39,640 DEBUG [c.c.a.q.QueryManagerImpl] (qtp788117692-19:ctx-6a63dae6 ctx-2b0751ee ctx-efacee4c) (logid:f8a225e4) >>>Searching for hosts>>> 2018-07-24 06:58:39,644 DEBUG [c.c.a.q.QueryManagerImpl] (qtp788117692-19:ctx-6a63dae6 ctx-2b0751ee ctx-efacee4c) (logid:f8a225e4) >>>Generating Response>>> 2018-07-24 06:58:39,653 DEBUG [c.c.a.ApiServlet] (qtp788117692-19:ctx-6a63dae6 ctx-2b0751ee ctx-efacee4c) (logid:f8a225e4) ===END=== 10.2.2.198 -- GET signatureversion=3&apiKey=LIN6rqXuaJwMPfGYFh13qDwYz5VNNz1J2J6qIOWcd3oLQOq0WtD4CwRundBL6rzXToa3lQOC_vKjI3nkHtiD8Q&expires=2018-07-24T07%3A08%3A39%2B0000&command=listHosts&signature=8urkC690IpkwpUHkFHhGgp93gyY%3D&response=json 2018-07-24 06:58:39,920 DEBUG [c.c.a.ApiServlet] (qtp788117692-12:ctx-9c4ea8db) (logid:59158410) ===START=== 10.1.0.1 -- GET command=listHosts&response=json&type=routing&listAll=true&page=1&pagesize=20&_=1532415567313 2018-07-24 06:58:39,923 DEBUG [c.c.a.ApiServer] (qtp788117692-12:ctx-9c4ea8db ctx-93f4ca2c) (logid:59158410) CIDRs from which account 'Acct[96b3bfc9-8f09-11e8-890d-06d1ac0107be-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0 2018-07-24 06:58:39,924 WARN [c.c.a.d.ParamGenericValidationWorker] (qtp788117692-12:ctx-9c4ea8db ctx-93f4ca2c) (logid:59158410) Received unknown parameters for command listHosts. Unknown parameters : listall 2018-07-24 06:58:39,925 DEBUG [c.c.a.q.QueryManagerImpl] (qtp788117692-12:ctx-9c4ea8db ctx-93f4ca2c) (logid:59158410) >>>Searching for hosts>>> 2018-07-24 06:58:39,929 DEBUG [c.c.a.q.QueryManagerImpl] (qtp788117692-12:ctx-9c4ea8db ctx-93f4ca2c) (logid:59158410) >>>Generating Response>>> 2018-07-24 06:58:39,934 DEBUG [c.c.a.ApiServlet] (qtp788117692-12:ctx-9c4ea8db ctx-93f4ca2c) (logid:59158410) ===END=== 10.1.0.1 -- GET command=listHosts&response=json&type=routing&listAll=true&page=1&pagesize=20&_=1532415567313 2018-07-24 06:58:40,254 DEBUG [c.c.a.ApiServlet] (qtp788117692-12:ctx-e6cac749) (logid:cf0b11b3) ===START=== 10.2.2.198 -- GET signatureversion=3&apiKey=LIN6rqXuaJwMPfGYFh13qDwYz5VNNz1J2J6qIOWcd3oLQOq0WtD4CwRundBL6rzXToa3lQOC_vKjI3nkHtiD8Q&expires=2018-07-24T07%3A08%3A40%2B0000&command=listCapacity&signature=x1GJbMeq%2FM9%2Bga8VsX3ItSvAt9s%3D&response=json 2018-07-24 06:58:40,256 DEBUG [c.c.a.ApiServer] (qtp788117692-12:ctx-e6cac749 ctx-983a3ec4) (logid:cf0b11b3) CIDRs from which account 'Acct[96b3bfc9-8f09-11e8-890d-06d1ac0107be-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0 2018-07-24 06:58:40,265 DEBUG [c.c.a.ApiServlet] (qtp788117692-12:ctx-e6cac749 ctx-983a3ec4 ctx-a4103ab7) (logid:cf0b11b3) ===END=== 10.2.2.198 -- GET signatureversion=3&apiKey=LIN6rqXuaJwMPfGYFh13qDwYz5VNNz1J2J6qIOWcd3oLQOq0WtD4CwRundBL6rzXToa3lQOC_vKjI3nkHtiD8Q&expires=2018-07-24T07%3A08%3A40%2B0000&command=listCapacity&signature=x1GJbMeq%2FM9%2Bga8VsX3ItSvAt9s%3D&response=json