S3 Error: 2016-02-18 10:12:30,707 DEBUG [c.c.a.ApiServlet] (catalina-exec-22:ctx-692943aa) (logid:b587a934) ===START=== 10.30.10.41 -- GET command=addImageStore&response=json&name=Images&provider=S3&details%5B2%5D.key=bucket&details%5B2%5D.value=cl-images&details%5B3%5D.key=usehttps&details%5B3%5D.value=false&details%5B4%5D.key=endpoint&details%5B4%5D.value= s3.cloud.bst.su&_=1455779550451 2016-02-18 10:12:30,741 INFO [o.a.c.s.d.l.S3ImageStoreLifeCycleImpl] (catalina-exec-22:ctx-692943aa ctx-dcc03fdb) (logid:b587a934) Trying to add a S3 store with endpoint: s3.cloud.bst.su 2016-02-18 10:12:30,913 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (catalina-exec-22:ctx-692943aa ctx-dcc03fdb) (logid:b587a934) template 3 is already in store:91, type:Image 2016-02-18 10:12:30,931 DEBUG [o.a.c.s.i.BaseImageStoreDriverImpl] (catalina-exec-22:ctx-692943aa ctx-dcc03fdb) (logid:b587a934) Downloading template to data store 91 2016-02-18 10:12:31,002 DEBUG [o.a.c.s.i.BaseImageStoreDriverImpl] (catalina-exec-22:ctx-692943aa ctx-dcc03fdb) (logid:b587a934) Performing image store createTemplate async callback 2016-02-18 10:12:31,317 INFO [o.a.c.s.i.d.TemplateDataStoreDaoImpl] (catalina-exec-22:ctx-692943aa ctx-dcc03fdb) (logid:b587a934) Duplicate 0 template cache store records to region store 2016-02-18 10:12:31,322 INFO [o.a.c.s.i.d.SnapshotDataStoreDaoImpl] (catalina-exec-22:ctx-692943aa ctx-dcc03fdb) (logid:b587a934) Duplicate 0 snapshot cache store records to region store 2016-02-18 10:12:31,339 INFO [o.a.c.s.i.d.VolumeDataStoreDaoImpl] (catalina-exec-22:ctx-692943aa ctx-dcc03fdb) (logid:b587a934) Duplicate 0 volume cache store records to region store 2016-02-18 10:12:31,351 DEBUG [c.c.a.ApiServlet] (catalina-exec-22:ctx-692943aa ctx-dcc03fdb) (logid:b587a934) ===END=== 10.30.10.41 -- GET command=addImageStore&response=json&name=Images&provider=S3&details%5B2%5D.key=bucket&details%5B2%5D.value=cl-images&details%5B3%5D.key=usehttps&details%5B3%5D.value=false&details%5B4%5D.key=endpoint&details%5B4%5D.value=s3.cloud.bst-su&_=1455779550451 2016-02-18 10:12:38,882 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-b7b15564) (logid:a3fcba8f) Begin cleanup expired async-jobs 2016-02-18 10:12:38,909 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-b7b15564) (logid:a3fcba8f) End cleanup expired async-jobs 2016-02-18 10:12:41,020 DEBUG [c.c.u.n.HTTPUtils] (pool-10-thread-1:ctx-38ab02de) (logid:a6a55e58) Initializing new HttpMethodRetryHandler with retry count 5 2016-02-18 10:12:41,030 INFO [c.c.s.t.S3TemplateDownloader] (pool-9-thread-1:ctx-d4d0b7c3) (logid:c652699b) Starting download from http://10.30.10.3/mrepo/ISO/systemvm64template-4.6.0-kvm.qcow2.bz2 to S3 bucket cl-images and size 319401369 bytes 2016-02-18 10:12:41,030 DEBUG [c.c.u.s.S.S3Utils] (pool-9-thread-1:ctx-d4d0b7c3) (logid:c652699b) Sending stream as S3 object template/tmpl/1/3/routing-3/systemvm64template-4.6.0-kvm.qcow2.bz2 in bucket cl-images using PutObjectRequest 2016-02-18 10:12:41,030 DEBUG [c.c.u.s.S.S3Utils] (pool-9-thread-1:ctx-d4d0b7c3) (logid:c652699b) Creating S3 client with configuration: [protocol: http, signer: null, connectionTimeOut: 50000, maxErrorRetry: -1, socketTimeout: 50000, useTCPKeepAlive: null, connectionTtl: null] 2016-02-18 10:12:41,038 DEBUG [c.c.u.s.S.S3Utils] (pool-9-thread-1:ctx-d4d0b7c3) (logid:c652699b) Setting the end point for S3 client with access key IONTKFQF1TUIRZ1BLGAO to s3.cloud.bst.su. 2016-02-18 10:12:44,021 DEBUG [o.a.c.s.i.BaseImageStoreDriverImpl] (pool-10-thread-1:ctx-38ab02de) (logid:a6a55e58) Performing image store createTemplate async callback 2016-02-18 10:12:44,076 WARN [o.a.c.alerts] (pool-10-thread-1:ctx-38ab02de) (logid:a6a55e58) alertType:: 28 // dataCenterId:: 4 // podId:: null // clusterId:: null // message:: Failed to register template: dc7e53a0-4615-43a1-8bf0-2ce51b246a33 with error: 2016-02-18 10:12:44,091 ERROR [o.a.c.s.i.BaseImageStoreDriverImpl] (pool-10-thread-1:ctx-38ab02de) (logid:a6a55e58) Failed to register template: dc7e53a0-4615-43a1-8bf0-2ce51b246a33 with error: 2016-02-18 10:12:44,815 DEBUG [c.c.a.m.ClusteredAgentAttache] (AgentManager-Handler-13:null) (logid:) Seq 121-6638305850744119545: Routing from 121491073759284 2016-02-18 10:12:44,818 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentManager-Handler-2:null) (logid:) Seq 121-6638305850744119545: MgmtId 121491073759284: Resp: Routing to peer 2016-02-18 10:12:48,883 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-e47445ff) (logid:1c1cc9e3) Begin cleanup expired async-jobs 2016-02-18 10:12:48,913 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-e47445ff) (logid:1c1cc9e3) End cleanup expired async-jobs 2016-02-18 10:12:48,929 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-7f832e66) (logid:1df7dab6) Found 0 routers to update status. 2016-02-18 10:12:48,935 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-7f832e66) (logid:1df7dab6) Found 0 VPC networks to update Redundant State. 2016-02-18 10:12:48,941 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-7f832e66) (logid:1df7dab6) Found 0 networks to update RvR status. 2016-02-18 10:12:49,062 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-94526f96) (logid:c7046ad8) Found 0 routers to update status. 2016-02-18 10:12:49,068 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-94526f96) (logid:c7046ad8) Found 0 VPC networks to update Redundant State. 2016-02-18 10:12:49,074 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-94526f96) (logid:c7046ad8) Found 0 networks to update RvR status.
2016-02-17 23:20 GMT+03:00 Simon Weller <[email protected]>: > Yuriy, > > This looks like a bug. There was a similar reported issue quite a while > back on S3 (but with KVM). Please open an issue on it. > > Have you tried using the S3 secondary storage option instead? It's > probably more widely deployed than swift on CloudStack. > There are a bunch of other bugs that are currently being addressed in the > swift implementation related to templates. > > - Si > > ________________________________________ > From: Yuriy Karpel <[email protected]> > Sent: Wednesday, February 17, 2016 7:16 AM > To: [email protected] > Subject: kvm, snapshot create error > > My test stend: CentOS 7, Cloudstack 4.7, qemu-kvm 10:1.5.3-105.el7_2.3 > Primary storage: Ceph RBD, Secondary storage: RadosGW Swift + NFS staging > store > > When you create a disk snapshot I get an error: > > 2016-02-17 14:41:57,693 INFO [o.a.c.f.j.i.AsyncJobMonitor] > (API-Job-Executor-82:ctx-3b960545 job-2524) (logid:e60ab5a4) Add job-2524 > into job monitoring > 2016-02-17 14:41:57,710 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (catalina-exec-20:ctx-35c895a8 ctx-a26caf1e) (logid:b023f26d) submit async > job-2524, details: AsyncJobVO {id:2524, userId: 10, accountId: 7, > instanceType: Snapshot, instanceId: 16, cmd: > org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd, cmdInfo: > > {"quiescevm":"false","httpmethod":"GET","ctxAccountId":"7","uuid":"b487a5b5-b990-4f75-91d4-4acb1b9aa8dd","cmdEventType":"SNAPSHOT.CREATE","response":"json","ctxUserId":"10","volumeId":"c935a963-2990-4bc4-86fd-facf5e711e5b","name":"test","ctxStartEventId":"6871","id":"16","ctxDetails":"{\"interface > > com.cloud.storage.Snapshot\":\"b487a5b5-b990-4f75-91d4-4acb1b9aa8dd\",\"interface > > com.cloud.storage.Volume\":\"c935a963-2990-4bc4-86fd-facf5e711e5b\"}","_":"1455709317187"}, > cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, > result: null, initMsid: 90212275930085, completeMsid: null, lastUpdated: > null, lastPolled: null, created: null} > 2016-02-17 14:41:57,711 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (API-Job-Executor-82:ctx-3b960545 job-2524) (logid:0a96ee1e) Executing > AsyncJobVO {id:2524, userId: 10, accountId: 7, instanceType: Snapshot, > instanceId: 16, cmd: > org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd, cmdInfo: > > {"quiescevm":"false","httpmethod":"GET","ctxAccountId":"7","uuid":"b487a5b5-b990-4f75-91d4-4acb1b9aa8dd","cmdEventType":"SNAPSHOT.CREATE","response":"json","ctxUserId":"10","volumeId":"c935a963-2990-4bc4-86fd-facf5e711e5b","name":"test","ctxStartEventId":"6871","id":"16","ctxDetails":"{\"interface > > com.cloud.storage.Snapshot\":\"b487a5b5-b990-4f75-91d4-4acb1b9aa8dd\",\"interface > > com.cloud.storage.Volume\":\"c935a963-2990-4bc4-86fd-facf5e711e5b\"}","_":"1455709317187"}, > cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, > result: null, initMsid: 90212275930085, completeMsid: null, lastUpdated: > null, lastPolled: null, created: null} > 2016-02-17 14:41:57,714 DEBUG [c.c.a.ApiServlet] > (catalina-exec-20:ctx-35c895a8 ctx-a26caf1e) (logid:b023f26d) ===END=== > 10.30.10.41 -- GET > > > command=createSnapshot&response=json&volumeId=c935a963-2990-4bc4-86fd-facf5e711e5b&quiescevm=false&name=test&_=1455709317187 > 2016-02-17 14:41:57,751 DEBUG [c.c.u.AccountManagerImpl] > (API-Job-Executor-82:ctx-3b960545 job-2524 ctx-acd8bf64) (logid:0a96ee1e) > Access to Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:41:57,874 INFO [o.a.c.a.c.u.s.CreateSnapshotCmd] > (API-Job-Executor-82:ctx-3b960545 job-2524 ctx-acd8bf64) (logid:0a96ee1e) > VOLSS: createSnapshotCmd starts:1455709317874 > 2016-02-17 14:41:57,956 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (API-Job-Executor-82:ctx-3b960545 job-2524 ctx-acd8bf64) (logid:0a96ee1e) > Sync job-2527 execution on object VmWorkJobQueue.99 > 2016-02-17 14:41:58,866 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (AsyncJobMgr-Heartbeat-1:ctx-c113b5a4) (logid:d6f846a6) Execute sync-queue > item: SyncQueueItemVO {id:1246, queueId: 1240, contentType: AsyncJob, > contentId: 2527, lastProcessMsid: 90212275930085, lastprocessNumber: 2, > lastProcessTime: Wed Feb 17 14:41:58 MSK 2016, created: Wed Feb 17 14:41:57 > MSK 2016} > 2016-02-17 14:41:58,871 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (AsyncJobMgr-Heartbeat-1:ctx-c113b5a4) (logid:d6f846a6) Schedule queued > job-2527 > 2016-02-17 14:41:58,888 INFO [o.a.c.f.j.i.AsyncJobMonitor] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527) (logid:afae7d3f) Add > job-2527 into job monitoring > 2016-02-17 14:41:58,902 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] > (AsyncJobMgr-Heartbeat-1:ctx-feb21635) (logid:27fa58a0) Begin cleanup > expired async-jobs > 2016-02-17 14:41:58,906 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527) (logid:0a96ee1e) > Executing AsyncJobVO {id:2527, userId: 10, accountId: 7, instanceType: > null, instanceId: null, cmd: com.cloud.vm.VmWorkTakeVolumeSnapshot, > cmdInfo: > > rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrVGFrZVZvbHVtZVNuYXBzaG90BL5gG4Li1c8CAARaAAlxdWllc2NlVm1MAAhwb2xpY3lJZHQAEExqYXZhL2xhbmcvTG9uZztMAApzbmFwc2hvdElkcQB-AAFMAAh2b2x1bWVJZHEAfgABeHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAcAAAAAAAAACgAAAAAAAABjdAAUVm9sdW1lQXBpU2VydmljZUltcGwAc3IADmphdmEubGFuZy5Mb25nO4vkkMyPI98CAAFKAAV2YWx1ZXhyABBqYXZhLmxhbmcuTnVtYmVyhqyVHQuU4IsCAAB4cAAAAAAAAAAAc3EAfgAGAAAAAAAAABBzcQB-AAYAAAAAAAABYw, > cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, > result: null, initMsid: 90212275930085, completeMsid: null, lastUpdated: > null, lastPolled: null, created: Wed Feb 17 14:41:57 MSK 2016} > 2016-02-17 14:41:58,906 DEBUG [c.c.v.VmWorkJobDispatcher] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527) (logid:0a96ee1e) Run > VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot for VM 99, job origin: > 2524 > 2016-02-17 14:41:58,912 DEBUG [c.c.v.VmWorkJobHandlerProxy] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) Execute VM work job: > > com.cloud.vm.VmWorkTakeVolumeSnapshot{"volumeId":355,"policyId":0,"snapshotId":16,"quiesceVm":false,"userId":10,"accountId":7,"vmId":99,"handlerName":"VolumeApiServiceImpl"} > 2016-02-17 14:41:58,930 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] > (AsyncJobMgr-Heartbeat-1:ctx-feb21635) (logid:27fa58a0) End cleanup expired > async-jobs > 2016-02-17 14:41:59,183 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) getCommandHostDelegation: class > org.apache.cloudstack.storage.command.CreateObjectCommand > 2016-02-17 14:41:59,183 DEBUG [c.c.h.XenServerGuru] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) getCommandHostDelegation: class > org.apache.cloudstack.storage.command.CreateObjectCommand > 2016-02-17 14:41:59,200 DEBUG [c.c.a.t.Request] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) Seq 121-2842334314824210223: Sending { Cmd , MgmtId: > 90212275930085, via: 121(srv-kvm01.cloud.bst.su), Ver: v1, Flags: 100011, > > [{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"c935a963-2990-4bc4-86fd-facf5e711e5b","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"f5efdbfb-8fe7-3dfd-bc07-5088222d8b84","id":52,"poolType":"RBD","host":" > ceph-mon.cloud.bst.su","path":"rbd-cl","port":6789,"url":"RBD:// > > ceph-mon.cloud.bst.su/rbd-cl/?ROLE=Primary&STOREUUID=f5efdbfb-8fe7-3dfd-bc07-5088222d8b84 > > "}},"name":"ROOT-99","size":472312242,"path":"c935a963-2990-4bc4-86fd-facf5e711e5b","volumeId":355,"vmName":"i-7-99-VM","accountId":7,"format":"RAW","provisioningType":"THIN","id":355,"deviceId":0,"hypervisorType":"KVM"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"f5efdbfb-8fe7-3dfd-bc07-5088222d8b84","id":52,"poolType":"RBD","host":" > ceph-mon.cloud.bst.su","path":"rbd-cl","port":6789,"url":"RBD:// > > ceph-mon.cloud.bst.su/rbd-cl/?ROLE=Primary&STOREUUID=f5efdbfb-8fe7-3dfd-bc07-5088222d8b84 > "}},"vmName":"i-7-99-VM","name":"test","hypervisorType":"KVM","id":16,"quiescevm":false,"physicalSize":0}},"wait":0}}] > } > 2016-02-17 14:41:59,597 DEBUG [c.c.a.t.Request] > (AgentManager-Handler-6:null) (logid:) Seq 121-2842334314824210223: > Processing: { Ans: , MgmtId: 90212275930085, via: 121, Ver: v1, Flags: 10, > > [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"rbd-cl/c935a963-2990-4bc4-86fd-facf5e711e5b/a26adf8e-6665-45bf-b6a8-37d164b825c6","id":0,"quiescevm":false,"physicalSize":0}},"result":true,"wait":0}}] > } > 2016-02-17 14:41:59,598 DEBUG [c.c.a.t.Request] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) Seq 121-2842334314824210223: Received: { Ans: , MgmtId: > 90212275930085, via: 121(srv-kvm01.cloud.bst.su), Ver: v1, Flags: 10, { > CreateObjectAnswer } } > 2016-02-17 14:41:59,789 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) copyAsync inspecting src type SNAPSHOT copyAsync > inspecting dest type SNAPSHOT > 2016-02-17 14:41:59,884 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) needCacheStorage true, dest at snapshots/7/355 dest role > > Imagerbd-cl/c935a963-2990-4bc4-86fd-facf5e711e5b/a26adf8e-6665-45bf-b6a8-37d164b825c6 > src role Primary > 2016-02-17 14:42:00,095 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) getCommandHostDelegation: class > org.apache.cloudstack.storage.command.CopyCommand > 2016-02-17 14:42:00,095 DEBUG [c.c.h.XenServerGuru] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) getCommandHostDelegation: class > org.apache.cloudstack.storage.command.CopyCommand > 2016-02-17 14:42:00,100 DEBUG [c.c.a.t.Request] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) Seq 121-2842334314824210224: Sending { Cmd , MgmtId: > 90212275930085, via: 121(srv-kvm01.cloud.bst.su), Ver: v1, Flags: 100111, > > [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"rbd-cl/c935a963-2990-4bc4-86fd-facf5e711e5b/a26adf8e-6665-45bf-b6a8-37d164b825c6","volume":{"uuid":"c935a963-2990-4bc4-86fd-facf5e711e5b","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"f5efdbfb-8fe7-3dfd-bc07-5088222d8b84","id":52,"poolType":"RBD","host":" > ceph-mon.cloud.bst.su","path":"rbd-cl","port":6789,"url":"RBD:// > > ceph-mon.cloud.bst.su/rbd-cl/?ROLE=Primary&STOREUUID=f5efdbfb-8fe7-3dfd-bc07-5088222d8b84 > > "}},"name":"ROOT-99","size":472312242,"path":"c935a963-2990-4bc4-86fd-facf5e711e5b","volumeId":355,"vmName":"i-7-99-VM","accountId":7,"format":"RAW","provisioningType":"THIN","id":355,"deviceId":0,"hypervisorType":"KVM"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"f5efdbfb-8fe7-3dfd-bc07-5088222d8b84","id":52,"poolType":"RBD","host":" > ceph-mon.cloud.bst.su","path":"rbd-cl","port":6789,"url":"RBD:// > > ceph-mon.cloud.bst.su/rbd-cl/?ROLE=Primary&STOREUUID=f5efdbfb-8fe7-3dfd-bc07-5088222d8b84 > > "}},"vmName":"i-7-99-VM","name":"test","hypervisorType":"KVM","id":16,"quiescevm":false,"physicalSize":0}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/7/355","volume":{"uuid":"c935a963-2990-4bc4-86fd-facf5e711e5b","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"f5efdbfb-8fe7-3dfd-bc07-5088222d8b84","id":52,"poolType":"RBD","host":" > ceph-mon.cloud.bst.su","path":"rbd-cl","port":6789,"url":"RBD:// > > ceph-mon.cloud.bst.su/rbd-cl/?ROLE=Primary&STOREUUID=f5efdbfb-8fe7-3dfd-bc07-5088222d8b84 > > "}},"name":"ROOT-99","size":472312242,"path":"c935a963-2990-4bc4-86fd-facf5e711e5b","volumeId":355,"vmName":"i-7-99-VM","accountId":7,"format":"RAW","provisioningType":"THIN","id":355,"deviceId":0,"hypervisorType":"KVM"},"dataStore":{"com.cloud.agent.api.to.SwiftTO":{"id":73,"url":" > http://ceph-rgw.cloud.bst.su:8080/auth/v1.0/ > > ","account":"cloudstack","userName":"swift","key":"VPGpdk5ppNgCepV58NNa1E1x4j5RDP9xyIxB7XMB"}},"vmName":"i-7-99-VM","name":"test","hypervisorType":"KVM","id":16,"quiescevm":false,"physicalSize":0}},"cacheTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/7/355","volume":{"uuid":"c935a963-2990-4bc4-86fd-facf5e711e5b","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"f5efdbfb-8fe7-3dfd-bc07-5088222d8b84","id":52,"poolType":"RBD","host":" > ceph-mon.cloud.bst.su","path":"rbd-cl","port":6789,"url":"RBD:// > > ceph-mon.cloud.bst.su/rbd-cl/?ROLE=Primary&STOREUUID=f5efdbfb-8fe7-3dfd-bc07-5088222d8b84 > > "}},"name":"ROOT-99","size":472312242,"path":"c935a963-2990-4bc4-86fd-facf5e711e5b","volumeId":355,"vmName":"i-7-99-VM","accountId":7,"format":"RAW","provisioningType":"THIN","id":355,"deviceId":0,"hypervisorType":"KVM"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs:// > srv-nfs.cloud.bst.su/nfs > ","_role":"ImageCache"}},"vmName":"i-7-99-VM","name":"test","hypervisorType":"KVM","id":16,"quiescevm":false,"physicalSize":0}},"executeInSequence":true,"options":{"fullSnapshot":"true"},"options2":{},"wait":21600}}] > } > 2016-02-17 14:42:00,743 DEBUG [c.c.a.ApiServlet] > (catalina-exec-24:ctx-e717f61f) (logid:01fce183) ===START=== 10.30.10.41 > -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709320685 > 2016-02-17 14:42:00,803 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-24:ctx-e717f61f ctx-f1954731) (logid:01fce183) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:00,843 DEBUG [c.c.a.ApiServlet] > (catalina-exec-24:ctx-e717f61f ctx-f1954731) (logid:01fce183) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709320685 > 2016-02-17 14:42:03,752 DEBUG [c.c.a.ApiServlet] > (catalina-exec-10:ctx-2218d665) (logid:7bf93934) ===START=== 10.30.10.41 > -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709323687 > 2016-02-17 14:42:03,813 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-10:ctx-2218d665 ctx-21c82669) (logid:7bf93934) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:03,852 DEBUG [c.c.a.ApiServlet] > (catalina-exec-10:ctx-2218d665 ctx-21c82669) (logid:7bf93934) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709323687 > 2016-02-17 14:42:04,332 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-8:null) (logid:) SeqA 127-27657: Processing Seq > 127-27657: { Cmd , MgmtId: -1, via: 127, Ver: v1, Flags: 11, > > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":79,"_loadInfo":"{\n > \"connections\": [\n {\n \"id\": 28,\n \"clientInfo\": > \"\",\n \"host\": \"10.30.16.10\",\n \"port\": 5904,\n > \"tag\": \"4535bf74-d255-4634-b873-d4185b3e6433\",\n \"createTime\": > 1455702716959,\n \"lastUsedTime\": 1455709322174\n }\n > ]\n}","wait":0}}] } > 2016-02-17 14:42:04,344 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-8:null) (logid:) SeqA 127-27657: Sending Seq > 127-27657: { Ans: , MgmtId: 90212275930085, via: 127, Ver: v1, Flags: > 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2016-02-17 14:42:04,766 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] > (secstorage-1:ctx-f5f85727) (logid:8a939115) Zone 4 is ready to launch > secondary storage VM > 2016-02-17 14:42:04,837 DEBUG [c.c.c.ConsoleProxyManagerImpl] > (consoleproxy-1:ctx-2e943c4f) (logid:c78e8ca9) Zone 4 is ready to launch > console proxy > 2016-02-17 14:42:06,754 DEBUG [c.c.a.ApiServlet] > (catalina-exec-23:ctx-456ba9fc) (logid:93d89c41) ===START=== 10.30.10.41 > -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709326685 > 2016-02-17 14:42:06,819 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-23:ctx-456ba9fc ctx-8d92ea82) (logid:93d89c41) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:06,862 DEBUG [c.c.a.ApiServlet] > (catalina-exec-23:ctx-456ba9fc ctx-8d92ea82) (logid:93d89c41) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709326685 > 2016-02-17 14:42:08,874 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] > (AsyncJobMgr-Heartbeat-1:ctx-6bbebfec) (logid:81494643) Begin cleanup > expired async-jobs > 2016-02-17 14:42:08,902 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] > (AsyncJobMgr-Heartbeat-1:ctx-6bbebfec) (logid:81494643) End cleanup expired > async-jobs > 2016-02-17 14:42:09,756 DEBUG [c.c.a.ApiServlet] > (catalina-exec-19:ctx-516a5879) (logid:843735ea) ===START=== 10.30.10.41 > -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709329686 > 2016-02-17 14:42:09,834 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-19:ctx-516a5879 ctx-034669ac) (logid:843735ea) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:09,895 DEBUG [c.c.a.ApiServlet] > (catalina-exec-19:ctx-516a5879 ctx-034669ac) (logid:843735ea) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709329686 > 2016-02-17 14:42:11,628 DEBUG [c.c.a.m.ClusteredAgentAttache] > (AgentManager-Handler-15:null) (logid:) Seq 121-6638305850744116094: > Routing from 121491073759284 > 2016-02-17 14:42:11,631 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] > (AgentManager-Handler-11:null) (logid:) Seq 121-6638305850744116094: MgmtId > 121491073759284: Resp: Routing to peer > 2016-02-17 14:42:12,753 DEBUG [c.c.a.ApiServlet] > (catalina-exec-11:ctx-f52ee770) (logid:902a3aff) ===START=== 10.30.10.41 > -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709332686 > 2016-02-17 14:42:12,817 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-11:ctx-f52ee770 ctx-c987af1f) (logid:902a3aff) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:12,858 DEBUG [c.c.a.ApiServlet] > (catalina-exec-11:ctx-f52ee770 ctx-c987af1f) (logid:902a3aff) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709332686 > 2016-02-17 14:42:14,333 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-5:null) (logid:) SeqA 127-27658: Processing Seq > 127-27658: { Cmd , MgmtId: -1, via: 127, Ver: v1, Flags: 11, > > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":79,"_loadInfo":"{\n > \"connections\": [\n {\n \"id\": 28,\n \"clientInfo\": > \"\",\n \"host\": \"10.30.16.10\",\n \"port\": 5904,\n > \"tag\": \"4535bf74-d255-4634-b873-d4185b3e6433\",\n \"createTime\": > 1455702716959,\n \"lastUsedTime\": 1455709331340\n }\n > ]\n}","wait":0}}] } > 2016-02-17 14:42:14,344 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-5:null) (logid:) SeqA 127-27658: Sending Seq > 127-27658: { Ans: , MgmtId: 90212275930085, via: 127, Ver: v1, Flags: > 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2016-02-17 14:42:15,754 DEBUG [c.c.a.ApiServlet] > (catalina-exec-25:ctx-9319ad12) (logid:cea4e95d) ===START=== 10.30.10.41 > -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709335686 > 2016-02-17 14:42:15,817 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-25:ctx-9319ad12 ctx-64ce6d52) (logid:cea4e95d) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:15,858 DEBUG [c.c.a.ApiServlet] > (catalina-exec-25:ctx-9319ad12 ctx-64ce6d52) (logid:cea4e95d) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709335686 > 2016-02-17 14:42:18,753 DEBUG [c.c.a.ApiServlet] > (catalina-exec-7:ctx-adcc4b0d) (logid:878a5f9c) ===START=== 10.30.10.41 -- > GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709338685 > 2016-02-17 14:42:18,816 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-7:ctx-adcc4b0d ctx-4375a027) (logid:878a5f9c) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:18,862 DEBUG [c.c.a.ApiServlet] > (catalina-exec-7:ctx-adcc4b0d ctx-4375a027) (logid:878a5f9c) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709338685 > 2016-02-17 14:42:18,877 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] > (AsyncJobMgr-Heartbeat-1:ctx-8181dd1a) (logid:f826bc0e) Begin cleanup > expired async-jobs > 2016-02-17 14:42:18,904 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] > (AsyncJobMgr-Heartbeat-1:ctx-8181dd1a) (logid:f826bc0e) End cleanup expired > async-jobs > 2016-02-17 14:42:18,938 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] > (RouterStatusMonitor-1:ctx-58b72550) (logid:d64b4182) Found 1 routers to > update status. > 2016-02-17 14:42:18,944 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] > (RouterStatusMonitor-1:ctx-58b72550) (logid:d64b4182) Found 0 VPC networks > to update Redundant State. > 2016-02-17 14:42:18,950 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] > (RouterStatusMonitor-1:ctx-58b72550) (logid:d64b4182) Found 0 networks to > update RvR status. > 2016-02-17 14:42:19,064 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] > (RouterStatusMonitor-1:ctx-f9dd85a6) (logid:ba2f902a) Found 1 routers to > update status. > 2016-02-17 14:42:19,070 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] > (RouterStatusMonitor-1:ctx-f9dd85a6) (logid:ba2f902a) Found 0 VPC networks > to update Redundant State. > 2016-02-17 14:42:19,076 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] > (RouterStatusMonitor-1:ctx-f9dd85a6) (logid:ba2f902a) Found 0 networks to > update RvR status. > 2016-02-17 14:42:19,983 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-13:null) (logid:) Ping from 127(v-79-VM) > 2016-02-17 14:42:20,207 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-14:null) (logid:) Ping from 130(s-78-VM) > 2016-02-17 14:42:21,754 DEBUG [c.c.a.ApiServlet] > (catalina-exec-20:ctx-4c92529b) (logid:aea56580) ===START=== 10.30.10.41 > -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709341686 > 2016-02-17 14:42:21,816 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-20:ctx-4c92529b ctx-8a691200) (logid:aea56580) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:21,856 DEBUG [c.c.a.ApiServlet] > (catalina-exec-20:ctx-4c92529b ctx-8a691200) (logid:aea56580) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709341686 > 2016-02-17 14:42:22,762 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-1:null) (logid:) Ping from 121( > srv-kvm01.cloud.bst.su) > 2016-02-17 14:42:22,763 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) Process host VM state report from > ping process. host: 121 > 2016-02-17 14:42:22,809 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) Process VM state report. host: 121, > number of records in report: 6 > 2016-02-17 14:42:22,809 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) VM state report. host: 121, vm id: > 97, power state: PowerOn > 2016-02-17 14:42:22,819 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) VM power state does not change, skip > DB writing. vm id: 97 > 2016-02-17 14:42:22,819 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) VM state report. host: 121, vm id: > 98, power state: PowerOn > 2016-02-17 14:42:22,828 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) VM power state does not change, skip > DB writing. vm id: 98 > 2016-02-17 14:42:22,829 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) VM state report. host: 121, vm id: > 99, power state: PowerOn > 2016-02-17 14:42:22,841 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) VM state report is updated. host: > 121, vm id: 99, power state: PowerOn > 2016-02-17 14:42:22,850 INFO [c.c.v.VirtualMachineManagerImpl] > (AgentManager-Handler-1:null) (logid:) There is pending job or HA tasks > working on the VM. vm id: 99, postpone power-change report by resetting > power-change counters > 2016-02-17 14:42:22,865 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) VM state report. host: 121, vm id: > 78, power state: PowerOn > 2016-02-17 14:42:22,875 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) VM power state does not change, skip > DB writing. vm id: 78 > 2016-02-17 14:42:22,875 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) VM state report. host: 121, vm id: > 79, power state: PowerOn > 2016-02-17 14:42:22,884 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) VM power state does not change, skip > DB writing. vm id: 79 > 2016-02-17 14:42:22,884 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) VM state report. host: 121, vm id: > 95, power state: PowerOn > 2016-02-17 14:42:22,893 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) VM power state does not change, skip > DB writing. vm id: 95 > 2016-02-17 14:42:22,904 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] > (AgentManager-Handler-1:null) (logid:) Done with process of VM state > report. host: 121 > 2016-02-17 14:42:24,334 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-10:null) (logid:) SeqA 127-27660: Processing Seq > 127-27660: { Cmd , MgmtId: -1, via: 127, Ver: v1, Flags: 11, > > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":79,"_loadInfo":"{\n > \"connections\": [\n {\n \"id\": 28,\n \"clientInfo\": > \"\",\n \"host\": \"10.30.16.10\",\n \"port\": 5904,\n > \"tag\": \"4535bf74-d255-4634-b873-d4185b3e6433\",\n \"createTime\": > 1455702716959,\n \"lastUsedTime\": 1455709343561\n }\n > ]\n}","wait":0}}] } > 2016-02-17 14:42:24,344 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-10:null) (logid:) SeqA 127-27660: Sending Seq > 127-27660: { Ans: , MgmtId: 90212275930085, via: 127, Ver: v1, Flags: > 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2016-02-17 14:42:24,407 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager > Timer:ctx-c5881dc5) (logid:1517cc52) Resetting hosts suitable for reconnect > 2016-02-17 14:42:24,416 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager > Timer:ctx-c5881dc5) (logid:1517cc52) Completed resetting hosts suitable for > reconnect > 2016-02-17 14:42:24,416 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager > Timer:ctx-c5881dc5) (logid:1517cc52) Acquiring hosts for clusters already > owned by this management server > 2016-02-17 14:42:24,418 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager > Timer:ctx-c5881dc5) (logid:1517cc52) Completed acquiring hosts for clusters > already owned by this management server > 2016-02-17 14:42:24,418 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager > Timer:ctx-c5881dc5) (logid:1517cc52) Acquiring hosts for clusters not owned > by any management server > 2016-02-17 14:42:24,420 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager > Timer:ctx-c5881dc5) (logid:1517cc52) Completed acquiring hosts for clusters > not owned by any management server > 2016-02-17 14:42:24,757 DEBUG [c.c.a.ApiServlet] > (catalina-exec-1:ctx-a2d8e6d1) (logid:fdbcedc1) ===START=== 10.30.10.41 -- > GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709344683 > 2016-02-17 14:42:24,828 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-1:ctx-a2d8e6d1 ctx-5135eef0) (logid:fdbcedc1) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:24,874 DEBUG [c.c.a.ApiServlet] > (catalina-exec-1:ctx-a2d8e6d1 ctx-5135eef0) (logid:fdbcedc1) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709344683 > 2016-02-17 14:42:25,250 DEBUG [c.c.s.StatsCollector] > (StatsCollector-4:ctx-c1a20ac2) (logid:b7064d0c) VmStatsCollector is > running... > 2016-02-17 14:42:25,349 DEBUG [c.c.a.t.Request] > (StatsCollector-4:ctx-c1a20ac2) (logid:b7064d0c) Seq > 121-2842334314824210225: Received: { Ans: , MgmtId: 90212275930085, via: > 121(srv-kvm01.cloud.bst.su), Ver: v1, Flags: 10, { GetVmStatsAnswer } } > 2016-02-17 14:42:27,756 DEBUG [c.c.a.ApiServlet] > (catalina-exec-10:ctx-b706cef7) (logid:a71b8b76) ===START=== 10.30.10.41 > -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709347689 > 2016-02-17 14:42:27,824 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-10:ctx-b706cef7 ctx-4a7005e7) (logid:a71b8b76) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:27,870 DEBUG [c.c.a.ApiServlet] > (catalina-exec-10:ctx-b706cef7 ctx-4a7005e7) (logid:a71b8b76) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709347689 > 2016-02-17 14:42:28,878 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] > (AsyncJobMgr-Heartbeat-1:ctx-46abae78) (logid:0c233f0d) Begin cleanup > expired async-jobs > 2016-02-17 14:42:28,908 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] > (AsyncJobMgr-Heartbeat-1:ctx-46abae78) (logid:0c233f0d) End cleanup expired > async-jobs > 2016-02-17 14:42:30,757 DEBUG [c.c.a.ApiServlet] > (catalina-exec-8:ctx-f88cb125) (logid:37518ba5) ===START=== 10.30.10.41 -- > GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709350683 > 2016-02-17 14:42:30,819 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-8:ctx-f88cb125 ctx-9cf26608) (logid:37518ba5) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:30,862 DEBUG [c.c.a.ApiServlet] > (catalina-exec-8:ctx-f88cb125 ctx-9cf26608) (logid:37518ba5) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709350683 > 2016-02-17 14:42:33,753 DEBUG [c.c.a.ApiServlet] > (catalina-exec-12:ctx-31e13dd3) (logid:5eb61ab6) ===START=== 10.30.10.41 > -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709353683 > 2016-02-17 14:42:33,817 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-12:ctx-31e13dd3 ctx-fb580cc8) (logid:5eb61ab6) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:33,859 DEBUG [c.c.a.ApiServlet] > (catalina-exec-12:ctx-31e13dd3 ctx-fb580cc8) (logid:5eb61ab6) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709353683 > 2016-02-17 14:42:34,337 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-3:null) (logid:) SeqA 127-27661: Processing Seq > 127-27661: { Cmd , MgmtId: -1, via: 127, Ver: v1, Flags: 11, > > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":79,"_loadInfo":"{\n > \"connections\": [\n {\n \"id\": 28,\n \"clientInfo\": > \"\",\n \"host\": \"10.30.16.10\",\n \"port\": 5904,\n > \"tag\": \"4535bf74-d255-4634-b873-d4185b3e6433\",\n \"createTime\": > 1455702716959,\n \"lastUsedTime\": 1455709352740\n }\n > ]\n}","wait":0}}] } > 2016-02-17 14:42:34,349 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-3:null) (logid:) SeqA 127-27661: Sending Seq > 127-27661: { Ans: , MgmtId: 90212275930085, via: 127, Ver: v1, Flags: > 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2016-02-17 14:42:34,763 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] > (secstorage-1:ctx-19feb311) (logid:3b1ae194) Zone 4 is ready to launch > secondary storage VM > 2016-02-17 14:42:34,834 DEBUG [c.c.c.ConsoleProxyManagerImpl] > (consoleproxy-1:ctx-3525dc1e) (logid:949d40ea) Zone 4 is ready to launch > console proxy > 2016-02-17 14:42:36,740 DEBUG [c.c.a.ApiServlet] > (catalina-exec-11:ctx-3f579fb7) (logid:4ddb3f86) ===START=== 10.30.10.41 > -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709356682 > 2016-02-17 14:42:36,835 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-11:ctx-3f579fb7 ctx-c5484f70) (logid:4ddb3f86) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:36,895 DEBUG [c.c.a.ApiServlet] > (catalina-exec-11:ctx-3f579fb7 ctx-c5484f70) (logid:4ddb3f86) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709356682 > 2016-02-17 14:42:38,876 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] > (AsyncJobMgr-Heartbeat-1:ctx-f20bc02c) (logid:c1f1a56b) Begin cleanup > expired async-jobs > 2016-02-17 14:42:38,901 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] > (AsyncJobMgr-Heartbeat-1:ctx-f20bc02c) (logid:c1f1a56b) End cleanup expired > async-jobs > 2016-02-17 14:42:39,758 DEBUG [c.c.a.ApiServlet] > (catalina-exec-13:ctx-c125e815) (logid:a54a004b) ===START=== 10.30.10.41 > -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709359688 > 2016-02-17 14:42:39,819 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-13:ctx-c125e815 ctx-7db89eda) (logid:a54a004b) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:39,860 DEBUG [c.c.a.ApiServlet] > (catalina-exec-13:ctx-c125e815 ctx-7db89eda) (logid:a54a004b) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709359688 > 2016-02-17 14:42:42,754 DEBUG [c.c.a.ApiServlet] > (catalina-exec-7:ctx-e388f44d) (logid:d14628b8) ===START=== 10.30.10.41 -- > GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709362683 > 2016-02-17 14:42:42,818 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-7:ctx-e388f44d ctx-0e07e3be) (logid:d14628b8) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:42,863 DEBUG [c.c.a.ApiServlet] > (catalina-exec-7:ctx-e388f44d ctx-0e07e3be) (logid:d14628b8) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709362683 > 2016-02-17 14:42:44,336 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-12:null) (logid:) SeqA 127-27662: Processing Seq > 127-27662: { Cmd , MgmtId: -1, via: 127, Ver: v1, Flags: 11, > > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":79,"_loadInfo":"{\n > \"connections\": [\n {\n \"id\": 28,\n \"clientInfo\": > \"\",\n \"host\": \"10.30.16.10\",\n \"port\": 5904,\n > \"tag\": \"4535bf74-d255-4634-b873-d4185b3e6433\",\n \"createTime\": > 1455702716959,\n \"lastUsedTime\": 1455709361905\n }\n > ]\n}","wait":0}}] } > 2016-02-17 14:42:44,347 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-12:null) (logid:) SeqA 127-27662: Sending Seq > 127-27662: { Ans: , MgmtId: 90212275930085, via: 127, Ver: v1, Flags: > 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2016-02-17 14:42:45,753 DEBUG [c.c.a.ApiServlet] > (catalina-exec-18:ctx-fa009cf4) (logid:0564cb71) ===START=== 10.30.10.41 > -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709365682 > 2016-02-17 14:42:45,821 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-18:ctx-fa009cf4 ctx-c631c841) (logid:0564cb71) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:45,864 DEBUG [c.c.a.ApiServlet] > (catalina-exec-18:ctx-fa009cf4 ctx-c631c841) (logid:0564cb71) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709365682 > 2016-02-17 14:42:47,473 DEBUG [c.c.s.StatsCollector] > (StatsCollector-2:ctx-6290e24b) (logid:ba691574) AutoScaling Monitor is > running... > 2016-02-17 14:42:48,756 DEBUG [c.c.a.ApiServlet] > (catalina-exec-21:ctx-6f46f10a) (logid:fd06240c) ===START=== 10.30.10.41 > -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709368688 > 2016-02-17 14:42:48,823 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-21:ctx-6f46f10a ctx-c9bf5115) (logid:fd06240c) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:48,869 DEBUG [c.c.a.ApiServlet] > (catalina-exec-21:ctx-6f46f10a ctx-c9bf5115) (logid:fd06240c) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709368688 > 2016-02-17 14:42:48,883 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] > (AsyncJobMgr-Heartbeat-1:ctx-89f8fe29) (logid:b8f61b84) Begin cleanup > expired async-jobs > 2016-02-17 14:42:48,913 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] > (AsyncJobMgr-Heartbeat-1:ctx-89f8fe29) (logid:b8f61b84) End cleanup expired > async-jobs > 2016-02-17 14:42:48,931 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] > (RouterStatusMonitor-1:ctx-9e4ea762) (logid:77f09669) Found 1 routers to > update status. > 2016-02-17 14:42:48,938 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] > (RouterStatusMonitor-1:ctx-9e4ea762) (logid:77f09669) Found 0 VPC networks > to update Redundant State. > 2016-02-17 14:42:48,944 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] > (RouterStatusMonitor-1:ctx-9e4ea762) (logid:77f09669) Found 0 networks to > update RvR status. > 2016-02-17 14:42:49,063 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] > (RouterStatusMonitor-1:ctx-479db730) (logid:587e8d61) Found 1 routers to > update status. > 2016-02-17 14:42:49,069 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] > (RouterStatusMonitor-1:ctx-479db730) (logid:587e8d61) Found 0 VPC networks > to update Redundant State. > 2016-02-17 14:42:49,075 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] > (RouterStatusMonitor-1:ctx-479db730) (logid:587e8d61) Found 0 networks to > update RvR status. > 2016-02-17 14:42:50,035 DEBUG [c.c.a.m.ClusteredAgentAttache] > (AgentManager-Handler-2:null) (logid:) Seq 121-6638305850744116095: Routing > from 121491073759284 > 2016-02-17 14:42:50,097 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] > (AgentManager-Handler-9:null) (logid:) Seq 121-6638305850744116095: MgmtId > 121491073759284: Resp: Routing to peer > 2016-02-17 14:42:51,755 DEBUG [c.c.a.ApiServlet] > (catalina-exec-10:ctx-e0ab94a5) (logid:7c7050f3) ===START=== 10.30.10.41 > -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709371682 > 2016-02-17 14:42:51,820 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-10:ctx-e0ab94a5 ctx-786de8bd) (logid:7c7050f3) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:51,871 DEBUG [c.c.a.ApiServlet] > (catalina-exec-10:ctx-e0ab94a5 ctx-786de8bd) (logid:7c7050f3) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709371682 > 2016-02-17 14:42:53,146 DEBUG [c.c.s.StatsCollector] > (StatsCollector-3:ctx-82829583) (logid:d7658d5e) StorageCollector is > running... > 2016-02-17 14:42:53,173 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] > (StatsCollector-3:ctx-82829583) (logid:d7658d5e) getCommandHostDelegation: > class com.cloud.agent.api.GetStorageStatsCommand > 2016-02-17 14:42:53,173 DEBUG [c.c.h.XenServerGuru] > (StatsCollector-3:ctx-82829583) (logid:d7658d5e) getCommandHostDelegation: > class com.cloud.agent.api.GetStorageStatsCommand > 2016-02-17 14:42:53,223 DEBUG [c.c.a.t.Request] > (StatsCollector-3:ctx-82829583) (logid:d7658d5e) Seq > 130-1390486384950642428: Received: { Ans: , MgmtId: 90212275930085, via: > 130(s-78-VM), Ver: v1, Flags: 10, { GetStorageStatsAnswer } } > 2016-02-17 14:42:53,229 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] > (StatsCollector-3:ctx-82829583) (logid:d7658d5e) getCommandHostDelegation: > class com.cloud.agent.api.GetStorageStatsCommand > 2016-02-17 14:42:53,230 DEBUG [c.c.h.XenServerGuru] > (StatsCollector-3:ctx-82829583) (logid:d7658d5e) getCommandHostDelegation: > class com.cloud.agent.api.GetStorageStatsCommand > 2016-02-17 14:42:53,348 DEBUG [c.c.a.m.ClusteredAgentAttache] > (AgentManager-Handler-6:null) (logid:) Seq 130-4066468988538848895: Routing > from 121491073759284 > 2016-02-17 14:42:53,390 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] > (AgentManager-Handler-8:null) (logid:) Seq 130-4066468988538848895: MgmtId > 121491073759284: Resp: Routing to peer > 2016-02-17 14:42:53,405 DEBUG [c.c.a.m.ClusteredAgentAttache] > (AgentManager-Handler-15:null) (logid:) Seq 121-6638305850744116096: > Routing from 121491073759284 > 2016-02-17 14:42:53,452 DEBUG [c.c.a.t.Request] > (StatsCollector-3:ctx-82829583) (logid:d7658d5e) Seq > 121-2842334314824210226: Received: { Ans: , MgmtId: 90212275930085, via: > 121(srv-kvm01.cloud.bst.su), Ver: v1, Flags: 10, { GetStorageStatsAnswer > } } > 2016-02-17 14:42:53,602 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] > (AgentManager-Handler-5:null) (logid:) Seq 121-6638305850744116096: MgmtId > 121491073759284: Resp: Routing to peer > 2016-02-17 14:42:54,337 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-13:null) (logid:) SeqA 127-27663: Processing Seq > 127-27663: { Cmd , MgmtId: -1, via: 127, Ver: v1, Flags: 11, > > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":79,"_loadInfo":"{\n > \"connections\": [\n {\n \"id\": 28,\n \"clientInfo\": > \"\",\n \"host\": \"10.30.16.10\",\n \"port\": 5904,\n > \"tag\": \"4535bf74-d255-4634-b873-d4185b3e6433\",\n \"createTime\": > 1455702716959,\n \"lastUsedTime\": 1455709374152\n }\n > ]\n}","wait":0}}] } > 2016-02-17 14:42:54,350 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-13:null) (logid:) SeqA 127-27663: Sending Seq > 127-27663: { Ans: , MgmtId: 90212275930085, via: 127, Ver: v1, Flags: > 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2016-02-17 14:42:54,755 DEBUG [c.c.a.ApiServlet] > (catalina-exec-2:ctx-033d8622) (logid:a74966c6) ===START=== 10.30.10.41 -- > GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709374683 > 2016-02-17 14:42:54,819 DEBUG [c.c.u.AccountManagerImpl] > (catalina-exec-2:ctx-033d8622 ctx-da3d563e) (logid:a74966c6) Access to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] granted to > Acct[69296515-f19c-407c-859e-42f4599e4653-ykarpel] by DomainChecker > 2016-02-17 14:42:54,861 DEBUG [c.c.a.ApiServlet] > (catalina-exec-2:ctx-033d8622 ctx-da3d563e) (logid:a74966c6) ===END=== > 10.30.10.41 -- GET > > > command=queryAsyncJobResult&jobId=0a96ee1e-408a-4f4f-988a-3fa0974cec69&response=json&_=1455709374683 > 2016-02-17 14:42:55,045 DEBUG [c.c.a.t.Request] > (AgentManager-Handler-14:null) (logid:) Seq 121-2842334314824210224: > Processing: { Ans: , MgmtId: 90212275930085, via: 121, Ver: v1, Flags: > 110, > > [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"Unsupported > protocol","wait":0}}] } > 2016-02-17 14:42:55,045 DEBUG [c.c.a.m.AgentAttache] > (AgentManager-Handler-14:null) (logid:) Seq 121-2842334314824210224: No > more commands found > 2016-02-17 14:42:55,045 DEBUG [c.c.a.t.Request] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) Seq 121-2842334314824210224: Received: { Ans: , MgmtId: > 90212275930085, via: 121(srv-kvm01.cloud.bst.su), Ver: v1, Flags: 110, { > CopyCmdAnswer } } > 2016-02-17 14:42:55,069 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) getCommandHostDelegation: class > org.apache.cloudstack.storage.command.DeleteCommand > 2016-02-17 14:42:55,070 DEBUG [c.c.h.XenServerGuru] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) getCommandHostDelegation: class > org.apache.cloudstack.storage.command.DeleteCommand > 2016-02-17 14:42:55,075 DEBUG [c.c.a.t.Request] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) Seq 130-1390486384950642429: Sending { Cmd , MgmtId: > 90212275930085, via: 130(s-78-VM), Ver: v1, Flags: 100011, > > [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/7/355","volume":{"uuid":"c935a963-2990-4bc4-86fd-facf5e711e5b","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"f5efdbfb-8fe7-3dfd-bc07-5088222d8b84","id":52,"poolType":"RBD","host":" > ceph-mon.cloud.bst.su","path":"rbd-cl","port":6789,"url":"RBD:// > > ceph-mon.cloud.bst.su/rbd-cl/?ROLE=Primary&STOREUUID=f5efdbfb-8fe7-3dfd-bc07-5088222d8b84 > > "}},"name":"ROOT-99","size":472312242,"path":"c935a963-2990-4bc4-86fd-facf5e711e5b","volumeId":355,"vmName":"i-7-99-VM","accountId":7,"format":"RAW","provisioningType":"THIN","id":355,"deviceId":0,"hypervisorType":"KVM"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs:// > srv-nfs.cloud.bst.su/nfs > ","_role":"ImageCache"}},"vmName":"i-7-99-VM","name":"test","hypervisorType":"KVM","id":16,"quiescevm":false,"physicalSize":0}},"wait":0}}] > } > 2016-02-17 14:42:55,182 DEBUG [c.c.a.t.Request] > (AgentManager-Handler-1:null) (logid:) Seq 130-1390486384950642429: > Processing: { Ans: , MgmtId: 90212275930085, via: 130, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } > 2016-02-17 14:42:55,182 DEBUG [c.c.a.t.Request] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) Seq 130-1390486384950642429: Received: { Ans: , MgmtId: > 90212275930085, via: 130(s-78-VM), Ver: v1, Flags: 10, { Answer } } > 2016-02-17 14:42:55,197 DEBUG [c.c.s.StatsCollector] > (StatsCollector-1:ctx-0ffd116a) (logid:d8a68bc7) HostStatsCollector is > running... > 2016-02-17 14:42:55,242 DEBUG [c.c.a.t.Request] > (StatsCollector-1:ctx-0ffd116a) (logid:d8a68bc7) Seq > 121-2842334314824210227: Received: { Ans: , MgmtId: 90212275930085, via: > 121(srv-kvm01.cloud.bst.su), Ver: v1, Flags: 10, { GetHostStatsAnswer } } > 2016-02-17 14:42:55,290 DEBUG [c.c.s.s.SnapshotManagerImpl] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) Failed to create snapshot > com.cloud.utils.exception.CloudRuntimeException: Unsupported protocol > at > > org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:285) > at > > org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:155) > at > > org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:322) > at > > com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1007) > 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:497) > at > > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) > at > > org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) > at > > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204) > at com.sun.proxy.$Proxy189.takeSnapshot(Unknown Source) > at > > org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1591) > at > > com.cloud.storage.VolumeApiServiceImpl.orchestrateTakeVolumeSnapshot(VolumeApiServiceImpl.java:2091) > at > > com.cloud.storage.VolumeApiServiceImpl.orchestrateTakeVolumeSnapshot(VolumeApiServiceImpl.java:2883) > 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:497) > at > > com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) > at > > com.cloud.storage.VolumeApiServiceImpl.handleVmWorkJob(VolumeApiServiceImpl.java:2891) > 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:497) > at > > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) > at > > org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) > at > > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204) > at com.sun.proxy.$Proxy194.handleVmWorkJob(Unknown Source) > at > com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) > at > > org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554) > 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:502) > 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) > 2016-02-17 14:42:55,338 DEBUG [o.a.c.s.v.VolumeServiceImpl] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) Take snapshot: 355 failed > com.cloud.utils.exception.CloudRuntimeException: Failed to create snapshot > at > > com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1023) > 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:497) > at > > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) > at > > org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) > at > > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204) > at com.sun.proxy.$Proxy189.takeSnapshot(Unknown Source) > at > > org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1591) > at > > com.cloud.storage.VolumeApiServiceImpl.orchestrateTakeVolumeSnapshot(VolumeApiServiceImpl.java:2091) > at > > com.cloud.storage.VolumeApiServiceImpl.orchestrateTakeVolumeSnapshot(VolumeApiServiceImpl.java:2883) > 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:497) > at > > com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) > at > > com.cloud.storage.VolumeApiServiceImpl.handleVmWorkJob(VolumeApiServiceImpl.java:2891) > 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:497) > at > > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) > at > > org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) > at > > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204) > at com.sun.proxy.$Proxy194.handleVmWorkJob(Unknown Source) > at > com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) > at > > org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554) > 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:502) > 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: com.cloud.utils.exception.CloudRuntimeException: Unsupported > protocol > at > > org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:285) > at > > org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:155) > at > > org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:322) > ... 45 more > 2016-02-17 14:42:55,340 ERROR [c.c.v.VmWorkJobHandlerProxy] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) Invocation exception, caused by: > com.cloud.utils.exception.CloudRuntimeException: Failed to take snapshot > 2016-02-17 14:42:55,344 INFO [c.c.v.VmWorkJobHandlerProxy] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527 ctx-85ee1822) > (logid:0a96ee1e) Rethrow exception > com.cloud.utils.exception.CloudRuntimeException: Failed to take snapshot > 2016-02-17 14:42:55,344 DEBUG [c.c.v.VmWorkJobDispatcher] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527) (logid:0a96ee1e) Done > with run of VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot for VM 99, > job origin: 2524 > 2016-02-17 14:42:55,344 ERROR [c.c.v.VmWorkJobDispatcher] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527) (logid:0a96ee1e) > Unable to complete AsyncJobVO {id:2527, userId: 10, accountId: 7, > instanceType: null, instanceId: null, cmd: > com.cloud.vm.VmWorkTakeVolumeSnapshot, cmdInfo: > > rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrVGFrZVZvbHVtZVNuYXBzaG90BL5gG4Li1c8CAARaAAlxdWllc2NlVm1MAAhwb2xpY3lJZHQAEExqYXZhL2xhbmcvTG9uZztMAApzbmFwc2hvdElkcQB-AAFMAAh2b2x1bWVJZHEAfgABeHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAcAAAAAAAAACgAAAAAAAABjdAAUVm9sdW1lQXBpU2VydmljZUltcGwAc3IADmphdmEubGFuZy5Mb25nO4vkkMyPI98CAAFKAAV2YWx1ZXhyABBqYXZhLmxhbmcuTnVtYmVyhqyVHQuU4IsCAAB4cAAAAAAAAAAAc3EAfgAGAAAAAAAAABBzcQB-AAYAAAAAAAABYw, > cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, > result: null, initMsid: 90212275930085, completeMsid: null, lastUpdated: > null, lastPolled: null, created: Wed Feb 17 14:41:57 MSK 2016}, job > origin:2524 > com.cloud.utils.exception.CloudRuntimeException: Failed to take snapshot > at > > org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1594) > at > > com.cloud.storage.VolumeApiServiceImpl.orchestrateTakeVolumeSnapshot(VolumeApiServiceImpl.java:2091) > at > > com.cloud.storage.VolumeApiServiceImpl.orchestrateTakeVolumeSnapshot(VolumeApiServiceImpl.java:2883) > 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:497) > at > > com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) > at > > com.cloud.storage.VolumeApiServiceImpl.handleVmWorkJob(VolumeApiServiceImpl.java:2891) > 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:497) > at > > org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) > at > > org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91) > at > > org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) > at > > org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204) > at com.sun.proxy.$Proxy194.handleVmWorkJob(Unknown Source) > at > com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) > at > > org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554) > 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:502) > 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: com.cloud.utils.exception.CloudRuntimeException: Failed to > create snapshot > at > > com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1023) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at > > sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) > ... 42 more > Caused by: com.cloud.utils.exception.CloudRuntimeException: Unsupported > protocol > at > > org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:285) > at > > org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:155) > at > > org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:322) > ... 45 more > 2016-02-17 14:42:55,367 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527) (logid:0a96ee1e) > Complete async job-2527, jobStatus: FAILED, resultCode: 0, result: > > rO0ABXNyAC9jb20uY2xvdWQudXRpbHMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGlvbgAAAABWTU9yAwABSQALY3NFcnJvckNvZGV4cgAaamF2YS5sYW5nLlJ1bnRpbWVFeGNlcHRpb26eXwZHCjSD5QIAAHhyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAFY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwc3EAfgAAc3EAfgAAcQB-AAp0ABRVbnN1cHBvcnRlZCBwcm90b2NvbHVyAB5bTGphdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudDsCRio8PP0iOQIAAHhwAAAAMHNyABtqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnRhCcWaJjbdhQIABEkACmxpbmVOdW1iZXJMAA5kZWNsYXJpbmdDbGFzc3EAfgAFTAAIZmlsZU5hbWVxAH4ABUwACm1ldGhvZE5hbWVxAH4ABXhwAAABHXQAOm9yZy5hcGFjaGUuY2xvdWRzdGFjay5zdG9yYWdlLnNuYXBzaG90LlNuYXBzaG90U2VydmljZUltcGx0ABhTbmFwc2hvdFNlcnZpY2VJbXBsLmphdmF0AA5iYWNrdXBTbmFwc2hvdHNxAH4ADgAAAJt0AEBvcmcuYXBhY2hlLmNsb3Vkc3RhY2suc3RvcmFnZS5zbmFwc2hvdC5YZW5zZXJ2ZXJTbmFwc2hvdFN0cmF0ZWd5dAAeWGVuc2VydmVyU25hcHNob3RTdHJhdGVneS5qYXZhcQB-ABJzcQB-AA4AAAFCcQB-ABRxAH4AFXQADHRha2VTbmFwc2hvdHNxAH4ADgAAA-90AC5jb20uY2xvdWQuc3RvcmFnZS5zbmFwc2hvdC5TbmFwc2hvdE1hbmFnZXJJbXBsdAAYU25hcHNob3RNYW5hZ2VySW1wbC5qYXZhcQB-ABdzcQB-AA7____-dAAkc3VuLnJlZmxlY3QuTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsdAAdTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsLmphdmF0AAdpbnZva2Uwc3EAfgAOAAAAPnEAfgAccQB-AB10AAZpbnZva2VzcQB-AA4AAAArdAAoc3VuLnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgAgc3EAfgAOAAAB8XQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-ACBzcQB-AA4AAAE9dAAob3JnLnNwcmluZ2ZyYW1ld29yay5hb3Auc3VwcG9ydC5Bb3BVdGlsc3QADUFvcFV0aWxzLmphdmF0AB5pbnZva2VKb2lucG9pbnRVc2luZ1JlZmxlY3Rpb25zcQB-AA4AAAC3dAA8b3JnLnNwcmluZ2ZyYW1ld29yay5hb3AuZnJhbWV3b3JrLlJlZmxlY3RpdmVNZXRob2RJbnZvY2F0aW9udAAfUmVmbGVjdGl2ZU1ldGhvZEludm9jYXRpb24uamF2YXQAD2ludm9rZUpvaW5wb2ludHNxAH4ADgAAAJZxAH4ALHEAfgAtdAAHcHJvY2VlZHNxAH4ADgAAAFt0AD9vcmcuc3ByaW5nZnJhbWV3b3JrLmFvcC5pbnRlcmNlcHRvci5FeHBvc2VJbnZvY2F0aW9uSW50ZXJjZXB0b3J0ACBFeHBvc2VJbnZvY2F0aW9uSW50ZXJjZXB0b3IuamF2YXEAfgAgc3EAfgAOAAAArHEAfgAscQB-AC1xAH4AMHNxAH4ADgAAAMx0ADRvcmcuc3ByaW5nZnJhbWV3b3JrLmFvcC5mcmFtZXdvcmsuSmRrRHluYW1pY0FvcFByb3h5dAAXSmRrRHluYW1pY0FvcFByb3h5LmphdmFxAH4AIHNxAH4ADv____90ABdjb20uc3VuLnByb3h5LiRQcm94eTE4OXBxAH4AF3NxAH4ADgAABjd0ADZvcmcuYXBhY2hlLmNsb3Vkc3RhY2suc3RvcmFnZS52b2x1bWUuVm9sdW1lU2VydmljZUltcGx0ABZWb2x1bWVTZXJ2aWNlSW1wbC5qYXZhcQB-ABdzcQB-AA4AAAgrdAAmY29tLmNsb3VkLnN0b3JhZ2UuVm9sdW1lQXBpU2VydmljZUltcGx0ABlWb2x1bWVBcGlTZXJ2aWNlSW1wbC5qYXZhdAAdb3JjaGVzdHJhdGVUYWtlVm9sdW1lU25hcHNob3RzcQB-AA4AAAtDcQB-AD5xAH4AP3EAfgBAc3EAfgAO_____nEAfgAccQB-AB1xAH4AHnNxAH4ADgAAAD5xAH4AHHEAfgAdcQB-ACBzcQB-AA4AAAArcQB-ACJxAH4AI3EAfgAgc3EAfgAOAAAB8XEAfgAlcQB-ACZxAH4AIHNxAH4ADgAAAGt0ACJjb20uY2xvdWQudm0uVm1Xb3JrSm9iSGFuZGxlclByb3h5dAAaVm1Xb3JrSm9iSGFuZGxlclByb3h5LmphdmF0AA9oYW5kbGVWbVdvcmtKb2JzcQB-AA4AAAtLcQB-AD5xAH4AP3EAfgBJc3EAfgAO_____nEAfgAccQB-AB1xAH4AHnNxAH4ADgAAAD5xAH4AHHEAfgAdcQB-ACBzcQB-AA4AAAArcQB-ACJxAH4AI3EAfgAgc3EAfgAOAAAB8XEAfgAlcQB-ACZxAH4AIHNxAH4ADgAAAT1xAH4AKHEAfgApcQB-ACpzcQB-AA4AAAC3cQB-ACxxAH4ALXEAfgAuc3EAfgAOAAAAlnEAfgAscQB-AC1xAH4AMHNxAH4ADgAAAFtxAH4AMnEAfgAzcQB-ACBzcQB-AA4AAACscQB-ACxxAH4ALXEAfgAwc3EAfgAOAAAAzHEAfgA2cQB-ADdxAH4AIHNxAH4ADv____90ABdjb20uc3VuLnByb3h5LiRQcm94eTE5NHBxAH4ASXNxAH4ADgAAAGZ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4ADgAAAip0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-AA4AAAAxdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-AA4AAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgAOAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4AZXQAD2NhbGxXaXRoQ29udGV4dHNxAH4ADgAAADVxAH4AaHEAfgBldAAOcnVuV2l0aENvbnRleHRzcQB-AA4AAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-AGFxAH4AYnNxAH4ADgAAAfZxAH4AXHEAfgBdcQB-AGJzcQB-AA4AAAH_dAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-AGZzcQB-AA4AAAEKdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgBic3EAfgAOAAAEdnQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgAOAAACaXQALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4Ad3EAfgBic3EAfgAOAAAC6XQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgBic3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAd4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4Ag3gAABCadwgAAAAAAAAAAHh0ABlGYWlsZWQgdG8gY3JlYXRlIHNuYXBzaG90dXEAfgAMAAAALXNxAH4ADgAAA_9xAH4AGXEAfgAacQB-ABdzcQB-AA7____-cQB-ABxxAH4AHXEAfgAec3EAfgAOAAAAPnEAfgAccQB-AB1xAH4AIHNxAH4ADgAAACtxAH4AInEAfgAjcQB-ACBzcQB-AA4AAAHxcQB-ACVxAH4AJnEAfgAgc3EAfgAOAAABPXEAfgAocQB-AClxAH4AKnNxAH4ADgAAALdxAH4ALHEAfgAtcQB-AC5zcQB-AA4AAACWcQB-ACxxAH4ALXEAfgAwc3EAfgAOAAAAW3EAfgAycQB-ADNxAH4AIHNxAH4ADgAAAKxxAH4ALHEAfgAtcQB-ADBzcQB-AA4AAADMcQB-ADZxAH4AN3EAfgAgc3EAfgAO_____3EAfgA5cHEAfgAXc3EAfgAOAAAGN3EAfgA7cQB-ADxxAH4AF3NxAH4ADgAACCtxAH4APnEAfgA_cQB-AEBzcQB-AA4AAAtDcQB-AD5xAH4AP3EAfgBAc3EAfgAO_____nEAfgAccQB-AB1xAH4AHnNxAH4ADgAAAD5xAH4AHHEAfgAdcQB-ACBzcQB-AA4AAAArcQB-ACJxAH4AI3EAfgAgc3EAfgAOAAAB8XEAfgAlcQB-ACZxAH4AIHNxAH4ADgAAAGtxAH4AR3EAfgBIcQB-AElzcQB-AA4AAAtLcQB-AD5xAH4AP3EAfgBJc3EAfgAO_____nEAfgAccQB-AB1xAH4AHnNxAH4ADgAAAD5xAH4AHHEAfgAdcQB-ACBzcQB-AA4AAAArcQB-ACJxAH4AI3EAfgAgc3EAfgAOAAAB8XEAfgAlcQB-ACZxAH4AIHNxAH4ADgAAAT1xAH4AKHEAfgApcQB-ACpzcQB-AA4AAAC3cQB-ACxxAH4ALXEAfgAuc3EAfgAOAAAAlnEAfgAscQB-AC1xAH4AMHNxAH4ADgAAAFtxAH4AMnEAfgAzcQB-ACBzcQB-AA4AAACscQB-ACxxAH4ALXEAfgAwc3EAfgAOAAAAzHEAfgA2cQB-ADdxAH4AIHNxAH4ADv____9xAH4AVnBxAH4ASXNxAH4ADgAAAGZxAH4AWHEAfgBZcQB-AFpzcQB-AA4AAAIqcQB-AFxxAH4AXXEAfgBec3EAfgAOAAAAMXEAfgBgcQB-AGFxAH4AYnNxAH4ADgAAADhxAH4AZHEAfgBlcQB-AGZzcQB-AA4AAABncQB-AGhxAH4AZXEAfgBpc3EAfgAOAAAANXEAfgBocQB-AGVxAH4Aa3NxAH4ADgAAAC5xAH4AbXEAfgBhcQB-AGJzcQB-AA4AAAH2cQB-AFxxAH4AXXEAfgBic3EAfgAOAAAB_3EAfgBwcQB-AHFxAH4AZnNxAH4ADgAAAQpxAH4Ac3EAfgB0cQB-AGJzcQB-AA4AAAR2cQB-AHZxAH4Ad3EAfgB4c3EAfgAOAAACaXEAfgB6cQB-AHdxAH4AYnNxAH4ADgAAAulxAH4AfHEAfgB9cQB-AGJxAH4AgXgAABCadwgAAAAAAAAAAHh0ABdGYWlsZWQgdG8gdGFrZSBzbmFwc2hvdHVxAH4ADAAAACFzcQB-AA4AAAY6cQB-ADtxAH4APHEAfgAXc3EAfgAOAAAIK3EAfgA-cQB-AD9xAH4AQHNxAH4ADgAAC0NxAH4APnEAfgA_cQB-AEBzcQB-AA7____-cQB-ABxxAH4AHXEAfgAec3EAfgAOAAAAPnEAfgAccQB-AB1xAH4AIHNxAH4ADgAAACtxAH4AInEAfgAjcQB-ACBzcQB-AA4AAAHxcQB-ACVxAH4AJnEAfgAgc3EAfgAOAAAAa3EAfgBHcQB-AEhxAH4ASXNxAH4ADgAAC0txAH4APnEAfgA_cQB-AElzcQB-AA7____-cQB-ABxxAH4AHXEAfgAec3EAfgAOAAAAPnEAfgAccQB-AB1xAH4AIHNxAH4ADgAAACtxAH4AInEAfgAjcQB-ACBzcQB-AA4AAAHxcQB-ACVxAH4AJnEAfgAgc3EAfgAOAAABPXEAfgAocQB-AClxAH4AKnNxAH4ADgAAALdxAH4ALHEAfgAtcQB-AC5zcQB-AA4AAACWcQB-ACxxAH4ALXEAfgAwc3EAfgAOAAAAW3EAfgAycQB-ADNxAH4AIHNxAH4ADgAAAKxxAH4ALHEAfgAtcQB-ADBzcQB-AA4AAADMcQB-ADZxAH4AN3EAfgAgc3EAfgAO_____3EAfgBWcHEAfgBJc3EAfgAOAAAAZnEAfgBYcQB-AFlxAH4AWnNxAH4ADgAAAipxAH4AXHEAfgBdcQB-AF5zcQB-AA4AAAAxcQB-AGBxAH4AYXEAfgBic3EAfgAOAAAAOHEAfgBkcQB-AGVxAH4AZnNxAH4ADgAAAGdxAH4AaHEAfgBlcQB-AGlzcQB-AA4AAAA1cQB-AGhxAH4AZXEAfgBrc3EAfgAOAAAALnEAfgBtcQB-AGFxAH4AYnNxAH4ADgAAAfZxAH4AXHEAfgBdcQB-AGJzcQB-AA4AAAH_cQB-AHBxAH4AcXEAfgBmc3EAfgAOAAABCnEAfgBzcQB-AHRxAH4AYnNxAH4ADgAABHZxAH4AdnEAfgB3cQB-AHhzcQB-AA4AAAJpcQB-AHpxAH4Ad3EAfgBic3EAfgAOAAAC6XEAfgB8cQB-AH1xAH4AYnEAfgCBeAAAEJp3CAAAAAAAAAAAeA > 2016-02-17 14:42:55,376 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527) (logid:0a96ee1e) > Publish async job-2527 complete on message bus > 2016-02-17 14:42:55,377 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527) (logid:0a96ee1e) Wake > up jobs related to job-2527 > 2016-02-17 14:42:55,377 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527) (logid:0a96ee1e) > Update db status for job-2527 > 2016-02-17 14:42:55,383 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527) (logid:0a96ee1e) Wake > up jobs joined with job-2527 and disjoin all subjobs created from job- 2527 > 2016-02-17 14:42:55,400 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527) (logid:0a96ee1e) Done > executing com.cloud.vm.VmWorkTakeVolumeSnapshot for job-2527 > 2016-02-17 14:42:55,409 INFO [o.a.c.f.j.i.AsyncJobMonitor] > (Work-Job-Executor-51:ctx-f6739a2f job-2524/job-2527) (logid:0a96ee1e) > Remove job-2527 from job monitoring > 2016-02-17 14:42:55,456 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (API-Job-Executor-82:ctx-3b960545 job-2524) (logid:0a96ee1e) Complete async > job-2524, jobStatus: FAILED, resultCode: 530, result: > > org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed > to create snapshot due to an internal error creating snapshot for volume > 355"} > 2016-02-17 14:42:55,462 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (API-Job-Executor-82:ctx-3b960545 job-2524) (logid:0a96ee1e) Publish async > job-2524 complete on message bus > 2016-02-17 14:42:55,462 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (API-Job-Executor-82:ctx-3b960545 job-2524) (logid:0a96ee1e) Wake up jobs > related to job-2524 > 2016-02-17 14:42:55,462 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (API-Job-Executor-82:ctx-3b960545 job-2524) (logid:0a96ee1e) Update db > status for job-2524 > 2016-02-17 14:42:55,467 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (API-Job-Executor-82:ctx-3b960545 job-2524) (logid:0a96ee1e) Wake up jobs > joined with job-2524 and disjoin all subjobs created from job- 2524 > 2016-02-17 14:42:55,475 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] > (API-Job-Executor-82:ctx-3b960545 job-2524) (logid:0a96ee1e) Done executing > org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd for > job-2524 > 2016-02-17 14:42:55,475 INFO [o.a.c.f.j.i.AsyncJobMonitor] > (API-Job-Executor-82:ctx-3b960545 job-2524) (logid:0a96ee1e) Remove > job-2524 from job monitoring >
