[CLOUDSTACK-9962] Take VM Snapshot is failing for VM in stopped state, on KVM Hypervisor - ASF JIRA

XML

Word

Printable

JSON

Details

Type: Bug
Status: Open
Priority: Major
Resolution: Unresolved
Affects Version/s: 4.10.0.0
Fix Version/s: None
Component/s: KVM, Snapshot
Security Level: Public (Anyone can view this level - this is the default.)
Labels:
None
Environment:
KVM

Description

Steps to reproduce

1) launch a VM in KVM Host
2) Stop VM
3) Take VM Snapshot

Below is MS log for the exception

Last login: Wed Jun 14 12:30:54 on ttys000
pavankumar@HSL007960:~/ACP_HOME/cloudstack$ tail -n 500 vm
vmops-mar141801.log vmops-mar141945.log vmops-mar141945.log~ vmops.log vmops.log.2017-03-16.gz vmops.log.2017-05-09 vmops.log.2017-05-10.gz vmops.log.2017-06-07.gz vmware-base/
pavankumar@HSL007960:~/ACP_HOME/cloudstack$ tail -n 500 vmops.log
2017-06-14 16:11:47,193 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-7:null) (logid Ping from 3(localhost.localdomain)
2017-06-14 16:11:47,193 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-7:null) (logid Process host VM state report from ping process. host: 3
2017-06-14 16:11:47,196 INFO [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-7:null) (logid Unable to find matched VM in CloudStack DB. name: i-2-23-VM
2017-06-14 16:11:47,197 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-7:null) (logid Process VM state report. host: 3, number of records in report: 2
2017-06-14 16:11:47,197 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-7:null) (logid VM state report. host: 3, vm id: 1, power state: PowerOn
2017-06-14 16:11:47,200 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-7:null) (logid VM power state does not change, skip DB writing. vm id: 1
2017-06-14 16:11:47,200 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-7:null) (logid VM state report. host: 3, vm id: 2, power state: PowerOn
2017-06-14 16:11:47,202 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-7:null) (logid VM power state does not change, skip DB writing. vm id: 2
2017-06-14 16:11:47,204 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-7:null) (logid Done with process of VM state report. host: 3
2017-06-14 16:11:47,527 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-53a2d22e) (logid:7a254200) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:11:48,124 DEBUG [c.c.a.ApiServlet] (qtp752030228-23:ctx-6fb09013) (logid:4bab4c97) ===START=== 127.0.0.1 – GET command=listZones&id=79d64489-e87f-4b3c-8c22-5bededdb8772&response=json&_=1497436908122
2017-06-14 16:11:48,137 DEBUG [c.c.a.ApiServlet] (qtp752030228-23:ctx-6fb09013 ctx-7a97b488) (logid:4bab4c97) ===END=== 127.0.0.1 – GET command=listZones&id=79d64489-e87f-4b3c-8c22-5bededdb8772&response=json&_=1497436908122
2017-06-14 16:11:48,143 DEBUG [c.c.a.ApiServlet] (qtp752030228-288:ctx-5882ef58) (logid:70b3744d) ===START=== 127.0.0.1 – GET command=listVirtualMachines&id=59f8d6f5-afa0-4965-8966-4aa45726933c&response=json&_=1497436908141
2017-06-14 16:11:48,180 DEBUG [c.c.a.ApiServlet] (qtp752030228-288:ctx-5882ef58 ctx-074da5b4) (logid:70b3744d) ===END=== 127.0.0.1 – GET command=listVirtualMachines&id=59f8d6f5-afa0-4965-8966-4aa45726933c&response=json&_=1497436908141
2017-06-14 16:11:48,534 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-a25a40cc) (logid:f4ccf4fd) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:11:49,538 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-2934a1b6) (logid:a1b6551e) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:11:50,541 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-4d861c88) (logid:02bd6aae) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:11:51,546 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-86aeb9bc) (logid:ef48c386) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:11:52,549 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-0e857587) (logid:03c341fe) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:11:53,554 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-50ef0be7) (logid:d8f9678c) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:11:54,560 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-205bf9ca) (logid:824dd293) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:11:55,429 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) (logid SeqA 4-81743: Processing Seq 4-81743: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"

{\n \"connections\": []\n}

","wait":0}}] }
2017-06-14 16:11:55,432 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) (logid SeqA 4-81743: Sending Seq 4-81743: { Ans: , MgmtId: 4278190080, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2017-06-14 16:11:55,563 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-70b6c264) (logid:962286b6) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:11:56,051 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-28913b1a) (logid:12baa5e1) Begin cleanup expired async-jobs
2017-06-14 16:11:56,055 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-28913b1a) (logid:12baa5e1) End cleanup expired async-jobs
2017-06-14 16:11:56,571 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-5a0a0398) (logid:6d6de11d) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:11:57,055 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-20:null) (logid Ping from 5(s-2-VM)
2017-06-14 16:11:57,055 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-15:null) (logid Ping from 4(v-1-VM)
2017-06-14 16:11:57,311 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-4:null) (logid Ping from 3(localhost.localdomain)
2017-06-14 16:11:57,311 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid Process host VM state report from ping process. host: 3
2017-06-14 16:11:57,314 INFO [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid Unable to find matched VM in CloudStack DB. name: i-2-23-VM
2017-06-14 16:11:57,315 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid Process VM state report. host: 3, number of records in report: 2
2017-06-14 16:11:57,315 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid VM state report. host: 3, vm id: 1, power state: PowerOn
2017-06-14 16:11:57,316 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid VM power state does not change, skip DB writing. vm id: 1
2017-06-14 16:11:57,316 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid VM state report. host: 3, vm id: 2, power state: PowerOn
2017-06-14 16:11:57,317 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid VM power state does not change, skip DB writing. vm id: 2
2017-06-14 16:11:57,318 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid Done with process of VM state report. host: 3
2017-06-14 16:11:57,575 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-27cf8a13) (logid:6875e80e) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:11:58,165 DEBUG [c.c.s.StorageManagerImpl] (StorageManager-Scavenger-2:ctx-3e043f62) (logid:bd3cf9a3) Storage pool garbage collector found 0 templates to clean up in storage pool: Primary
2017-06-14 16:11:58,168 DEBUG [c.c.s.StorageManagerImpl] (StorageManager-Scavenger-2:ctx-3e043f62) (logid:bd3cf9a3) Secondary storage garbage collector found 0 templates to cleanup on template_store_ref for store: Secondary01
2017-06-14 16:11:58,170 DEBUG [c.c.s.StorageManagerImpl] (StorageManager-Scavenger-2:ctx-3e043f62) (logid:bd3cf9a3) Secondary storage garbage collector found 0 snapshots to cleanup on snapshot_store_ref for store: Secondary01
2017-06-14 16:11:58,171 DEBUG [c.c.s.StorageManagerImpl] (StorageManager-Scavenger-2:ctx-3e043f62) (logid:bd3cf9a3) Secondary storage garbage collector found 0 volumes to cleanup on volume_store_ref for store: Secondary01
2017-06-14 16:11:58,580 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-0beaa3eb) (logid:936b52b6) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:11:59,167 INFO [o.a.c.e.o.NetworkOrchestrator] (Network-Scavenger-1:ctx-0eedb26d) (logid:035c69db) NetworkGarbageCollector uses '20' seconds for GC interval.
2017-06-14 16:11:59,170 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Network-Scavenger-1:ctx-0eedb26d) (logid:035c69db) We found network 205 to be free for the first time. Adding it to the list: 1497436919
2017-06-14 16:11:59,587 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-03fcebde) (logid:b411c319) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:00,591 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-3af3ccf7) (logid:813d8e4b) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:01,597 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-d893b84d) (logid:5975ad24) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:02,605 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-c773d2c4) (logid:fe3a7d24) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:03,611 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-9e757a68) (logid:d07bf4e8) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:04,615 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-8de3c1cf) (logid:720b1e69) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:05,435 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid SeqA 4-81745: Processing Seq 4-81745: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"

{\n \"connections\": []\n}

","wait":0}}] }
2017-06-14 16:12:05,438 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid SeqA 4-81745: Sending Seq 4-81745: { Ans: , MgmtId: 4278190080, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2017-06-14 16:12:05,622 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-8d08f767) (logid:6489067f) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:06,054 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-30887c59) (logid:de2a8796) Begin cleanup expired async-jobs
2017-06-14 16:12:06,058 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-30887c59) (logid:de2a8796) End cleanup expired async-jobs
2017-06-14 16:12:06,166 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-1d4edaf1) (logid:ad983d97) Found 1 routers to update status.
2017-06-14 16:12:06,167 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-1d4edaf1) (logid:ad983d97) Found 0 VPC networks to update Redundant State.
2017-06-14 16:12:06,168 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-1d4edaf1) (logid:ad983d97) Found 0 networks to update RvR status.
2017-06-14 16:12:06,303 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-5dd40b03) (logid:34e9652e) Found 0 removed accounts to cleanup
2017-06-14 16:12:06,304 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-5dd40b03) (logid:34e9652e) Found 0 disabled accounts to cleanup
2017-06-14 16:12:06,305 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-5dd40b03) (logid:34e9652e) Found 0 inactive domains to cleanup
2017-06-14 16:12:06,306 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-5dd40b03) (logid:34e9652e) Found 0 disabled projects to cleanup
2017-06-14 16:12:06,625 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-43c3d870) (logid:acab161c) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:06,878 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) (logid Ping from 4(v-1-VM)
2017-06-14 16:12:07,045 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-5:null) (logid Ping from 5(s-2-VM)
2017-06-14 16:12:07,185 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) (logid Ping from 3(localhost.localdomain)
2017-06-14 16:12:07,185 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid Process host VM state report from ping process. host: 3
2017-06-14 16:12:07,194 INFO [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid Unable to find matched VM in CloudStack DB. name: i-2-23-VM
2017-06-14 16:12:07,196 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid Process VM state report. host: 3, number of records in report: 2
2017-06-14 16:12:07,196 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid VM state report. host: 3, vm id: 1, power state: PowerOn
2017-06-14 16:12:07,198 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid VM power state does not change, skip DB writing. vm id: 1
2017-06-14 16:12:07,198 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid VM state report. host: 3, vm id: 2, power state: PowerOn
2017-06-14 16:12:07,199 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid VM power state does not change, skip DB writing. vm id: 2
2017-06-14 16:12:07,201 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-14:null) (logid Done with process of VM state report. host: 3
2017-06-14 16:12:07,627 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-8998d76c) (logid:ae4c4ca2) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:08,488 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-9d9715b9) (logid:a795f94a) Zone 1 is ready to launch console proxy
2017-06-14 16:12:08,529 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-cbf1e779) (logid:9e6ae55e) Zone 1 is ready to launch secondary storage VM
2017-06-14 16:12:08,628 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-379720ea) (logid:be583393) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:09,636 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-d6c9d793) (logid:ac97b101) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:10,285 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-10:null) (logid SeqA 4-81747: Processing Seq 4-81747: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"

{\n \"connections\": []\n}

","wait":0}}] }
2017-06-14 16:12:10,287 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-10:null) (logid SeqA 4-81747: Sending Seq 4-81747: { Ans: , MgmtId: 4278190080, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2017-06-14 16:12:10,642 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-034c1431) (logid:b7aef03b) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:11,389 DEBUG [c.c.s.StatsCollector] (StatsCollector-6:ctx-b0be5653) (logid:585f44cf) StorageCollector is running...
2017-06-14 16:12:11,397 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (StatsCollector-6:ctx-b0be5653) (logid:585f44cf) getCommandHostDelegation: class com.cloud.agent.api.GetStorageStatsCommand
2017-06-14 16:12:11,397 DEBUG [c.c.h.XenServerGuru] (StatsCollector-6:ctx-b0be5653) (logid:585f44cf) getCommandHostDelegation: class com.cloud.agent.api.GetStorageStatsCommand
2017-06-14 16:12:11,645 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-96057699) (logid:ddeebf52) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:12,294 DEBUG [c.c.a.t.Request] (StatsCollector-6:ctx-b0be5653) (logid:585f44cf) Seq 5-3742209815368171539: Received: { Ans: , MgmtId: 4278190080, via: 5(s-2-VM), Ver: v1, Flags: 10,

{ GetStorageStatsAnswer } }
2017-06-14 16:12:12,295 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (StatsCollector-6:ctx-b0be5653) (logid:585f44cf) getCommandHostDelegation: class com.cloud.agent.api.GetStorageStatsCommand
2017-06-14 16:12:12,295 DEBUG [c.c.h.XenServerGuru] (StatsCollector-6:ctx-b0be5653) (logid:585f44cf) getCommandHostDelegation: class com.cloud.agent.api.GetStorageStatsCommand
2017-06-14 16:12:12,648 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-d8cb39f8) (logid:26512c25) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:13,063 DEBUG [c.c.a.t.Request] (StatsCollector-6:ctx-b0be5653) (logid:585f44cf) Seq 3-5718727101830397983: Received: { Ans: , MgmtId: 4278190080, via: 3(localhost.localdomain), Ver: v1, Flags: 10, { GetStorageStatsAnswer }

}
2017-06-14 16:12:13,654 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-0d620f7d) (logid:601a55fa) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:14,659 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-f35c8bcc) (logid:e775d9e3) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:15,667 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-0123d94a) (logid:910cd0bf) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:16,050 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-553641ad) (logid:98d5fd4d) Begin cleanup expired async-jobs
2017-06-14 16:12:16,056 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-553641ad) (logid:98d5fd4d) End cleanup expired async-jobs
2017-06-14 16:12:16,673 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-b86a4c20) (logid:e8c4a0dd) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:16,967 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-13:null) (logid Ping from 4(v-1-VM)
2017-06-14 16:12:17,041 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-3:null) (logid Ping from 5(s-2-VM)
2017-06-14 16:12:17,186 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-11:null) (logid Ping from 3(localhost.localdomain)
2017-06-14 16:12:17,186 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-11:null) (logid Process host VM state report from ping process. host: 3
2017-06-14 16:12:17,190 INFO [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-11:null) (logid Unable to find matched VM in CloudStack DB. name: i-2-23-VM
2017-06-14 16:12:17,192 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-11:null) (logid Process VM state report. host: 3, number of records in report: 2
2017-06-14 16:12:17,192 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-11:null) (logid VM state report. host: 3, vm id: 1, power state: PowerOn
2017-06-14 16:12:17,193 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-11:null) (logid VM power state does not change, skip DB writing. vm id: 1
2017-06-14 16:12:17,194 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-11:null) (logid VM state report. host: 3, vm id: 2, power state: PowerOn
2017-06-14 16:12:17,195 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-11:null) (logid VM power state does not change, skip DB writing. vm id: 2
2017-06-14 16:12:17,196 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-11:null) (logid Done with process of VM state report. host: 3
2017-06-14 16:12:17,677 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-107e6f75) (logid:b3e3a389) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:18,681 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-31ef41ba) (logid:cfa03f41) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:19,181 INFO [o.a.c.e.o.NetworkOrchestrator] (Network-Scavenger-1:ctx-137fa413) (logid:a8693a9b) NetworkGarbageCollector uses '20' seconds for GC interval.
2017-06-14 16:12:19,189 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Network-Scavenger-1:ctx-137fa413) (logid:a8693a9b) Network is already shutdown: Ntwk[205|Guest|8]
2017-06-14 16:12:19,685 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-82042341) (logid:06643ae8) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:20,310 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-16:null) (logid SeqA 4-81749: Processing Seq 4-81749: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"

{\n \"connections\": []\n}

","wait":0}}] }
2017-06-14 16:12:20,313 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-16:null) (logid SeqA 4-81749: Sending Seq 4-81749: { Ans: , MgmtId: 4278190080, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2017-06-14 16:12:20,689 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-4c569494) (logid:f8077758) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:21,695 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-d5ad78ce) (logid:b7861d16) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:22,702 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-c5d1da8a) (logid:20384afb) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:23,706 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-d730ca2d) (logid:d21ea199) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:24,711 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-fb22715d) (logid:c1fa31cb) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:24,830 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-c735678c) (logid:c9db39b1) HostStatsCollector is running...
2017-06-14 16:12:25,546 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-c735678c) (logid:c9db39b1) Seq 3-5718727101830397984: Received: { Ans: , MgmtId: 4278190080, via: 3(localhost.localdomain), Ver: v1, Flags: 10,

{ GetHostStatsAnswer }

}
2017-06-14 16:12:25,716 DEBUG [c.c.s.StatsCollector] (StatsCollector-5:ctx-b9ddd3d6) (logid:8115a9c5) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:26,050 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-f5096ce3) (logid:4a6eb109) Begin cleanup expired async-jobs
2017-06-14 16:12:26,054 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-f5096ce3) (logid:4a6eb109) End cleanup expired async-jobs
2017-06-14 16:12:26,311 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-202ff4de) (logid:25273d6a) Found 0 removed accounts to cleanup
2017-06-14 16:12:26,313 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-202ff4de) (logid:25273d6a) Found 0 disabled accounts to cleanup
2017-06-14 16:12:26,315 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-202ff4de) (logid:25273d6a) Found 0 inactive domains to cleanup
2017-06-14 16:12:26,317 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-202ff4de) (logid:25273d6a) Found 0 disabled projects to cleanup
2017-06-14 16:12:26,721 DEBUG [c.c.s.StatsCollector] (StatsCollector-5:ctx-c47a85f0) (logid:d039d010) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:26,890 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-18:null) (logid Ping from 4(v-1-VM)
2017-06-14 16:12:27,048 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-17:null) (logid Ping from 5(s-2-VM)
2017-06-14 16:12:27,224 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-12:null) (logid Ping from 3(localhost.localdomain)
2017-06-14 16:12:27,224 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-12:null) (logid Process host VM state report from ping process. host: 3
2017-06-14 16:12:27,228 INFO [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-12:null) (logid Unable to find matched VM in CloudStack DB. name: i-2-23-VM
2017-06-14 16:12:27,229 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-12:null) (logid Process VM state report. host: 3, number of records in report: 2
2017-06-14 16:12:27,229 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-12:null) (logid VM state report. host: 3, vm id: 1, power state: PowerOn
2017-06-14 16:12:27,231 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-12:null) (logid VM power state does not change, skip DB writing. vm id: 1
2017-06-14 16:12:27,231 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-12:null) (logid VM state report. host: 3, vm id: 2, power state: PowerOn
2017-06-14 16:12:27,232 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-12:null) (logid VM power state does not change, skip DB writing. vm id: 2
2017-06-14 16:12:27,233 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-12:null) (logid Done with process of VM state report. host: 3
2017-06-14 16:12:27,725 DEBUG [c.c.s.StatsCollector] (StatsCollector-5:ctx-4d4bd8d8) (logid:05633553) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:28,730 DEBUG [c.c.s.StatsCollector] (StatsCollector-5:ctx-1606bf25) (logid:92ded977) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:29,738 DEBUG [c.c.s.StatsCollector] (StatsCollector-5:ctx-9434bfbb) (logid:fe427dee) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:30,337 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-7:null) (logid SeqA 4-81751: Processing Seq 4-81751: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"

{\n \"connections\": []\n}

","wait":0}}] }
2017-06-14 16:12:30,342 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-7:null) (logid SeqA 4-81751: Sending Seq 4-81751: { Ans: , MgmtId: 4278190080, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2017-06-14 16:12:30,745 DEBUG [c.c.s.StatsCollector] (StatsCollector-5:ctx-2dceb5a0) (logid:adc40bd1) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:31,750 DEBUG [c.c.s.StatsCollector] (StatsCollector-5:ctx-db04e955) (logid:8eac3002) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:32,751 DEBUG [c.c.s.StatsCollector] (StatsCollector-5:ctx-a70c1507) (logid:b4dc6f0a) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:33,629 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-5c304e8f) (logid:6c3db43d) Resetting hosts suitable for reconnect
2017-06-14 16:12:33,630 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-5c304e8f) (logid:6c3db43d) Completed resetting hosts suitable for reconnect
2017-06-14 16:12:33,630 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-5c304e8f) (logid:6c3db43d) Acquiring hosts for clusters already owned by this management server
2017-06-14 16:12:33,631 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-5c304e8f) (logid:6c3db43d) Completed acquiring hosts for clusters already owned by this management server
2017-06-14 16:12:33,631 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-5c304e8f) (logid:6c3db43d) Acquiring hosts for clusters not owned by any management server
2017-06-14 16:12:33,631 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-5c304e8f) (logid:6c3db43d) Completed acquiring hosts for clusters not owned by any management server
2017-06-14 16:12:33,752 DEBUG [c.c.s.StatsCollector] (StatsCollector-5:ctx-781f1b88) (logid:38b7fec1) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:34,346 DEBUG [c.c.a.ApiServlet] (qtp752030228-25:ctx-dce061e9) (logid:2e697ac3) ===START=== 127.0.0.1 – GET command=createVMSnapshot&virtualmachineid=59f8d6f5-afa0-4965-8966-4aa45726933c&snapshotmemory=false&quiescevm=false&name=VMSnap&description=VMsnap&response=json&_=1497436954339
2017-06-14 16:12:34,421 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-2:ctx-12b3434b job-75) (logid:79220454) Add job-75 into job monitoring
2017-06-14 16:12:34,425 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (qtp752030228-25:ctx-dce061e9 ctx-1def1999) (logid:2e697ac3) submit async job-75, details: AsyncJobVO {id:75, userId: 2, accountId: 2, instanceType: None, instanceId: 1, cmd: org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd, cmdInfo: {"quiescevm":"false","description":"VMsnap","httpmethod":"GET","snapshotmemory":"false","ctxAccountId":"2","cmdEventType":"VMSNAPSHOT.CREATE","virtualmachineid":"59f8d6f5-afa0-4965-8966-4aa45726933c","response":"json","ctxUserId":"2","name":"VMSnap","ctxStartEventId":"141","id":"1","ctxDetails":"

{\"interface com.cloud.vm.VirtualMachine\":\"59f8d6f5-afa0-4965-8966-4aa45726933c\"}

","_":"1497436954339"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 4278190080, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2017-06-14 16:12:34,426 DEBUG [c.c.a.ApiServlet] (qtp752030228-25:ctx-dce061e9 ctx-1def1999) (logid:2e697ac3) ===END=== 127.0.0.1 – GET command=createVMSnapshot&virtualmachineid=59f8d6f5-afa0-4965-8966-4aa45726933c&snapshotmemory=false&quiescevm=false&name=VMSnap&description=VMsnap&response=json&_=1497436954339
2017-06-14 16:12:34,427 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-2:ctx-12b3434b job-75) (logid:24479ad0) Executing AsyncJobVO {id:75, userId: 2, accountId: 2, instanceType: None, instanceId: 1, cmd: org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd, cmdInfo: {"quiescevm":"false","description":"VMsnap","httpmethod":"GET","snapshotmemory":"false","ctxAccountId":"2","cmdEventType":"VMSNAPSHOT.CREATE","virtualmachineid":"59f8d6f5-afa0-4965-8966-4aa45726933c","response":"json","ctxUserId":"2","name":"VMSnap","ctxStartEventId":"141","id":"1","ctxDetails":"

{\"interface com.cloud.vm.VirtualMachine\":\"59f8d6f5-afa0-4965-8966-4aa45726933c\"}

","_":"1497436954339"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 4278190080, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2017-06-14 16:12:34,488 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-2:ctx-12b3434b job-75 ctx-522b12de) (logid:24479ad0) Sync job-76 execution on object VmWorkJobQueue.5
2017-06-14 16:12:34,758 DEBUG [c.c.s.StatsCollector] (StatsCollector-5:ctx-9d7dd58b) (logid:de2255d5) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:35,765 DEBUG [c.c.s.StatsCollector] (StatsCollector-5:ctx-0331fe52) (logid:9b9ac074) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:36,057 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-e2f54b08) (logid:ae5a3a4f) Execute sync-queue item: SyncQueueItemVO

{id:1, queueId: 12, contentType: AsyncJob, contentId: 76, lastProcessMsid: 4278190080, lastprocessNumber: 6, lastProcessTime: Wed Jun 14 16:12:36 IST 2017, created: Wed Jun 14 16:12:34 IST 2017}

2017-06-14 16:12:36,058 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-e2f54b08) (logid:ae5a3a4f) Schedule queued job-76
2017-06-14 16:12:36,064 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76) (logid:7ff5cb42) Add job-76 into job monitoring
2017-06-14 16:12:36,068 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-a576b165) (logid:75cd8bb5) Begin cleanup expired async-jobs
2017-06-14 16:12:36,072 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76) (logid:24479ad0) Executing AsyncJobVO

{id:76, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.vm.snapshot.VmWorkCreateVMSnapshot, cmdInfo: rO0ABXNyACxjb20uY2xvdWQudm0uc25hcHNob3QuVm1Xb3JrQ3JlYXRlVk1TbmFwc2hvdAG56JeB4A8uAgACWgAJcXVpZXNjZVZtTAAMdm1TbmFwc2hvdElkdAAQTGphdmEvbGFuZy9Mb25nO3hyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAABXQAFVZNU25hcHNob3RNYW5hZ2VySW1wbABzcgAOamF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHIAEGphdmEubGFuZy5OdW1iZXKGrJUdC5TgiwIAAHhwAAAAAAAAAAE, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 4278190080, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Jun 14 16:12:34 IST 2017}

2017-06-14 16:12:36,082 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-a576b165) (logid:75cd8bb5) End cleanup expired async-jobs
2017-06-14 16:12:36,082 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76) (logid:24479ad0) Run VM work job: com.cloud.vm.snapshot.VmWorkCreateVMSnapshot for VM 5, job origin: 75
2017-06-14 16:12:36,086 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76 ctx-f177563d) (logid:24479ad0) Execute VM work job: com.cloud.vm.snapshot.VmWorkCreateVMSnapshot

{"vmSnapshotId":1,"quiesceVm":false,"userId":2,"accountId":2,"vmId":5,"handlerName":"VMSnapshotManagerImpl"}

2017-06-14 16:12:36,130 DEBUG [c.c.a.t.Request] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76 ctx-f177563d) (logid:24479ad0) Seq 3-5718727101830397985: Sending { Cmd , MgmtId: 4278190080, via: 3(localhost.localdomain), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.CreateVMSnapshotCommand":{"vmUuid":"59f8d6f5-afa0-4965-8966-4aa45726933c","volumeTOs":[{"uuid":"e79c4457-4360-4804-82e4-7edbff85570d","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"2841def8-9e86-3e56-991c-46c510e62803","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/pavandev/acs/kvm/primary01","port":2049,"url":"NetworkFilesystem://10.223.110.232/export/home/pavandev/acs/kvm/primary01/?ROLE=Primary&STOREUUID=2841def8-9e86-3e56-991c-46c510e62803","isManaged":false}},"name":"ROOT-5","size":8589934592,"path":"e79c4457-4360-4804-82e4-7edbff85570d","volumeId":5,"vmName":"i-2-5-VM","accountId":4,"format":"QCOW2","provisioningType":"THIN","id":5,"deviceId":0,"hypervisorType":"KVM"}],"target":

{"id":1,"snapshotName":"i-2-5-VM_VS_20170614104234","type":"Disk","current":false,"description":"VMsnap","quiescevm":false}

,"vmName":"i-2-5-VM","guestOSType":"CentOS 5.5 (64-bit)","platformEmulator":"CentOS 5.5","wait":1800}}] }
2017-06-14 16:12:36,169 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-8511104e) (logid:85f413d9) Found 1 routers to update status.
2017-06-14 16:12:36,171 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-8511104e) (logid:85f413d9) Found 0 VPC networks to update Redundant State.
2017-06-14 16:12:36,173 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-8511104e) (logid:85f413d9) Found 0 networks to update RvR status.
2017-06-14 16:12:36,591 DEBUG [c.c.s.StatsCollector] (StatsCollector-1:ctx-e8f8f19c) (logid:2a92c8f4) AutoScaling Monitor is running...
2017-06-14 16:12:36,771 DEBUG [c.c.s.StatsCollector] (StatsCollector-6:ctx-7868a5fc) (logid:e81faf54) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:36,782 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-ae3fa229) (logid:e437540d) VmStatsCollector is running...
2017-06-14 16:12:36,881 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-9:null) (logid Ping from 4(v-1-VM)
2017-06-14 16:12:36,941 DEBUG [c.c.a.t.Request] (AgentManager-Handler-20:null) (logid Seq 3-5718727101830397985: Processing: { Ans: , MgmtId: 4278190080, via: 3, Ver: v1, Flags: 10, [{"com.cloud.agent.api.CreateVMSnapshotAnswer":{"result":false,"details":" Create VM snapshot failed due to org.libvirt.LibvirtException: Domain not found: no domain with matching name 'i-2-5-VM'","wait":0}}] }
2017-06-14 16:12:36,941 DEBUG [c.c.a.t.Request] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76 ctx-f177563d) (logid:24479ad0) Seq 3-5718727101830397985: Received: { Ans: , MgmtId: 4278190080, via: 3(localhost.localdomain), Ver: v1, Flags: 10,

{ CreateVMSnapshotAnswer }

}
2017-06-14 16:12:36,941 ERROR [o.a.c.s.v.DefaultVMSnapshotStrategy] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76 ctx-f177563d) (logid:24479ad0) Creating VM snapshot: i-2-5-VM_VS_20170614104234 failed due to Create VM snapshot failed due to org.libvirt.LibvirtException: Domain not found: no domain with matching name 'i-2-5-VM'
2017-06-14 16:12:36,944 DEBUG [c.c.v.s.VMSnapshotManagerImpl] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76 ctx-f177563d) (logid:24479ad0) Failed to create vm snapshot: 1
com.cloud.utils.exception.CloudRuntimeException: Creating VM snapshot: i-2-5-VM_VS_20170614104234 failed due to Create VM snapshot failed due to org.libvirt.LibvirtException: Domain not found: no domain with matching name 'i-2-5-VM'
at org.apache.cloudstack.storage.vmsnapshot.DefaultVMSnapshotStrategy.takeVMSnapshot(DefaultVMSnapshotStrategy.java:163)
at com.cloud.vm.snapshot.VMSnapshotManagerImpl.orchestrateCreateVMSnapshot(VMSnapshotManagerImpl.java:511)
at com.cloud.vm.snapshot.VMSnapshotManagerImpl.orchestrateCreateVMSnapshot(VMSnapshotManagerImpl.java:1193)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at com.cloud.vm.snapshot.VMSnapshotManagerImpl.handleVmWorkJob(VMSnapshotManagerImpl.java:1220)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
at com.sun.proxy.$Proxy227.handleVmWorkJob(Unknown Source)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:558)
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:506)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2017-06-14 16:12:36,945 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76 ctx-f177563d) (logid:24479ad0) Invocation exception, caused by: java.lang.NullPointerException
2017-06-14 16:12:36,945 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76 ctx-f177563d) (logid:24479ad0) Rethrow exception java.lang.NullPointerException
2017-06-14 16:12:36,945 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76) (logid:24479ad0) Done with run of VM work job: com.cloud.vm.snapshot.VmWorkCreateVMSnapshot for VM 5, job origin: 75
2017-06-14 16:12:36,946 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76) (logid:24479ad0) Unable to complete AsyncJobVO

, job origin:75
java.lang.NullPointerException
at com.cloud.vm.snapshot.VMSnapshotManagerImpl.orchestrateCreateVMSnapshot(VMSnapshotManagerImpl.java:1195)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at com.cloud.vm.snapshot.VMSnapshotManagerImpl.handleVmWorkJob(VMSnapshotManagerImpl.java:1220)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
at com.sun.proxy.$Proxy227.handleVmWorkJob(Unknown Source)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:558)
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:506)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2017-06-14 16:12:36,958 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76) (logid:24479ad0) Complete async job-76, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyAB5qYXZhLmxhbmcuTnVsbFBvaW50ZXJFeGNlcHRpb25HpaGO_zHhuAIAAHhyABpqYXZhLmxhbmcuUnVudGltZUV4Y2VwdGlvbp5fBkcKNIPlAgAAeHIAE2phdmEubGFuZy5FeGNlcHRpb27Q_R8-GjscxAIAAHhyABNqYXZhLmxhbmcuVGhyb3dhYmxl1cY1Jzl3uMsDAARMAAVjYXVzZXQAFUxqYXZhL2xhbmcvVGhyb3dhYmxlO0wADWRldGFpbE1lc3NhZ2V0ABJMamF2YS9sYW5nL1N0cmluZztbAApzdGFja1RyYWNldAAeW0xqYXZhL2xhbmcvU3RhY2tUcmFjZUVsZW1lbnQ7TAAUc3VwcHJlc3NlZEV4Y2VwdGlvbnN0ABBMamF2YS91dGlsL0xpc3Q7eHBxAH4ACHB1cgAeW0xqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnQ7AkYqPDz9IjkCAAB4cAAAAB9zcgAbamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50YQnFmiY23YUCAARJAApsaW5lTnVtYmVyTAAOZGVjbGFyaW5nQ2xhc3NxAH4ABUwACGZpbGVOYW1lcQB-AAVMAAptZXRob2ROYW1lcQB-AAV4cAAABKt0ACtjb20uY2xvdWQudm0uc25hcHNob3QuVk1TbmFwc2hvdE1hbmFnZXJJbXBsdAAaVk1TbmFwc2hvdE1hbmFnZXJJbXBsLmphdmF0ABtvcmNoZXN0cmF0ZUNyZWF0ZVZNU25hcHNob3RzcQB-AAv___-dAAkc3VuLnJlZmxlY3QuTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsdAAdTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsLmphdmF0AAdpbnZva2Uwc3EAfgALAAAAPnEAfgARcQB-ABJ0AAZpbnZva2VzcQB-AAsAAAArdAAoc3VuLnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgAVc3EAfgALAAAB8nQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-ABVzcQB-AAsAAABrdAAiY29tLmNsb3VkLnZtLlZtV29ya0pvYkhhbmRsZXJQcm94eXQAGlZtV29ya0pvYkhhbmRsZXJQcm94eS5qYXZhdAAPaGFuZGxlVm1Xb3JrSm9ic3EAfgALAAAExHEAfgANcQB-AA5xAH4AH3NxAH4AC___5xAH4AEXEAfgAScQB-ABNzcQB-AAsAAAA-cQB-ABFxAH4AEnEAfgAVc3EAfgALAAAAK3EAfgAXcQB-ABhxAH4AFXNxAH4ACwAAAfJxAH4AGnEAfgAbcQB-ABVzcQB-AAsAAAFNdAAob3JnLnNwcmluZ2ZyYW1ld29yay5hb3Auc3VwcG9ydC5Bb3BVdGlsc3QADUFvcFV0aWxzLmphdmF0AB5pbnZva2VKb2lucG9pbnRVc2luZ1JlZmxlY3Rpb25zcQB-AAsAAAC-dAA8b3JnLnNwcmluZ2ZyYW1ld29yay5hb3AuZnJhbWV3b3JrLlJlZmxlY3RpdmVNZXRob2RJbnZvY2F0aW9udAAfUmVmbGVjdGl2ZU1ldGhvZEludm9jYXRpb24uamF2YXQAD2ludm9rZUpvaW5wb2ludHNxAH4ACwAAAJ1xAH4AKnEAfgArdAAHcHJvY2VlZHNxAH4ACwAAAFx0AD9vcmcuc3ByaW5nZnJhbWV3b3JrLmFvcC5pbnRlcmNlcHRvci5FeHBvc2VJbnZvY2F0aW9uSW50ZXJjZXB0b3J0ACBFeHBvc2VJbnZvY2F0aW9uSW50ZXJjZXB0b3IuamF2YXEAfgAVc3EAfgALAAAAs3EAfgAqcQB-ACtxAH4ALnNxAH4ACwAAANV0ADRvcmcuc3ByaW5nZnJhbWV3b3JrLmFvcC5mcmFtZXdvcmsuSmRrRHluYW1pY0FvcFByb3h5dAAXSmRrRHluYW1pY0FvcFByb3h5LmphdmFxAH4AFXNxAH4AC____90ABdjb20uc3VuLnByb3h5LiRQcm94eTIyN3BxAH4AH3NxAH4ACwAAAGZ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4ACwAAAi50AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-AAsAAAAxdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-AAsAAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgALAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4ARnQAD2NhbGxXaXRoQ29udGV4dHNxAH4ACwAAADVxAH4ASXEAfgBGdAAOcnVuV2l0aENvbnRleHRzcQB-AAsAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-AEJxAH4AQ3NxAH4ACwAAAfpxAH4APXEAfgA-cQB-AENzcQB-AAsAAAH_dAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-AEdzcQB-AAsAAAEKdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgBDc3EAfgALAAAEdnQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgALAAACaXQALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4AWHEAfgBDc3EAfgALAAAC6XQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgBDc3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAd4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AZHg
2017-06-14 16:12:36,960 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76) (logid:24479ad0) Publish async job-76 complete on message bus
2017-06-14 16:12:36,960 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76) (logid:24479ad0) Wake up jobs related to job-76
2017-06-14 16:12:36,960 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76) (logid:24479ad0) Update db status for job-76
2017-06-14 16:12:36,961 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76) (logid:24479ad0) Wake up jobs joined with job-76 and disjoin all subjobs created from job- 76
2017-06-14 16:12:36,969 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76) (logid:24479ad0) Done executing com.cloud.vm.snapshot.VmWorkCreateVMSnapshot for job-76
2017-06-14 16:12:36,970 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-1:ctx-8768bad2 job-75/job-76) (logid:24479ad0) Remove job-76 from job monitoring
2017-06-14 16:12:36,984 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-2:ctx-12b3434b job-75) (logid:24479ad0) Unexpected exception while executing org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd
java.lang.RuntimeException: Unexpected exception
at com.cloud.vm.snapshot.VMSnapshotManagerImpl.createVMSnapshot(VMSnapshotManagerImpl.java:479)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
at org.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:107)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168)
at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:168)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
at com.sun.proxy.$Proxy227.createVMSnapshot(Unknown Source)
at org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd.execute(CreateVMSnapshotCmd.java:113)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:150)
at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:558)
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:506)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NullPointerException
at com.cloud.vm.snapshot.VMSnapshotManagerImpl.orchestrateCreateVMSnapshot(VMSnapshotManagerImpl.java:1195)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
... 28 more
2017-06-14 16:12:36,986 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-2:ctx-12b3434b job-75) (logid:24479ad0) Complete async job-75, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/

{"uuidList":[],"errorcode":530,"errortext":"Unexpected exception"}

2017-06-14 16:12:36,988 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-2:ctx-12b3434b job-75) (logid:24479ad0) Publish async job-75 complete on message bus
2017-06-14 16:12:36,988 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-2:ctx-12b3434b job-75) (logid:24479ad0) Wake up jobs related to job-75
2017-06-14 16:12:36,988 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-2:ctx-12b3434b job-75) (logid:24479ad0) Update db status for job-75
2017-06-14 16:12:36,990 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-2:ctx-12b3434b job-75) (logid:24479ad0) Wake up jobs joined with job-75 and disjoin all subjobs created from job- 75
2017-06-14 16:12:36,993 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-2:ctx-12b3434b job-75) (logid:24479ad0) Done executing org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd for job-75
2017-06-14 16:12:36,994 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-2:ctx-12b3434b job-75) (logid:24479ad0) Remove job-75 from job monitoring
2017-06-14 16:12:37,041 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-15:null) (logid Ping from 5(s-2-VM)
2017-06-14 16:12:37,173 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-4:null) (logid Ping from 3(localhost.localdomain)
2017-06-14 16:12:37,173 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid Process host VM state report from ping process. host: 3
2017-06-14 16:12:37,177 INFO [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid Unable to find matched VM in CloudStack DB. name: i-2-23-VM
2017-06-14 16:12:37,179 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid Process VM state report. host: 3, number of records in report: 2
2017-06-14 16:12:37,179 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid VM state report. host: 3, vm id: 1, power state: PowerOn
2017-06-14 16:12:37,181 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid VM power state does not change, skip DB writing. vm id: 1
2017-06-14 16:12:37,181 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid VM state report. host: 3, vm id: 2, power state: PowerOn
2017-06-14 16:12:37,182 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid VM power state does not change, skip DB writing. vm id: 2
2017-06-14 16:12:37,183 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-4:null) (logid Done with process of VM state report. host: 3
2017-06-14 16:12:37,453 DEBUG [c.c.a.ApiServlet] (qtp752030228-289:ctx-169f367e) (logid:7c88bb8b) ===START=== 127.0.0.1 – GET command=queryAsyncJobResult&jobId=24479ad0-5286-4f69-8566-5e113e2b0230&response=json&_=1497436957447
2017-06-14 16:12:37,471 DEBUG [c.c.a.ApiServlet] (qtp752030228-289:ctx-169f367e ctx-c458c183) (logid:7c88bb8b) ===END=== 127.0.0.1 – GET command=queryAsyncJobResult&jobId=24479ad0-5286-4f69-8566-5e113e2b0230&response=json&_=1497436957447
2017-06-14 16:12:37,773 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-e99964be) (logid:79e9d09d) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:38,188 DEBUG [c.c.s.StorageManagerImpl] (StorageManager-Scavenger-2:ctx-073f359c) (logid:df5991dc) Storage pool garbage collector found 0 templates to clean up in storage pool: Primary
2017-06-14 16:12:38,191 DEBUG [c.c.s.StorageManagerImpl] (StorageManager-Scavenger-2:ctx-073f359c) (logid:df5991dc) Secondary storage garbage collector found 0 templates to cleanup on template_store_ref for store: Secondary01
2017-06-14 16:12:38,192 DEBUG [c.c.s.StorageManagerImpl] (StorageManager-Scavenger-2:ctx-073f359c) (logid:df5991dc) Secondary storage garbage collector found 0 snapshots to cleanup on snapshot_store_ref for store: Secondary01
2017-06-14 16:12:38,192 DEBUG [c.c.s.StorageManagerImpl] (StorageManager-Scavenger-2:ctx-073f359c) (logid:df5991dc) Secondary storage garbage collector found 0 volumes to cleanup on volume_store_ref for store: Secondary01
2017-06-14 16:12:38,489 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-32c0b081) (logid:6bc75ea0) Zone 1 is ready to launch console proxy
2017-06-14 16:12:38,534 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-075ec500) (logid:f0a89d6d) Zone 1 is ready to launch secondary storage VM
2017-06-14 16:12:38,778 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-fbf96fb7) (logid:bc00e2d9) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:39,196 INFO [o.a.c.e.o.NetworkOrchestrator] (Network-Scavenger-1:ctx-f59b219a) (logid:e42ade1f) NetworkGarbageCollector uses '20' seconds for GC interval.
2017-06-14 16:12:39,201 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Network-Scavenger-1:ctx-f59b219a) (logid:e42ade1f) We found network 205 to be free for the first time. Adding it to the list: 1497436959
2017-06-14 16:12:39,785 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-65f87af1) (logid:15a41c88) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:40,445 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid SeqA 4-81753: Processing Seq 4-81753: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"

{\n \"connections\": []\n}

","wait":0}}] }
2017-06-14 16:12:40,449 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-2:null) (logid SeqA 4-81753: Sending Seq 4-81753: { Ans: , MgmtId: 4278190080, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2017-06-14 16:12:40,792 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-019f3056) (logid:8921db90) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:41,799 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-96506e08) (logid:ab9dff42) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:42,802 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-6be0ecad) (logid:5fe2297e) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:43,806 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-a0a674b3) (logid:0fe05e76) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:44,814 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-6e530ed5) (logid:da67969a) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:45,354 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) (logid SeqA 4-81754: Processing Seq 4-81754: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"

{\n \"connections\": []\n}

","wait":0}}] }
2017-06-14 16:12:45,356 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-1:null) (logid SeqA 4-81754: Sending Seq 4-81754: { Ans: , MgmtId: 4278190080, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2017-06-14 16:12:45,818 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-462d8d0a) (logid:2597abdc) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:46,046 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-9772b804) (logid:89c6cee5) Begin cleanup expired async-jobs
2017-06-14 16:12:46,052 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-9772b804) (logid:89c6cee5) End cleanup expired async-jobs
2017-06-14 16:12:46,307 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-7600f192) (logid:af984f73) Found 0 removed accounts to cleanup
2017-06-14 16:12:46,308 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-7600f192) (logid:af984f73) Found 0 disabled accounts to cleanup
2017-06-14 16:12:46,310 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-7600f192) (logid:af984f73) Found 0 inactive domains to cleanup
2017-06-14 16:12:46,311 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-7600f192) (logid:af984f73) Found 0 disabled projects to cleanup
2017-06-14 16:12:46,820 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-43287fd8) (logid:dfd90d08) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:46,942 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-5:null) (logid Ping from 4(v-1-VM)
2017-06-14 16:12:47,049 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-14:null) (logid Ping from 5(s-2-VM)
2017-06-14 16:12:47,184 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-10:null) (logid Ping from 3(localhost.localdomain)
2017-06-14 16:12:47,184 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-10:null) (logid Process host VM state report from ping process. host: 3
2017-06-14 16:12:47,188 INFO [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-10:null) (logid Unable to find matched VM in CloudStack DB. name: i-2-23-VM
2017-06-14 16:12:47,190 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-10:null) (logid Process VM state report. host: 3, number of records in report: 2
2017-06-14 16:12:47,190 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-10:null) (logid VM state report. host: 3, vm id: 1, power state: PowerOn
2017-06-14 16:12:47,191 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-10:null) (logid VM power state does not change, skip DB writing. vm id: 1
2017-06-14 16:12:47,191 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-10:null) (logid VM state report. host: 3, vm id: 2, power state: PowerOn
2017-06-14 16:12:47,193 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-10:null) (logid VM power state does not change, skip DB writing. vm id: 2
2017-06-14 16:12:47,195 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-10:null) (logid Done with process of VM state report. host: 3
2017-06-14 16:12:47,824 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-2a28e1e9) (logid:570f3bcf) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:48,831 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-f4511774) (logid:8d33f667) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:49,838 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-308a1018) (logid:0f6cf156) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:50,841 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-9b461d18) (logid:61801806) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:51,843 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-cd8023ee) (logid:9671975e) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:52,851 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-ea69f749) (logid:379983a0) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:53,855 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-18e055ea) (logid:27353426) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:54,858 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-b14d188d) (logid:e4e27ec7) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:55,290 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-8:null) (logid SeqA 4-81756: Processing Seq 4-81756: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"

{\n \"connections\": []\n}

","wait":0}}] }
2017-06-14 16:12:55,292 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-8:null) (logid SeqA 4-81756: Sending Seq 4-81756: { Ans: , MgmtId: 4278190080, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2017-06-14 16:12:55,863 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-114c9900) (logid:089e81c3) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:56,051 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-5b1c0bde) (logid:6a6fd84f) Begin cleanup expired async-jobs
2017-06-14 16:12:56,055 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-5b1c0bde) (logid:6a6fd84f) End cleanup expired async-jobs
2017-06-14 16:12:56,869 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-e7cf5d61) (logid:397bc273) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:56,873 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-6:null) (logid Ping from 4(v-1-VM)
2017-06-14 16:12:57,039 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-13:null) (logid Ping from 5(s-2-VM)
2017-06-14 16:12:57,207 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-3:null) (logid Ping from 3(localhost.localdomain)
2017-06-14 16:12:57,207 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-3:null) (logid Process host VM state report from ping process. host: 3
2017-06-14 16:12:57,212 INFO [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-3:null) (logid Unable to find matched VM in CloudStack DB. name: i-2-23-VM
2017-06-14 16:12:57,213 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-3:null) (logid Process VM state report. host: 3, number of records in report: 2
2017-06-14 16:12:57,213 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-3:null) (logid VM state report. host: 3, vm id: 1, power state: PowerOn
2017-06-14 16:12:57,215 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-3:null) (logid VM power state does not change, skip DB writing. vm id: 1
2017-06-14 16:12:57,215 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-3:null) (logid VM state report. host: 3, vm id: 2, power state: PowerOn
2017-06-14 16:12:57,216 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-3:null) (logid VM power state does not change, skip DB writing. vm id: 2
2017-06-14 16:12:57,217 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-3:null) (logid Done with process of VM state report. host: 3
2017-06-14 16:12:57,872 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-b27772ce) (logid:f596c81d) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:58,879 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-f3d13567) (logid:10d13171) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:12:59,210 INFO [o.a.c.e.o.NetworkOrchestrator] (Network-Scavenger-1:ctx-fb5bbe09) (logid:6997571a) NetworkGarbageCollector uses '20' seconds for GC interval.
2017-06-14 16:12:59,221 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Network-Scavenger-1:ctx-fb5bbe09) (logid:6997571a) Network is already shutdown: Ntwk[205|Guest|8]
2017-06-14 16:12:59,883 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-5c9f8a91) (logid:611b94f3) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:13:00,311 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-11:null) (logid SeqA 4-81758: Processing Seq 4-81758: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"

{\n \"connections\": []\n}

","wait":0}}] }
2017-06-14 16:13:00,316 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-11:null) (logid SeqA 4-81758: Sending Seq 4-81758: { Ans: , MgmtId: 4278190080, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2017-06-14 16:13:00,887 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-ff01d3a5) (logid:6dc568ea) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:13:01,890 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-f8d69e98) (logid:71901fb3) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:13:02,895 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-eff0654d) (logid:6a27a647) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:13:03,900 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-5443f4c0) (logid:d496109e) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:13:04,903 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-7f429c5f) (logid:957c8b64) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:13:05,908 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-924f2953) (logid:228be278) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:13:06,047 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-327fcbbf) (logid:7d15f769) Begin cleanup expired async-jobs
2017-06-14 16:13:06,053 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-327fcbbf) (logid:7d15f769) End cleanup expired async-jobs
2017-06-14 16:13:06,069 DEBUG [c.c.n.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:ctx-59b686ef) (logid:0f54b1ee) External devices are not used. Skipping external device usage collection
2017-06-14 16:13:06,161 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:ctx-a05e1f3e) (logid:9248a263) Found 0 running routers.
2017-06-14 16:13:06,162 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-0e4c7eb7) (logid:1ecf5950) Found 1 routers to update status.
2017-06-14 16:13:06,163 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-0e4c7eb7) (logid:1ecf5950) Found 0 VPC networks to update Redundant State.
2017-06-14 16:13:06,164 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-0e4c7eb7) (logid:1ecf5950) Found 0 networks to update RvR status.
2017-06-14 16:13:06,311 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-14326169) (logid:8e75d2e3) Found 0 removed accounts to cleanup
2017-06-14 16:13:06,313 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-14326169) (logid:8e75d2e3) Found 0 disabled accounts to cleanup
2017-06-14 16:13:06,315 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-14326169) (logid:8e75d2e3) Found 0 inactive domains to cleanup
2017-06-14 16:13:06,316 INFO [c.c.u.AccountManagerImpl] (AccountChecker-1:ctx-14326169) (logid:8e75d2e3) Found 0 disabled projects to cleanup
2017-06-14 16:13:06,912 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-8f87a697) (logid:90db1973) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:13:07,008 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-16:null) (logid Ping from 4(v-1-VM)
2017-06-14 16:13:07,183 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-19:null) (logid Ping from 5(s-2-VM)
2017-06-14 16:13:07,242 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-18:null) (logid Ping from 3(localhost.localdomain)
2017-06-14 16:13:07,243 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-18:null) (logid Process host VM state report from ping process. host: 3
2017-06-14 16:13:07,245 INFO [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-18:null) (logid Unable to find matched VM in CloudStack DB. name: i-2-23-VM
2017-06-14 16:13:07,247 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-18:null) (logid Process VM state report. host: 3, number of records in report: 2
2017-06-14 16:13:07,247 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-18:null) (logid VM state report. host: 3, vm id: 1, power state: PowerOn
2017-06-14 16:13:07,249 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-18:null) (logid VM power state does not change, skip DB writing. vm id: 1
2017-06-14 16:13:07,249 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-18:null) (logid VM state report. host: 3, vm id: 2, power state: PowerOn
2017-06-14 16:13:07,251 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-18:null) (logid VM power state does not change, skip DB writing. vm id: 2
2017-06-14 16:13:07,252 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentManager-Handler-18:null) (logid Done with process of VM state report. host: 3
2017-06-14 16:13:07,914 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-8e5194eb) (logid:4fd65b6d) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:13:08,490 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-c5cf0859) (logid:2108e5dd) Zone 1 is ready to launch console proxy
2017-06-14 16:13:08,531 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-18247b6a) (logid:6b5bfee9) Zone 1 is ready to launch secondary storage VM
2017-06-14 16:13:08,834 INFO [c.c.a.m.AgentManagerImpl] (AgentMonitor-1:ctx-b6c685ed) (logid:2002cffe) Found the following agents behind on ping: [3, 4, 5]
2017-06-14 16:13:08,837 DEBUG [c.c.h.Status] (AgentMonitor-1:ctx-b6c685ed) (logid:2002cffe) Ping timeout for agent 3, do invstigation
2017-06-14 16:13:08,838 WARN [c.c.a.m.AgentManagerImpl] (AgentMonitor-1:ctx-b6c685ed) (logid:2002cffe) Disconnect agent for CPVM/SSVM due to physical connection close. host: 4
2017-06-14 16:13:08,839 INFO [c.c.a.m.AgentManagerImpl] (AgentTaskPool-3:ctx-d46f2f55) (logid:22aa214e) Investigating why host 3 has disconnected with event PingTimeout
2017-06-14 16:13:08,840 INFO [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Host 4 is disconnecting with event ShutdownRequested
2017-06-14 16:13:08,842 WARN [c.c.a.m.AgentManagerImpl] (AgentMonitor-1:ctx-b6c685ed) (logid:2002cffe) Disconnect agent for CPVM/SSVM due to physical connection close. host: 5
2017-06-14 16:13:08,842 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-3:ctx-d46f2f55) (logid:22aa214e) checking if agent (3) is alive
2017-06-14 16:13:08,843 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) The next status of agent 4is Disconnected, current status is Up
2017-06-14 16:13:08,843 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Deregistering link for 4 with state Disconnected
2017-06-14 16:13:08,843 INFO [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Host 5 is disconnecting with event ShutdownRequested
2017-06-14 16:13:08,843 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Remove Agent : 4
2017-06-14 16:13:08,843 DEBUG [c.c.a.m.ConnectedAgentAttache] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Processing Disconnect.
2017-06-14 16:13:08,843 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.hypervisor.xenserver.discoverer.XcpServerDiscoverer
2017-06-14 16:13:08,843 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.hypervisor.hyperv.discoverer.HypervServerDiscoverer
2017-06-14 16:13:08,843 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.storage.listener.StoragePoolMonitor
2017-06-14 16:13:08,843 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.storage.secondary.SecondaryStorageListener
2017-06-14 16:13:08,843 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.network.security.SecurityGroupListener
2017-06-14 16:13:08,843 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: org.apache.cloudstack.engine.orchestration.NetworkOrchestrator
2017-06-14 16:13:08,843 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.vm.ClusteredVirtualMachineManagerImpl
2017-06-14 16:13:08,844 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.deploy.DeploymentPlanningManagerImpl
2017-06-14 16:13:08,844 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.capacity.StorageCapacityListener
2017-06-14 16:13:08,844 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.capacity.ComputeCapacityListener
2017-06-14 16:13:08,844 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.network.NetworkUsageManagerImpl$DirectNetworkStatsListener
2017-06-14 16:13:08,844 DEBUG [c.c.n.NetworkUsageManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Disconnected called on 4 with status Disconnected
2017-06-14 16:13:08,844 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor
2017-06-14 16:13:08,844 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.network.router.VpcVirtualNetworkApplianceManagerImpl
2017-06-14 16:13:08,845 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.agent.manager.AgentManagerImpl$BehindOnPingListener
2017-06-14 16:13:08,845 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.agent.manager.AgentManagerImpl$SetHostParamsListener
2017-06-14 16:13:08,845 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor
2017-06-14 16:13:08,845 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.network.router.VirtualNetworkApplianceManagerImpl
2017-06-14 16:13:08,845 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.storage.download.DownloadListener
2017-06-14 16:13:08,845 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.storage.upload.UploadListener
2017-06-14 16:13:08,845 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) The next status of agent 5is Disconnected, current status is Up
2017-06-14 16:13:08,845 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Deregistering link for 5 with state Disconnected
2017-06-14 16:13:08,845 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Remove Agent : 5
2017-06-14 16:13:08,845 DEBUG [c.c.a.m.ConnectedAgentAttache] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Processing Disconnect.
2017-06-14 16:13:08,845 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.hypervisor.xenserver.discoverer.XcpServerDiscoverer
2017-06-14 16:13:08,845 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.hypervisor.hyperv.discoverer.HypervServerDiscoverer
2017-06-14 16:13:08,845 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.storage.listener.StoragePoolMonitor
2017-06-14 16:13:08,846 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.storage.secondary.SecondaryStorageListener
2017-06-14 16:13:08,846 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.network.security.SecurityGroupListener
2017-06-14 16:13:08,846 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: org.apache.cloudstack.engine.orchestration.NetworkOrchestrator
2017-06-14 16:13:08,846 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.vm.ClusteredVirtualMachineManagerImpl
2017-06-14 16:13:08,846 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.deploy.DeploymentPlanningManagerImpl
2017-06-14 16:13:08,846 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.capacity.StorageCapacityListener
2017-06-14 16:13:08,846 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.capacity.ComputeCapacityListener
2017-06-14 16:13:08,846 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.network.NetworkUsageManagerImpl$DirectNetworkStatsListener
2017-06-14 16:13:08,846 DEBUG [c.c.n.NetworkUsageManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Disconnected called on 5 with status Disconnected
2017-06-14 16:13:08,847 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor
2017-06-14 16:13:08,847 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.consoleproxy.ConsoleProxyListener
2017-06-14 16:13:08,847 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.network.router.VpcVirtualNetworkApplianceManagerImpl
2017-06-14 16:13:08,847 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.agent.manager.AgentManagerImpl$BehindOnPingListener
2017-06-14 16:13:08,847 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.agent.manager.AgentManagerImpl$SetHostParamsListener
2017-06-14 16:13:08,847 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor
2017-06-14 16:13:08,847 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.network.router.VirtualNetworkApplianceManagerImpl
2017-06-14 16:13:08,847 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.storage.download.DownloadListener
2017-06-14 16:13:08,847 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.storage.upload.UploadListener
2017-06-14 16:13:08,847 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.consoleproxy.ConsoleProxyListener
2017-06-14 16:13:08,849 DEBUG [c.c.a.t.Request] (AgentTaskPool-3:ctx-d46f2f55) (logid:22aa214e) Seq 3-5718727101830397986: Sending { Cmd , MgmtId: 4278190080, via: 3(localhost.localdomain), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.CheckHealthCommand":{"wait":50}}] }
2017-06-14 16:13:08,849 INFO [c.c.c.ConsoleProxyManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Console proxy agent disconnected, proxy: v-1-VM
2017-06-14 16:13:08,849 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Sending Disconnect to listener: com.cloud.storage.LocalStoragePoolListener
2017-06-14 16:13:08,849 DEBUG [c.c.h.Status] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Transition:[Resource state = Enabled, Agent event = ShutdownRequested, Host id = 5, name = s-2-VM]
2017-06-14 16:13:08,851 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Sending Disconnect to listener: com.cloud.storage.LocalStoragePoolListener
2017-06-14 16:13:08,852 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentTaskPool-5:ctx-8f81c0d6) (logid:bef9a8ba) Notifying other nodes of to disconnect
2017-06-14 16:13:08,852 DEBUG [c.c.h.Status] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Transition:[Resource state = Enabled, Agent event = ShutdownRequested, Host id = 4, name = v-1-VM]
2017-06-14 16:13:08,855 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentTaskPool-4:ctx-51c0151c) (logid:a372c9fc) Notifying other nodes of to disconnect
2017-06-14 16:13:08,921 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-60881bc7) (logid:1af97e25) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:13:09,690 DEBUG [c.c.a.t.Request] (AgentManager-Handler-17:null) (logid Seq 3-5718727101830397986: Processing: { Ans: , MgmtId: 4278190080, via: 3, Ver: v1, Flags: 10, [{"com.cloud.agent.api.CheckHealthAnswer":{"result":true,"details":"resource is alive","wait":0}}] }
2017-06-14 16:13:09,690 DEBUG [c.c.a.t.Request] (AgentTaskPool-3:ctx-d46f2f55) (logid:22aa214e) Seq 3-5718727101830397986: Received: { Ans: , MgmtId: 4278190080, via: 3(localhost.localdomain), Ver: v1, Flags: 10,

{ CheckHealthAnswer }

}
2017-06-14 16:13:09,690 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-3:ctx-d46f2f55) (logid:22aa214e) Details from executing class com.cloud.agent.api.CheckHealthCommand: resource is alive
2017-06-14 16:13:09,690 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-3:ctx-d46f2f55) (logid:22aa214e) agent (3) responded to checkHeathCommand, reporting that agent is Up
2017-06-14 16:13:09,690 INFO [c.c.a.m.AgentManagerImpl] (AgentTaskPool-3:ctx-d46f2f55) (logid:22aa214e) The agent from host 3 state determined is Up
2017-06-14 16:13:09,690 INFO [c.c.a.m.AgentManagerImpl] (AgentTaskPool-3:ctx-d46f2f55) (logid:22aa214e) Agent is determined to be up and running
2017-06-14 16:13:09,690 DEBUG [c.c.h.Status] (AgentTaskPool-3:ctx-d46f2f55) (logid:22aa214e) Transition:[Resource state = Enabled, Agent event = Ping, Host id = 3, name = localhost.localdomain]
2017-06-14 16:13:09,925 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-7dd268d5) (logid:422a2299) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:13:10,930 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-77b629ec) (logid:224e2438) HostOutOfBandManagementStatsCollector is running...
2017-06-14 16:13:11,937 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-56adfc46) (logid:c33ba65b) HostOutOfBandManagementStatsCollector is running...
pavankumar@HSL007960:~/ACP_HOME/cloudstack$
pavankumar@HSL007960:~/ACP_HOME/cloudstack$
pavankumar@HSL007960:~/ACP_HOME/cloudstack$ tail -f vmops.log >> vmsnap.log
^C
pavankumar@HSL007960:~/ACP_HOME/cloudstack$ vi vmops.log
pavankumar@HSL007960:~/ACP_HOME/cloudstack$ vi vmsnap.log

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:506)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.NullPointerException
at com.cloud.vm.snapshot.VMSnapshotManagerImpl.orchestrateCreateVMSnapshot(VMSnapshotManagerImpl.java:1195)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
... 28 more
2017-06-14 16:18:51,043 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-5:ctx-0343c9fd job-84) (logid:acb0fe06) Complete async job-84, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/

{"uuidList":[],"errorcode":530,"errortext":"Unexpected exception"}

2017-06-14 16:18:51,044 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-5:ctx-0343c9fd job-84) (logid:acb0fe06) Publish async job-84 complete on message bus
2017-06-14 16:18:51,045 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-5:ctx-0343c9fd job-84) (logid:acb0fe06) Wake up jobs related to job-84
2017-06-14 16:18:51,045 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-5:ctx-0343c9fd job-84) (logid:acb0fe06) Update db status for job-84
2017-06-14 16:18:51,046 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-5:ctx-0343c9fd job-84) (logid:acb0fe06) Wake up jobs joined with job-84 and disjoin all subjobs created from job- 84
2017-06-14 16:18:51,048 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-5:ctx-0343c9fd job-84) (logid:acb0fe06) Done executing org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd for job-84
2017-06-14 16:18:51,048 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-5:ctx-0343c9fd job-84) (logid:acb0fe06) Remove job-84 from job monitoring
2017-06-14 16:18:51,437 DEBUG [c.c.a.ApiServlet] (qtp752030228-26:ctx-5144fab9) (logid:0ab596f6) ===START=== 127.0.0.1 – GET command=queryAsyncJobResult&jobId=acb0fe06-516a-4176-9b9b-8695552ef4e8&response=json&_=1497437331430
2017-06-14 16:18:51,453 DEBUG [c.c.a.ApiServlet] (qtp752030228-26:ctx-5144fab9 ctx-6bfbb028) (logid:0ab596f6) ===END=== 127.0.0.1 – GET command=queryAsyncJobResult&jobId=acb0fe06-516a-4176-9b9b-8695552ef4e8&response=json&_=1497437331430
2017-06-14 16:18:51,532 DEBUG

KVM libvirt Log

2017-06-14 17:50:51.909+0000: 25824: warning : qemuDomainObjTaint:1459 : Domain id=10 name='r-6-VM' uuid=0b38c8d0-381e-491b-870e-3ac582731cde is tainted: high-privileges
2017-06-14 17:51:18.103+0000: 25821: warning : qemuAgentNotifyEvent:1279 : Received unexpected event 3
2017-06-14 17:51:59.696+0000: 25822: warning : qemuDomainObjTaint:1459 : Domain id=11 name='i-2-5-VM' uuid=59f8d6f5-afa0-4965-8966-4aa45726933c is tainted: high-privileges
2017-06-14 17:52:51.000+0000: 25826: error : qemuAgentSend:889 : Guest agent is not responding: Guest agent not available for now
2017-06-14 17:55:25.592+0000: 25821: error : qemuMonitorIO:615 : internal error End of file from monitor
2017-06-14 17:58:46.249+0000: 25822: warning : qemuDomainObjTaint:1459 : Domain id=12 name='r-6-VM' uuid=0b38c8d0-381e-491b-870e-3ac582731cde is tainted: high-privileges
2017-06-14 17:59:19.581+0000: 25824: warning : qemuDomainObjTaint:1459 : Domain id=13 name='i-2-5-VM' uuid=59f8d6f5-afa0-4965-8966-4aa45726933c is tainted: high-privileges
2017-06-14 18:00:17.001+0000: 25825: error : qemuAgentSend:889 : Guest agent is not responding: Guest agent not available for now
2017-06-14 18:00:43.265+0000: 25821: error : qemuMonitorIO:615 : internal error End of file from monitor
2017-06-14 18:01:15.531+0000: 25821: error : qemuMonitorIO:615 : internal error End of file from monitor

Attachments

Activity

People

Assignee:: Unassigned

Reporter:: Pavan Kumar Aravapalli

Votes:: 0 Vote for this issue

Watchers:: 1 Start watching this issue

Dates

Created:: 14/Jun/17 12:04

Updated:: 14/Jun/17 12:04