UPD: s3. RadosGW config: [client.rgw.srv-rgw01] rgw_print_continue = false host = srv-rgw01 rgw dns name = s3.cloud.bst.su rgw_frontends = civetweb port=80 rgw_socket_path = /tmp/radosgw.sock
[client.rgw.srv-rgw02] rgw_print_continue = false host = srv-rgw01 rgw dns name = s3.cloud.bst.su rgw_frontends = civetweb port=80 rgw_socket_path = /tmp/radosgw.sock [ceph@ceph-adm ~]s3cmd -c s3test.cfg ls 2016-02-18 06:37 s3://cl-images [ceph@ceph-adm ~]$ s3cmd -c s3test.cfg put s3test.cfg s3://cl-images upload: 's3test.cfg' -> 's3://cl-images/s3test.cfg' [1 of 1] 1949 of 1949 100% in 0s 241.14 kB/s done upload: 's3test.cfg' -> 's3://cl-images/s3test.cfg' [1 of 1] 1949 of 1949 100% in 0s 99.51 kB/s done [ceph@ceph-adm ~]$ s3cmd -c s3test.cfg la 2016-02-18 07:23 1949 s3://cl-images/s3test.cfg [ceph@ceph-adm ~]$ s3cmd -c s3test.cfg rm s3://cl-images/s3test.cfg delete: 's3://cl-images/s3test.cfg' [ceph@ceph-adm ~]$ s3cmd -c s3test.cfg ls 2016-02-18 06:37 s3://cl-images 2016-02-18 10:16 GMT+03:00 Yuriy Karpel <[email protected]>: > 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 >> > >
