Multiple secondary storage in one zone; problem with volume snapshots #9754

top-secrett · 2024-09-26T14:36:23Z

top-secrett
Sep 26, 2024

ISSUE TYPE

Bug Report

CLOUDSTACK VERSION

4.19.1.0, xcp-ng hypervisor

SUMMARY

We are planning to add multiple NFS secondary storages for backup purpose. And I don't understand the principle of distribution of storage snapshots among secstors.
I created 10 Intsances in one Account and all their volume snapshots exept one were copied to the first secstore. Only one volume snapshot was copied to the second NFS secstore, but I can't create addiditinal snapshots of this volume. I attach logs in comments.

STEPS TO REPRODUCE

Add multiple NFS secondary storages, try to create volume snapshots of different instances

EXPECTED RESULTS

Snapshots are copied based on free space allocation mode to all secstores

ACTUAL RESULTS

All snapshotes are copied to the first secstore

top-secrett · 2024-09-26T14:37:49Z

top-secrett
Sep 26, 2024
Author

Example of successful snapshot to the first secstore

2024-09-26 17:21:41,283 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-968ed109 job-72464) (logid:c8e45246) Executing AsyncJobVO: {id:72464, userId: 298, accountId: 225, instanceType: Snapshot, instanceId: 870, cmd: org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd, cmdInfo: {"asyncbackup":"false","response":"json","ctxUserId":"298","volumeid":"5e964ddb-3d14-4037-a241-12972ebc5354","httpmethod":"GET","ctxStartEventId":"1811491","id":"870","ctxDetails":"{\"interface com.cloud.storage.Volume\":\"5e964ddb-3d14-4037-a241-12972ebc5354\",\"interface com.cloud.storage.Snapshot\":\"7bdc207e-974e-41ed-a51f-f104bac1102c\"}","ctxAccountId":"225","uuid":"7bdc207e-974e-41ed-a51f-f104bac1102c","cmdEventType":"SNAPSHOT.CREATE"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 108597816265214, completeMsid: null, lastUpdated: null, lastPolled: null, created: null, removed: null}
2024-09-26 17:21:41,293 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-63:ctx-968ed109 job-72464 ctx-7ca9e6a7) (logid:c8e45246) Access to Account [{"accountName":"karasev-cluster5","id":225,"uuid":"fd32d818-5d3b-4d3c-9084-34704beefaf5"}] granted to Account [{"accountName":"karasev-cluster5","id":225,"uuid":"fd32d818-5d3b-4d3c-9084-34704beefaf5"}] by DomainChecker
2024-09-26 17:21:41,304 DEBUG [c.c.a.ApiServlet] (qtp501107890-4821895:ctx-285c7273) (logid:dbfd31f0) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:21:41,329 DEBUG [c.c.a.ApiServlet] (qtp501107890-4821895:ctx-285c7273 ctx-655df114) (logid:dbfd31f0) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:21:41,333 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-63:ctx-968ed109 job-72464 ctx-7ca9e6a7) (logid:c8e45246) Access to org.apache.cloudstack.storage.volume.VolumeObject@46645c52 granted to Account [{"accountName":"karasev-cluster5","id":225,"uuid":"fd32d818-5d3b-4d3c-9084-34704beefaf5"}] by DomainChecker
2024-09-26 17:21:41,341 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-63:ctx-968ed109 job-72464 ctx-7ca9e6a7) (logid:c8e45246) Access to VM instance {"id":5474,"instanceName":"i-225-5474-VM","type":"User","uuid":"64c1d590-88a5-4dea-aede-76e0afa0bf32"} granted to Account [{"accountName":"karasev-cluster5","id":225,"uuid":"fd32d818-5d3b-4d3c-9084-34704beefaf5"}] by DomainChecker
2024-09-26 17:21:41,350 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-968ed109 job-72464 ctx-7ca9e6a7) (logid:c8e45246) Sync job-72465 execution on object VmWorkJobQueue.5474
2024-09-26 17:21:42,578 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465) (logid:c8e45246) Executing AsyncJobVO: {id:72465, userId: 298, accountId: 225, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkTakeVolumeSnapshot, cmdInfo: rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrVGFrZVZvbHVtZVNuYXBzaG90BL5gG4Li1c8CAAdaAAthc3luY0JhY2t1cFoACXF1aWVzY2VWbUwADGxvY2F0aW9uVHlwZXQAKUxjb20vY2xvdWQvc3RvcmFnZS9TbmFwc2hvdCRMb2NhdGlvblR5cGU7TAAIcG9saWN5SWR0ABBMamF2YS9sYW5nL0xvbmc7TAAKc25hcHNob3RJZHEAfgACTAAIdm9sdW1lSWRxAH4AAkwAB3pvbmVJZHN0ABBMamF2YS91dGlsL0xpc3Q7eHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAOEAAAAAAAABKgAAAAAAABVidAAUVm9sdW1lQXBpU2VydmljZUltcGwAAHBzcgAOamF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHIAEGphdmEubGFuZy5OdW1iZXKGrJUdC5TgiwIAAHhwAAAAAAAAAABzcQB-AAgAAAAAAAADZnNxAH4ACAAAAAAAABgTcA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 108597816265214, completeMsid: null, lastUpdated: null, lastPolled: null, created: Thu Sep 26 17:21:41 MSK 2024, removed: null}
2024-09-26 17:21:42,579 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465) (logid:c8e45246) Run VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot for VM 5474, job origin: 72464
2024-09-26 17:21:42,581 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Execute VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot{"volumeId":6163,"policyId":0,"snapshotId":870,"quiesceVm":false,"asyncBackup":false,"userId":298,"accountId":225,"vmId":5474,"handlerName":"VolumeApiServiceImpl"}
2024-09-26 17:21:42,594 DEBUG [o.a.c.s.s.StorPoolSnapshotStrategy] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) StorpoolSnapshotStrategy.canHandle: snapshot=backup-test-karasev-9_ROOT-5474_20240926142141, uuid=7bdc207e-974e-41ed-a51f-f104bac1102c, op=TAKE
2024-09-26 17:21:42,632 DEBUG [o.a.c.s.d.d.CloudStackPrimaryDataStoreDriverImpl] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Taking snapshot of org.apache.cloudstack.storage.snapshot.SnapshotObject@4bd9bc84
2024-09-26 17:21:42,666 DEBUG [o.a.c.s.d.d.CloudStackPrimaryDataStoreDriverImpl] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Taking snapshot of org.apache.cloudstack.storage.snapshot.SnapshotObject@4bd9bc84 and encryption required is false
2024-09-26 17:21:42,666 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) getCommandHostDelegation: class org.apache.cloudstack.storage.command.CreateObjectCommand
2024-09-26 17:21:42,667 DEBUG [c.c.h.XenServerGuru] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) We are returning the default host to execute commands because the command is not of Copy type.
2024-09-26 17:21:42,670 DEBUG [c.c.a.t.Request] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Seq 77360-7409547286931430185: Sending  { Cmd , MgmtId: 108597816265214, via: 77360(xcp-sr246-u0708.aisrp.local), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"5e964ddb-3d14-4037-a241-12972ebc5354","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"name":"ROOT-5474","size":"(10.00 GB) 10737418240","path":"9c99b264-d618-4030-916b-1502ec5fadba","volumeId":"6163","vmName":"i-225-5474-VM","accountId":"225","format":"VHD","provisioningType":"THIN","poolId":"54","id":"6163","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"vmName":"i-225-5474-VM","name":"backup-test-karasev-9_ROOT-5474_20240926142141","hypervisorType":"XenServer","id":"870","quiescevm":"false","physicalSize":"0","accountId":"225","followRedirects":"false"}},"wait":"0","bypassHostMaintenance":"false"}}] }
2024-09-26 17:21:42,671 DEBUG [c.c.a.t.Request] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Seq 77360-7409547286931430185: Executing:  { Cmd , MgmtId: 108597816265214, via: 77360(xcp-sr246-u0708.aisrp.local), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"5e964ddb-3d14-4037-a241-12972ebc5354","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"name":"ROOT-5474","size":"(10.00 GB) 10737418240","path":"9c99b264-d618-4030-916b-1502ec5fadba","volumeId":"6163","vmName":"i-225-5474-VM","accountId":"225","format":"VHD","provisioningType":"THIN","poolId":"54","id":"6163","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"vmName":"i-225-5474-VM","name":"backup-test-karasev-9_ROOT-5474_20240926142141","hypervisorType":"XenServer","id":"870","quiescevm":"false","physicalSize":"0","accountId":"225","followRedirects":"false"}},"wait":"0","bypassHostMaintenance":"false"}}] }
2024-09-26 17:21:42,672 DEBUG [c.c.s.r.StorageSubsystemCommandHandlerBase] (DirectAgent-287:ctx-df71784d) (logid:c8e45246) Executing command CreateObjectCommand: [{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"5e964ddb-3d14-4037-a241-12972ebc5354","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":54,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":0,"url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":false}},"name":"ROOT-5474","size":10737418240,"path":"9c99b264-d618-4030-916b-1502ec5fadba","volumeId":6163,"vmName":"i-225-5474-VM","accountId":225,"format":"VHD","provisioningType":"THIN","poolId":54,"id":6163,"deviceId":0,"cacheMode":"NONE","hypervisorType":"XenServer","directDownload":false,"deployAsIs":false,"followRedirects":true},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":54,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":0,"url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":false}},"vmName":"i-225-5474-VM","name":"backup-test-karasev-9_ROOT-5474_20240926142141","hypervisorType":"XenServer","id":870,"quiescevm":false,"physicalSize":0,"accountId":225,"followRedirects":false}},"wait":0,"bypassHostMaintenance":false}].
2024-09-26 17:21:44,421 DEBUG [c.c.a.ApiServlet] (qtp501107890-4834338:ctx-38b579a2) (logid:2740bef9) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:21:44,446 DEBUG [c.c.a.ApiServlet] (qtp501107890-4834338:ctx-38b579a2 ctx-9d7b2d8d) (logid:2740bef9) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:21:47,537 DEBUG [c.c.a.ApiServlet] (qtp501107890-4834338:ctx-eb108eb7) (logid:25800034) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:21:47,561 DEBUG [c.c.a.ApiServlet] (qtp501107890-4834338:ctx-eb108eb7 ctx-d3852c77) (logid:25800034) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:21:50,671 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824845:ctx-95e72378) (logid:4e24b10a) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:21:50,693 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824845:ctx-95e72378 ctx-9321eab1) (logid:4e24b10a) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:21:53,779 DEBUG [c.c.a.ApiServlet] (qtp501107890-4821895:ctx-581ef07b) (logid:dca0df5b) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:21:53,811 DEBUG [c.c.a.ApiServlet] (qtp501107890-4821895:ctx-581ef07b ctx-69923e87) (logid:dca0df5b) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:21:56,898 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824845:ctx-cc466224) (logid:d706fc8d) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:21:56,926 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824845:ctx-cc466224 ctx-f28715e9) (logid:d706fc8d) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:21:57,319 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-287:ctx-df71784d) (logid:c8e45246) Seq 77360-7409547286931430185: Response Received:
2024-09-26 17:21:57,319 DEBUG [c.c.a.t.Request] (DirectAgent-287:ctx-df71784d) (logid:c8e45246) Seq 77360-7409547286931430185: Processing:  { Ans: , MgmtId: 108597816265214, via: 77360(xcp-sr246-u0708.aisrp.local), Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"d8f3d271-4b1d-4276-b4ea-390c3f82df57","id":"0","quiescevm":"false","physicalSize":"0","accountId":"0","followRedirects":"false"}},"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2024-09-26 17:21:57,319 DEBUG [c.c.a.t.Request] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Seq 77360-7409547286931430185: Received:  { Ans: , MgmtId: 108597816265214, via: 77360(xcp-sr246-u0708.aisrp.local), Ver: v1, Flags: 10, { CreateObjectAnswer } }
2024-09-26 17:21:57,377 DEBUG [o.a.c.s.h.HeuristicRuleHelper] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) No heuristic rules found for zone with ID [7] and heuristic type [SNAPSHOT]. Returning null.
2024-09-26 17:21:57,381 DEBUG [c.c.s.StatsCollector] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Verifying image storage [7]. Capacity: total=[785 GB], used=[243 GB], threshold=[89.99999761581421%].
2024-09-26 17:21:57,381 DEBUG [c.c.s.StatsCollector] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Verifying image storage [9]. Capacity: total=[785 GB], used=[72 GB], threshold=[89.99999761581421%].
2024-09-26 17:21:57,382 DEBUG [c.c.s.StatsCollector] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Verifying image storage [7]. Capacity: total=[785 GB], used=[243 GB], threshold=[89.99999761581421%].
2024-09-26 17:21:57,419 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) copyAsync inspecting src type SNAPSHOT copyAsync inspecting dest type SNAPSHOT
2024-09-26 17:21:57,529 ERROR [o.a.c.s.e.DefaultEndPointSelector] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) IR24 select BACKUPSNAPSHOT from primary to secondary 870 dest=870
2024-09-26 17:21:57,535 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) getCommandHostDelegation: class org.apache.cloudstack.storage.command.CopyCommand
2024-09-26 17:21:57,537 DEBUG [c.c.h.XenServerGuru] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) We are returning the default host to execute commands because the source and destination objects are not NFS type.
2024-09-26 17:21:57,540 DEBUG [c.c.a.t.Request] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Seq 77360-7409547286931430189: Sending  { Cmd , MgmtId: 108597816265214, via: 77360(xcp-sr246-u0708.aisrp.local), Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"d8f3d271-4b1d-4276-b4ea-390c3f82df57","volume":{"uuid":"5e964ddb-3d14-4037-a241-12972ebc5354","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"name":"ROOT-5474","size":"(10.00 GB) 10737418240","path":"9c99b264-d618-4030-916b-1502ec5fadba","volumeId":"6163","vmName":"i-225-5474-VM","accountId":"225","format":"VHD","provisioningType":"THIN","poolId":"54","id":"6163","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"vmName":"i-225-5474-VM","name":"backup-test-karasev-9_ROOT-5474_20240926142141","hypervisorType":"XenServer","id":"870","quiescevm":"false","physicalSize":"0","accountId":"225","followRedirects":"false"}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/225/6163","volume":{"uuid":"5e964ddb-3d14-4037-a241-12972ebc5354","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"name":"ROOT-5474","size":"(10.00 GB) 10737418240","path":"9c99b264-d618-4030-916b-1502ec5fadba","volumeId":"6163","vmName":"i-225-5474-VM","accountId":"225","format":"VHD","provisioningType":"THIN","poolId":"54","id":"6163","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.69.105.254/var/NFS","_role":"Image"}},"vmName":"i-225-5474-VM","name":"backup-test-karasev-9_ROOT-5474_20240926142141","hypervisorType":"XenServer","id":"870","quiescevm":"false","physicalSize":"0","accountId":"225","followRedirects":"false"}},"executeInSequence":"true","options":{"snapshot.backup.to.secondary":"true","fullSnapshot":"true"},"options2":{},"wait":"21600","bypassHostMaintenance":"false"}}] }
2024-09-26 17:21:57,562 DEBUG [c.c.a.t.Request] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Seq 77360-7409547286931430189: Executing:  { Cmd , MgmtId: 108597816265214, via: 77360(xcp-sr246-u0708.aisrp.local), Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"d8f3d271-4b1d-4276-b4ea-390c3f82df57","volume":{"uuid":"5e964ddb-3d14-4037-a241-12972ebc5354","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"name":"ROOT-5474","size":"(10.00 GB) 10737418240","path":"9c99b264-d618-4030-916b-1502ec5fadba","volumeId":"6163","vmName":"i-225-5474-VM","accountId":"225","format":"VHD","provisioningType":"THIN","poolId":"54","id":"6163","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"vmName":"i-225-5474-VM","name":"backup-test-karasev-9_ROOT-5474_20240926142141","hypervisorType":"XenServer","id":"870","quiescevm":"false","physicalSize":"0","accountId":"225","followRedirects":"false"}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/225/6163","volume":{"uuid":"5e964ddb-3d14-4037-a241-12972ebc5354","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"name":"ROOT-5474","size":"(10.00 GB) 10737418240","path":"9c99b264-d618-4030-916b-1502ec5fadba","volumeId":"6163","vmName":"i-225-5474-VM","accountId":"225","format":"VHD","provisioningType":"THIN","poolId":"54","id":"6163","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.69.105.254/var/NFS","_role":"Image"}},"vmName":"i-225-5474-VM","name":"backup-test-karasev-9_ROOT-5474_20240926142141","hypervisorType":"XenServer","id":"870","quiescevm":"false","physicalSize":"0","accountId":"225","followRedirects":"false"}},"executeInSequence":"true","options":{"snapshot.backup.to.secondary":"true","fullSnapshot":"true"},"options2":{},"wait":"21600","bypassHostMaintenance":"false"}}] }
2024-09-26 17:21:57,562 DEBUG [c.c.s.r.StorageSubsystemCommandHandlerBase] (DirectAgent-366:ctx-f42b18d7) (logid:c8e45246) Executing command CopyCommand: [{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"d8f3d271-4b1d-4276-b4ea-390c3f82df57","volume":{"uuid":"5e964ddb-3d14-4037-a241-12972ebc5354","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":54,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":0,"url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":false}},"name":"ROOT-5474","size":10737418240,"path":"9c99b264-d618-4030-916b-1502ec5fadba","volumeId":6163,"vmName":"i-225-5474-VM","accountId":225,"format":"VHD","provisioningType":"THIN","poolId":54,"id":6163,"deviceId":0,"cacheMode":"NONE","hypervisorType":"XenServer","directDownload":false,"deployAsIs":false,"followRedirects":true},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":54,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":0,"url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":false}},"vmName":"i-225-5474-VM","name":"backup-test-karasev-9_ROOT-5474_20240926142141","hypervisorType":"XenServer","id":870,"quiescevm":false,"physicalSize":0,"accountId":225,"followRedirects":false}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/225/6163","volume":{"uuid":"5e964ddb-3d14-4037-a241-12972ebc5354","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":54,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":0,"url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":false}},"name":"ROOT-5474","size":10737418240,"path":"9c99b264-d618-4030-916b-1502ec5fadba","volumeId":6163,"vmName":"i-225-5474-VM","accountId":225,"format":"VHD","provisioningType":"THIN","poolId":54,"id":6163,"deviceId":0,"cacheMode":"NONE","hypervisorType":"XenServer","directDownload":false,"deployAsIs":false,"followRedirects":true},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.69.105.254/var/NFS","_role":"Image"}},"vmName":"i-225-5474-VM","name":"backup-test-karasev-9_ROOT-5474_20240926142141","hypervisorType":"XenServer","id":870,"quiescevm":false,"physicalSize":0,"accountId":225,"followRedirects":false}},"executeInSequence":true,"options":{"snapshot.backup.to.secondary":"true","fullSnapshot":"true"},"options2":{},"wait":21600,"bypassHostMaintenance":false}].
2024-09-26 17:21:59,970 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-366:ctx-f42b18d7) (logid:c8e45246) No file SR found for path: /var/cloud_mount/440acca8-622d-3dfb-825d-b3e62d7bba87/snapshots/225/6163
2024-09-26 17:21:59,970 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-366:ctx-f42b18d7) (logid:c8e45246) Creating file SR for path [/var/cloud_mount/440acca8-622d-3dfb-825d-b3e62d7bba87/snapshots/225/6163] on host [7fe64564-c05c-4425-8436-ec2da15f740a]
2024-09-26 17:22:00,006 DEBUG [c.c.a.ApiServlet] (qtp501107890-4832815:ctx-29b0404b) (logid:360fad58) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:00,032 DEBUG [c.c.a.ApiServlet] (qtp501107890-4832815:ctx-29b0404b ctx-d7854f91) (logid:360fad58) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:03,119 DEBUG [c.c.a.ApiServlet] (qtp501107890-4834338:ctx-c04fc898) (logid:2219e417) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:03,142 DEBUG [c.c.a.ApiServlet] (qtp501107890-4834338:ctx-c04fc898 ctx-fec4282e) (logid:2219e417) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:06,257 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824845:ctx-63120037) (logid:8a9b8304) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:06,280 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824845:ctx-63120037 ctx-6adff946) (logid:8a9b8304) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:09,402 DEBUG [c.c.a.ApiServlet] (qtp501107890-4832815:ctx-b3166a90) (logid:b7878727) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:09,424 DEBUG [c.c.a.ApiServlet] (qtp501107890-4832815:ctx-b3166a90 ctx-af252453) (logid:b7878727) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:12,536 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824845:ctx-5e16f60d) (logid:ed82faf7) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:12,559 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824845:ctx-5e16f60d ctx-021e66d4) (logid:ed82faf7) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:15,663 DEBUG [c.c.a.ApiServlet] (qtp501107890-4821895:ctx-516e5765) (logid:a4ec32b9) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:15,686 DEBUG [c.c.a.ApiServlet] (qtp501107890-4821895:ctx-516e5765 ctx-f115c344) (logid:a4ec32b9) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:18,799 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824844:ctx-b60f4585) (logid:253c7fb4) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:18,822 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824844:ctx-b60f4585 ctx-cd2c67ed) (logid:253c7fb4) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:21,936 DEBUG [c.c.a.ApiServlet] (qtp501107890-4821895:ctx-863d8a59) (logid:08b2e49f) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:21,959 DEBUG [c.c.a.ApiServlet] (qtp501107890-4821895:ctx-863d8a59 ctx-95f1425b) (logid:08b2e49f) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:25,071 DEBUG [c.c.a.ApiServlet] (qtp501107890-4821895:ctx-6e2f29f1) (logid:724bb944) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:25,094 DEBUG [c.c.a.ApiServlet] (qtp501107890-4821895:ctx-6e2f29f1 ctx-fbc38980) (logid:724bb944) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:27,025 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-366:ctx-f42b18d7) (logid:c8e45246) Host 10.69.105.21 OpaqueRef:ff865e44-ce8f-4670-b990-855700769647: Removing SR
2024-09-26 17:22:27,038 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-366:ctx-f42b18d7) (logid:c8e45246) Host 10.69.105.21 OpaqueRef:d5a56d3b-f5af-461e-bee4-b387938e18fe: Unplugging pbd
2024-09-26 17:22:27,449 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-366:ctx-f42b18d7) (logid:c8e45246) Host 10.69.105.21 OpaqueRef:ff865e44-ce8f-4670-b990-855700769647: Forgetting
2024-09-26 17:22:27,454 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-366:ctx-f42b18d7) (logid:c8e45246) Successfully destroyed snapshot on volume: 9c99b264-d618-4030-916b-1502ec5fadba execept this current snapshot d8f3d271-4b1d-4276-b4ea-390c3f82df57
2024-09-26 17:22:27,454 INFO  [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-366:ctx-f42b18d7) (logid:c8e45246) New snapshot details: SnapshotTO[datastore=null|volume=null|pathsnapshots/225/6163/07116d77-9286-4eaa-9e40-f4b754def19f.vhd]
2024-09-26 17:22:27,455 INFO  [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-366:ctx-f42b18d7) (logid:c8e45246) New snapshot physical utilization: (5.46 GB) 5866705408
2024-09-26 17:22:27,455 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-366:ctx-f42b18d7) (logid:c8e45246) Seq 77360-7409547286931430189: Response Received:
2024-09-26 17:22:27,455 DEBUG [c.c.a.t.Request] (DirectAgent-366:ctx-f42b18d7) (logid:c8e45246) Seq 77360-7409547286931430189: Processing:  { Ans: , MgmtId: 108597816265214, via: 77360(xcp-sr246-u0708.aisrp.local), Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/225/6163/07116d77-9286-4eaa-9e40-f4b754def19f.vhd","id":"0","quiescevm":"false","physicalSize":"5866705408","accountId":"0","followRedirects":"false"}},"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2024-09-26 17:22:27,455 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-366:ctx-f42b18d7) (logid:c8e45246) Seq 77360-7409547286931430189: No more commands found
2024-09-26 17:22:27,455 DEBUG [c.c.a.t.Request] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Seq 77360-7409547286931430189: Received:  { Ans: , MgmtId: 108597816265214, via: 77360(xcp-sr246-u0708.aisrp.local), Ver: v1, Flags: 110, { CopyCmdAnswer } }
2024-09-26 17:22:27,491 DEBUG [c.c.r.ResourceLimitManagerImpl] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Updating resource Type = secondary_storage count for Account = 225 Operation = decreasing Amount = (4.54 GB) 4870712832
2024-09-26 17:22:27,499 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Done executing VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot{"volumeId":6163,"policyId":0,"snapshotId":870,"quiesceVm":false,"asyncBackup":false,"userId":298,"accountId":225,"vmId":5474,"handlerName":"VolumeApiServiceImpl"}
2024-09-26 17:22:27,500 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Complete async job-72465, jobStatus: SUCCEEDED, resultCode: 0, result: rO0ABXNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgABSgAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAAAAAAAADZg
2024-09-26 17:22:27,501 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Publish async job-72465 complete on message bus
2024-09-26 17:22:27,501 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Wake up jobs related to job-72465
2024-09-26 17:22:27,501 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Update db status for job-72465
2024-09-26 17:22:27,502 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465 ctx-75e57019) (logid:c8e45246) Wake up jobs joined with job-72465 and disjoin all subjobs created from job- 72465
2024-09-26 17:22:27,509 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465) (logid:c8e45246) Done with run of VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot for VM 5474, job origin: 72464
2024-09-26 17:22:27,509 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465) (logid:c8e45246) Done executing com.cloud.vm.VmWorkTakeVolumeSnapshot for job-72465
2024-09-26 17:22:27,511 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-152:ctx-2271fcd8 job-72464/job-72465) (logid:c8e45246) Remove job-72465 from job monitoring
2024-09-26 17:22:27,545 DEBUG [o.a.c.s.s.StorPoolSnapshotStrategy] (API-Job-Executor-63:ctx-968ed109 job-72464 ctx-7ca9e6a7) (logid:c8e45246) StorpoolSnapshotStrategy.canHandle: snapshot=backup-test-karasev-9_ROOT-5474_20240926142141, uuid=7bdc207e-974e-41ed-a51f-f104bac1102c, op=REVERT
2024-09-26 17:22:27,549 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-968ed109 job-72464 ctx-7ca9e6a7) (logid:c8e45246) Complete async job-72464, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.SnapshotResponse/snapshot/{"id":"7bdc207e-974e-41ed-a51f-f104bac1102c","account":"karasev-cluster5","domainid":"ce7e4a4a-75b6-4c96-938c-fe3158da9a47","domain":"cluster5","snapshottype":"MANUAL","volumeid":"5e964ddb-3d14-4037-a241-12972ebc5354","volumename":"ROOT-5474","volumetype":"ROOT","created":"2024-09-26T17:21:41+0300","name":"backup-test-karasev-9_ROOT-5474_20240926142141","intervaltype":"MANUAL","state":"BackedUp","physicalsize":"5866705408","zoneid":"9505445a-7164-4675-876d-1a2fee1f7e46","zonename":"xcp-zone-02","revertable":"false","ostypeid":"7b53b54f-d3d2-409f-b9b0-acd39122368a","osdisplayname":"Ubuntu 22.04 LTS","virtualsize":"10737418240","tags":[],"hasannotations":"false"}
2024-09-26 17:22:27,550 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-968ed109 job-72464 ctx-7ca9e6a7) (logid:c8e45246) Publish async job-72464 complete on message bus
2024-09-26 17:22:27,550 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-968ed109 job-72464 ctx-7ca9e6a7) (logid:c8e45246) Wake up jobs related to job-72464
2024-09-26 17:22:27,550 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-968ed109 job-72464 ctx-7ca9e6a7) (logid:c8e45246) Update db status for job-72464
2024-09-26 17:22:27,551 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-968ed109 job-72464 ctx-7ca9e6a7) (logid:c8e45246) Wake up jobs joined with job-72464 and disjoin all subjobs created from job- 72464
2024-09-26 17:22:27,555 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-63:ctx-968ed109 job-72464) (logid:c8e45246) Done executing org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd for job-72464
2024-09-26 17:22:27,555 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-63:ctx-968ed109 job-72464) (logid:c8e45246) Remove job-72464 from job monitoring
2024-09-26 17:22:28,208 DEBUG [c.c.a.ApiServlet] (qtp501107890-4834306:ctx-41f1ef09) (logid:5789c854) ===START===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json
2024-09-26 17:22:28,238 DEBUG [c.c.a.ApiServlet] (qtp501107890-4834306:ctx-41f1ef09 ctx-be04a227) (logid:5789c854) ===END===  172.16.11.61 -- GET  jobId=c8e45246-57d3-4238-8cf1-6b7fa887c144&command=queryAsyncJobResult&response=json

0 replies

top-secrett · 2024-09-26T14:40:05Z

top-secrett
Sep 26, 2024
Author

Example when first volume snapshot was copied to the second secstore and I try to create the next volume snapshot

2024-09-26 16:58:32,135 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-58:ctx-c9d433a7 job-72454) (logid:f365dd96) Executing AsyncJobVO: {id:72454, userId: 298, accountId: 225, instanceType: Snapshot, instanceId: 867, cmd: org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd, cmdInfo: {"asyncBackup":"false","quiescevm":"false","response":"json","ctxUserId":"298","volumeId":"da420806-0ff3-43b8-9ee0-4aa2adfd9b99","httpmethod":"GET","ctxStartEventId":"1811467","id":"867","ctxDetails":"{\"interface com.cloud.storage.Volume\":\"da420806-0ff3-43b8-9ee0-4aa2adfd9b99\",\"interface com.cloud.storage.Snapshot\":\"c62b0aa0-5a1c-475c-b7f6-6c9fab17e325\"}","ctxAccountId":"225","uuid":"c62b0aa0-5a1c-475c-b7f6-6c9fab17e325","cmdEventType":"SNAPSHOT.CREATE"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 108597816265214, completeMsid: null, lastUpdated: null, lastPolled: null, created: null, removed: null}
2024-09-26 16:58:32,147 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-58:ctx-c9d433a7 job-72454 ctx-829ed64e) (logid:f365dd96) Access to Account [{"accountName":"karasev-cluster5","id":225,"uuid":"fd32d818-5d3b-4d3c-9084-34704beefaf5"}] granted to Account [{"accountName":"karasev-cluster5","id":225,"uuid":"fd32d818-5d3b-4d3c-9084-34704beefaf5"}] by DomainChecker
2024-09-26 16:58:32,167 DEBUG [c.c.a.ApiServlet] (qtp501107890-4830812:ctx-4bacce10) (logid:11a55db0) ===START===  172.16.11.61 -- GET  jobId=f365dd96-c018-454a-874c-37dce9396d96&command=queryAsyncJobResult&response=json
2024-09-26 16:58:32,183 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-58:ctx-c9d433a7 job-72454 ctx-829ed64e) (logid:f365dd96) Access to org.apache.cloudstack.storage.volume.VolumeObject@f1e18b7 granted to Account [{"accountName":"karasev-cluster5","id":225,"uuid":"fd32d818-5d3b-4d3c-9084-34704beefaf5"}] by DomainChecker
2024-09-26 16:58:32,190 DEBUG [c.c.a.ApiServlet] (qtp501107890-4830812:ctx-4bacce10 ctx-aa1d9072) (logid:11a55db0) ===END===  172.16.11.61 -- GET  jobId=f365dd96-c018-454a-874c-37dce9396d96&command=queryAsyncJobResult&response=json
2024-09-26 16:58:32,192 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-58:ctx-c9d433a7 job-72454 ctx-829ed64e) (logid:f365dd96) Access to VM instance {"id":5468,"instanceName":"i-225-5468-VM","type":"User","uuid":"d1e26871-d01f-44cc-ac61-f19f46ed741a"} granted to Account [{"accountName":"karasev-cluster5","id":225,"uuid":"fd32d818-5d3b-4d3c-9084-34704beefaf5"}] by DomainChecker
2024-09-26 16:58:32,206 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-58:ctx-c9d433a7 job-72454 ctx-829ed64e) (logid:f365dd96) Sync job-72455 execution on object VmWorkJobQueue.5468
2024-09-26 16:58:32,575 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455) (logid:f365dd96) Executing AsyncJobVO: {id:72455, userId: 298, accountId: 225, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkTakeVolumeSnapshot, cmdInfo: rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrVGFrZVZvbHVtZVNuYXBzaG90BL5gG4Li1c8CAAdaAAthc3luY0JhY2t1cFoACXF1aWVzY2VWbUwADGxvY2F0aW9uVHlwZXQAKUxjb20vY2xvdWQvc3RvcmFnZS9TbmFwc2hvdCRMb2NhdGlvblR5cGU7TAAIcG9saWN5SWR0ABBMamF2YS9sYW5nL0xvbmc7TAAKc25hcHNob3RJZHEAfgACTAAIdm9sdW1lSWRxAH4AAkwAB3pvbmVJZHN0ABBMamF2YS91dGlsL0xpc3Q7eHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAOEAAAAAAAABKgAAAAAAABVcdAAUVm9sdW1lQXBpU2VydmljZUltcGwAAHBzcgAOamF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHIAEGphdmEubGFuZy5OdW1iZXKGrJUdC5TgiwIAAHhwAAAAAAAAAABzcQB-AAgAAAAAAAADY3NxAH4ACAAAAAAAABgMcA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 108597816265214, completeMsid: null, lastUpdated: null, lastPolled: null, created: Thu Sep 26 16:58:32 MSK 2024, removed: null}
2024-09-26 16:58:32,575 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455) (logid:f365dd96) Run VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot for VM 5468, job origin: 72454
2024-09-26 16:58:32,576 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Execute VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot{"volumeId":6156,"policyId":0,"snapshotId":867,"quiesceVm":false,"asyncBackup":false,"userId":298,"accountId":225,"vmId":5468,"handlerName":"VolumeApiServiceImpl"}
2024-09-26 16:58:32,588 DEBUG [o.a.c.s.s.StorPoolSnapshotStrategy] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) StorpoolSnapshotStrategy.canHandle: snapshot=backup-test-karasev-3_ROOT-5468_20240926135832, uuid=c62b0aa0-5a1c-475c-b7f6-6c9fab17e325, op=TAKE
2024-09-26 16:58:32,622 DEBUG [o.a.c.s.d.d.CloudStackPrimaryDataStoreDriverImpl] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Taking snapshot of org.apache.cloudstack.storage.snapshot.SnapshotObject@18f701c2
2024-09-26 16:58:32,653 DEBUG [o.a.c.s.d.d.CloudStackPrimaryDataStoreDriverImpl] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Taking snapshot of org.apache.cloudstack.storage.snapshot.SnapshotObject@18f701c2 and encryption required is false
2024-09-26 16:58:32,653 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) getCommandHostDelegation: class org.apache.cloudstack.storage.command.CreateObjectCommand
2024-09-26 16:58:32,655 DEBUG [c.c.h.XenServerGuru] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) We are returning the default host to execute commands because the command is not of Copy type.
2024-09-26 16:58:32,657 DEBUG [c.c.a.t.Request] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Seq 77353-4517673376206130891: Sending  { Cmd , MgmtId: 108597816265214, via: 77353(xcp-sr246-u1314.aisrp.local), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"da420806-0ff3-43b8-9ee0-4aa2adfd9b99","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":"53","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":"0","url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":"false"}},"name":"ROOT-5468","size":"(20.00 GB) 21474836480","path":"9e2a4d6e-3ab8-46f4-85cf-c7454fc9ea17","volumeId":"6156","vmName":"i-225-5468-VM","accountId":"225","format":"VHD","provisioningType":"THIN","poolId":"53","id":"6156","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"parentSnapshotPath":"70424963-5933-4e73-b185-cfdc402175cd","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":"53","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":"0","url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":"false"}},"vmName":"i-225-5468-VM","name":"backup-test-karasev-3_ROOT-5468_20240926135832","hypervisorType":"XenServer","id":"867","quiescevm":"false","parents":["70424963-5933-4e73-b185-cfdc402175cd"],"physicalSize":"0","accountId":"225","followRedirects":"false"}},"wait":"0","bypassHostMaintenance":"false"}}] }
2024-09-26 16:58:32,659 DEBUG [c.c.a.t.Request] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Seq 77353-4517673376206130891: Executing:  { Cmd , MgmtId: 108597816265214, via: 77353(xcp-sr246-u1314.aisrp.local), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"da420806-0ff3-43b8-9ee0-4aa2adfd9b99","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":"53","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":"0","url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":"false"}},"name":"ROOT-5468","size":"(20.00 GB) 21474836480","path":"9e2a4d6e-3ab8-46f4-85cf-c7454fc9ea17","volumeId":"6156","vmName":"i-225-5468-VM","accountId":"225","format":"VHD","provisioningType":"THIN","poolId":"53","id":"6156","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"parentSnapshotPath":"70424963-5933-4e73-b185-cfdc402175cd","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":"53","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":"0","url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":"false"}},"vmName":"i-225-5468-VM","name":"backup-test-karasev-3_ROOT-5468_20240926135832","hypervisorType":"XenServer","id":"867","quiescevm":"false","parents":["70424963-5933-4e73-b185-cfdc402175cd"],"physicalSize":"0","accountId":"225","followRedirects":"false"}},"wait":"0","bypassHostMaintenance":"false"}}] }
2024-09-26 16:58:32,659 DEBUG [c.c.s.r.StorageSubsystemCommandHandlerBase] (DirectAgent-128:ctx-052ce805) (logid:f365dd96) Executing command CreateObjectCommand: [{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"da420806-0ff3-43b8-9ee0-4aa2adfd9b99","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":53,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":0,"url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":false}},"name":"ROOT-5468","size":21474836480,"path":"9e2a4d6e-3ab8-46f4-85cf-c7454fc9ea17","volumeId":6156,"vmName":"i-225-5468-VM","accountId":225,"format":"VHD","provisioningType":"THIN","poolId":53,"id":6156,"deviceId":0,"cacheMode":"NONE","hypervisorType":"XenServer","directDownload":false,"deployAsIs":false,"followRedirects":true},"parentSnapshotPath":"70424963-5933-4e73-b185-cfdc402175cd","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":53,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":0,"url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":false}},"vmName":"i-225-5468-VM","name":"backup-test-karasev-3_ROOT-5468_20240926135832","hypervisorType":"XenServer","id":867,"quiescevm":false,"parents":["70424963-5933-4e73-b185-cfdc402175cd"],"physicalSize":0,"accountId":225,"followRedirects":false}},"wait":0,"bypassHostMaintenance":false}].
2024-09-26 16:58:35,268 DEBUG [c.c.a.ApiServlet] (qtp501107890-4820302:ctx-f711cc5b) (logid:4e44467e) ===START===  172.16.11.61 -- GET  jobId=f365dd96-c018-454a-874c-37dce9396d96&command=queryAsyncJobResult&response=json
2024-09-26 16:58:35,290 DEBUG [c.c.a.ApiServlet] (qtp501107890-4820302:ctx-f711cc5b ctx-e8b6659b) (logid:4e44467e) ===END===  172.16.11.61 -- GET  jobId=f365dd96-c018-454a-874c-37dce9396d96&command=queryAsyncJobResult&response=json
2024-09-26 16:58:38,370 DEBUG [c.c.a.ApiServlet] (qtp501107890-4830812:ctx-fd303fe2) (logid:ef8914d8) ===START===  172.16.11.61 -- GET  jobId=f365dd96-c018-454a-874c-37dce9396d96&command=queryAsyncJobResult&response=json
2024-09-26 16:58:38,394 DEBUG [c.c.a.ApiServlet] (qtp501107890-4830812:ctx-fd303fe2 ctx-aec37e2b) (logid:ef8914d8) ===END===  172.16.11.61 -- GET  jobId=f365dd96-c018-454a-874c-37dce9396d96&command=queryAsyncJobResult&response=json
2024-09-26 16:58:39,977 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-128:ctx-052ce805) (logid:f365dd96) Seq 77353-4517673376206130891: Response Received:
2024-09-26 16:58:39,977 DEBUG [c.c.a.t.Request] (DirectAgent-128:ctx-052ce805) (logid:f365dd96) Seq 77353-4517673376206130891: Processing:  { Ans: , MgmtId: 108597816265214, via: 77353(xcp-sr246-u1314.aisrp.local), Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"e1971e58-5b6e-4f59-a256-154280cf4d16","id":"0","quiescevm":"false","physicalSize":"0","accountId":"0","followRedirects":"false"}},"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2024-09-26 16:58:39,977 DEBUG [c.c.a.t.Request] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Seq 77353-4517673376206130891: Received:  { Ans: , MgmtId: 108597816265214, via: 77353(xcp-sr246-u1314.aisrp.local), Ver: v1, Flags: 10, { CreateObjectAnswer } }
2024-09-26 16:58:40,045 DEBUG [o.a.c.s.h.HeuristicRuleHelper] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) No heuristic rules found for zone with ID [7] and heuristic type [SNAPSHOT]. Returning null.
2024-09-26 16:58:40,049 DEBUG [c.c.s.StatsCollector] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Verifying image storage [7]. Capacity: total=[785 GB], used=[243 GB], threshold=[89.99999761581421%].
2024-09-26 16:58:40,050 DEBUG [c.c.s.StatsCollector] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Verifying image storage [9]. Capacity: total=[785 GB], used=[70 GB], threshold=[89.99999761581421%].
2024-09-26 16:58:40,051 DEBUG [c.c.s.StatsCollector] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Verifying image storage [7]. Capacity: total=[785 GB], used=[243 GB], threshold=[89.99999761581421%].
2024-09-26 16:58:40,101 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) copyAsync inspecting src type SNAPSHOT copyAsync inspecting dest type SNAPSHOT
2024-09-26 16:58:40,224 ERROR [o.a.c.s.e.DefaultEndPointSelector] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) IR24 select BACKUPSNAPSHOT from primary to secondary 867 dest=867
2024-09-26 16:58:40,236 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) getCommandHostDelegation: class org.apache.cloudstack.storage.command.CopyCommand
2024-09-26 16:58:40,238 DEBUG [c.c.h.XenServerGuru] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) We are returning the default host to execute commands because the source and destination objects are not NFS type.
2024-09-26 16:58:40,243 DEBUG [c.c.a.t.Request] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Seq 77358-1940207014466653252: Sending  { Cmd , MgmtId: 108597816265214, via: 77358(xcp-sr246-u1112.aisrp.local), Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"e1971e58-5b6e-4f59-a256-154280cf4d16","volume":{"uuid":"da420806-0ff3-43b8-9ee0-4aa2adfd9b99","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":"53","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":"0","url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":"false"}},"name":"ROOT-5468","size":"(20.00 GB) 21474836480","path":"9e2a4d6e-3ab8-46f4-85cf-c7454fc9ea17","volumeId":"6156","vmName":"i-225-5468-VM","accountId":"225","format":"VHD","provisioningType":"THIN","poolId":"53","id":"6156","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"parentSnapshotPath":"70424963-5933-4e73-b185-cfdc402175cd","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":"53","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":"0","url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":"false"}},"vmName":"i-225-5468-VM","name":"backup-test-karasev-3_ROOT-5468_20240926135832","hypervisorType":"XenServer","id":"867","quiescevm":"false","parents":["70424963-5933-4e73-b185-cfdc402175cd"],"physicalSize":"0","accountId":"225","followRedirects":"false"}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/225/6156","volume":{"uuid":"da420806-0ff3-43b8-9ee0-4aa2adfd9b99","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":"53","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":"0","url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":"false"}},"name":"ROOT-5468","size":"(20.00 GB) 21474836480","path":"9e2a4d6e-3ab8-46f4-85cf-c7454fc9ea17","volumeId":"6156","vmName":"i-225-5468-VM","accountId":"225","format":"VHD","provisioningType":"THIN","poolId":"53","id":"6156","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.69.105.254/var/NFS","_role":"Image"}},"vmName":"i-225-5468-VM","name":"backup-test-karasev-3_ROOT-5468_20240926135832","hypervisorType":"XenServer","id":"867","quiescevm":"false","physicalSize":"0","accountId":"225","followRedirects":"false"}},"executeInSequence":"true","options":{"snapshot.backup.to.secondary":"true","fullSnapshot":"false"},"options2":{},"wait":"21600","bypassHostMaintenance":"false"}}] }
2024-09-26 16:58:40,245 DEBUG [c.c.a.t.Request] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Seq 77358-1940207014466653252: Executing:  { Cmd , MgmtId: 108597816265214, via: 77358(xcp-sr246-u1112.aisrp.local), Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"e1971e58-5b6e-4f59-a256-154280cf4d16","volume":{"uuid":"da420806-0ff3-43b8-9ee0-4aa2adfd9b99","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":"53","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":"0","url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":"false"}},"name":"ROOT-5468","size":"(20.00 GB) 21474836480","path":"9e2a4d6e-3ab8-46f4-85cf-c7454fc9ea17","volumeId":"6156","vmName":"i-225-5468-VM","accountId":"225","format":"VHD","provisioningType":"THIN","poolId":"53","id":"6156","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"parentSnapshotPath":"70424963-5933-4e73-b185-cfdc402175cd","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":"53","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":"0","url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":"false"}},"vmName":"i-225-5468-VM","name":"backup-test-karasev-3_ROOT-5468_20240926135832","hypervisorType":"XenServer","id":"867","quiescevm":"false","parents":["70424963-5933-4e73-b185-cfdc402175cd"],"physicalSize":"0","accountId":"225","followRedirects":"false"}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/225/6156","volume":{"uuid":"da420806-0ff3-43b8-9ee0-4aa2adfd9b99","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":"53","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":"0","url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":"false"}},"name":"ROOT-5468","size":"(20.00 GB) 21474836480","path":"9e2a4d6e-3ab8-46f4-85cf-c7454fc9ea17","volumeId":"6156","vmName":"i-225-5468-VM","accountId":"225","format":"VHD","provisioningType":"THIN","poolId":"53","id":"6156","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.69.105.254/var/NFS","_role":"Image"}},"vmName":"i-225-5468-VM","name":"backup-test-karasev-3_ROOT-5468_20240926135832","hypervisorType":"XenServer","id":"867","quiescevm":"false","physicalSize":"0","accountId":"225","followRedirects":"false"}},"executeInSequence":"true","options":{"snapshot.backup.to.secondary":"true","fullSnapshot":"false"},"options2":{},"wait":"21600","bypassHostMaintenance":"false"}}] }
2024-09-26 16:58:40,246 DEBUG [c.c.s.r.StorageSubsystemCommandHandlerBase] (DirectAgent-322:ctx-abb19c96) (logid:f365dd96) Executing command CopyCommand: [{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"e1971e58-5b6e-4f59-a256-154280cf4d16","volume":{"uuid":"da420806-0ff3-43b8-9ee0-4aa2adfd9b99","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":53,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":0,"url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":false}},"name":"ROOT-5468","size":21474836480,"path":"9e2a4d6e-3ab8-46f4-85cf-c7454fc9ea17","volumeId":6156,"vmName":"i-225-5468-VM","accountId":225,"format":"VHD","provisioningType":"THIN","poolId":53,"id":6156,"deviceId":0,"cacheMode":"NONE","hypervisorType":"XenServer","directDownload":false,"deployAsIs":false,"followRedirects":true},"parentSnapshotPath":"70424963-5933-4e73-b185-cfdc402175cd","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":53,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":0,"url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":false}},"vmName":"i-225-5468-VM","name":"backup-test-karasev-3_ROOT-5468_20240926135832","hypervisorType":"XenServer","id":867,"quiescevm":false,"parents":["70424963-5933-4e73-b185-cfdc402175cd"],"physicalSize":0,"accountId":225,"followRedirects":false}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/225/6156","volume":{"uuid":"da420806-0ff3-43b8-9ee0-4aa2adfd9b99","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN3","name":"cluster5-dm7100_lun3","id":53,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN3","port":0,"url":"PreSetup://localhost/DM7100_LUN3/?ROLE=Primary&STOREUUID=DM7100_LUN3","isManaged":false}},"name":"ROOT-5468","size":21474836480,"path":"9e2a4d6e-3ab8-46f4-85cf-c7454fc9ea17","volumeId":6156,"vmName":"i-225-5468-VM","accountId":225,"format":"VHD","provisioningType":"THIN","poolId":53,"id":6156,"deviceId":0,"cacheMode":"NONE","hypervisorType":"XenServer","directDownload":false,"deployAsIs":false,"followRedirects":true},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.69.105.254/var/NFS","_role":"Image"}},"vmName":"i-225-5468-VM","name":"backup-test-karasev-3_ROOT-5468_20240926135832","hypervisorType":"XenServer","id":867,"quiescevm":false,"physicalSize":0,"accountId":225,"followRedirects":false}},"executeInSequence":true,"options":{"snapshot.backup.to.secondary":"true","fullSnapshot":"false"},"options2":{},"wait":21600,"bypassHostMaintenance":false}].
2024-09-26 16:58:41,264 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-322:ctx-abb19c96) (logid:f365dd96) No file SR found for path: /var/cloud_mount/440acca8-622d-3dfb-825d-b3e62d7bba87/snapshots/225/6156
2024-09-26 16:58:41,264 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-322:ctx-abb19c96) (logid:f365dd96) Creating file SR for path [/var/cloud_mount/440acca8-622d-3dfb-825d-b3e62d7bba87/snapshots/225/6156] on host [4208d709-b553-47c0-aee2-7942d370b70c]
2024-09-26 16:58:41,495 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824844:ctx-107e93ec) (logid:1bc5742a) ===START===  172.16.11.61 -- GET  jobId=f365dd96-c018-454a-874c-37dce9396d96&command=queryAsyncJobResult&response=json
2024-09-26 16:58:41,518 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824844:ctx-107e93ec ctx-f58fcdf2) (logid:1bc5742a) ===END===  172.16.11.61 -- GET  jobId=f365dd96-c018-454a-874c-37dce9396d96&command=queryAsyncJobResult&response=json
2024-09-26 16:58:41,520 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-322:ctx-abb19c96) (logid:f365dd96) Unpluging PBD [c9ae6161-7db8-f308-db93-4fa060c94f9c] of SR [f6204e02-6efe-3005-95a3-095f19b458ac] as it is not working properly.
2024-09-26 16:58:41,536 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-322:ctx-abb19c96) (logid:f365dd96) Forgetting SR [f6204e02-6efe-3005-95a3-095f19b458ac] as it is not working properly.
2024-09-26 16:58:41,617 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-322:ctx-abb19c96) (logid:f365dd96) Could not create file SR [/var/cloud_mount/440acca8-622d-3dfb-825d-b3e62d7bba87/snapshots/225/6156] on host [4208d709-b553-47c0-aee2-7942d370b70c].
2024-09-26 16:58:41,617 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-322:ctx-abb19c96) (logid:f365dd96) Exception in backupsnapshot stage due to com.cloud.utils.exception.CloudRuntimeException: Could not retrieve an already used file SR for path [/var/cloud_mount/440acca8-622d-3dfb-825d-b3e62d7bba87/snapshots/225/6156] or create a new file SR on host [4208d709-b553-47c0-aee2-7942d370b70c]
2024-09-26 16:58:41,617 WARN  [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-322:ctx-abb19c96) (logid:f365dd96) BackupSnapshot Failed due to Exception in backupsnapshot stage due to com.cloud.utils.exception.CloudRuntimeException: Could not retrieve an already used file SR for path [/var/cloud_mount/440acca8-622d-3dfb-825d-b3e62d7bba87/snapshots/225/6156] or create a new file SR on host [4208d709-b553-47c0-aee2-7942d370b70c]
2024-09-26 16:58:44,625 DEBUG [c.c.a.ApiServlet] (qtp501107890-4825573:ctx-e72bd43c) (logid:d5a19d4e) ===START===  172.16.11.61 -- GET  jobId=f365dd96-c018-454a-874c-37dce9396d96&command=queryAsyncJobResult&response=json
2024-09-26 16:58:44,651 DEBUG [c.c.a.ApiServlet] (qtp501107890-4825573:ctx-e72bd43c ctx-707eaf3e) (logid:d5a19d4e) ===END===  172.16.11.61 -- GET  jobId=f365dd96-c018-454a-874c-37dce9396d96&command=queryAsyncJobResult&response=json
2024-09-26 16:58:47,762 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824845:ctx-517f2c19) (logid:c6e8be8b) ===START===  172.16.11.61 -- GET  jobId=f365dd96-c018-454a-874c-37dce9396d96&command=queryAsyncJobResult&response=json
2024-09-26 16:58:47,784 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824845:ctx-517f2c19 ctx-9a6894c4) (logid:c6e8be8b) ===END===  172.16.11.61 -- GET  jobId=f365dd96-c018-454a-874c-37dce9396d96&command=queryAsyncJobResult&response=json
2024-09-26 16:58:47,863 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-322:ctx-abb19c96) (logid:f365dd96) Seq 77358-1940207014466653252: Response Received:
2024-09-26 16:58:47,864 DEBUG [c.c.a.t.Request] (DirectAgent-322:ctx-abb19c96) (logid:f365dd96) Seq 77358-1940207014466653252: Processing:  { Ans: , MgmtId: 108597816265214, via: 77358(xcp-sr246-u1112.aisrp.local), Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":"false","details":"BackupSnapshot Failed due to Exception in backupsnapshot stage due to com.cloud.utils.exception.CloudRuntimeException: Could not retrieve an already used file SR for path [/var/cloud_mount/440acca8-622d-3dfb-825d-b3e62d7bba87/snapshots/225/6156] or create a new file SR on host [4208d709-b553-47c0-aee2-7942d370b70c]","wait":"0","bypassHostMaintenance":"false"}}] }
2024-09-26 16:58:47,864 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-322:ctx-abb19c96) (logid:f365dd96) Seq 77358-1940207014466653252: No more commands found
2024-09-26 16:58:47,864 DEBUG [c.c.a.t.Request] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Seq 77358-1940207014466653252: Received:  { Ans: , MgmtId: 108597816265214, via: 77358(xcp-sr246-u1112.aisrp.local), Ver: v1, Flags: 110, { CopyCmdAnswer } }
2024-09-26 16:58:47,885 DEBUG [c.c.s.s.SnapshotManagerImpl] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Failed to create snapshotBackupSnapshot Failed due to Exception in backupsnapshot stage due to com.cloud.utils.exception.CloudRuntimeException: Could not retrieve an already used file SR for path [/var/cloud_mount/440acca8-622d-3dfb-825d-b3e62d7bba87/snapshots/225/6156] or create a new file SR on host [4208d709-b553-47c0-aee2-7942d370b70c]
2024-09-26 16:58:47,885 DEBUG [c.c.r.ResourceLimitManagerImpl] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Updating resource Type = snapshot count for Account = 225 Operation = decreasing Amount = 1
2024-09-26 16:58:47,894 DEBUG [c.c.r.ResourceLimitManagerImpl] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Updating resource Type = secondary_storage count for Account = 225 Operation = decreasing Amount = (20.00 GB) 21474836480
2024-09-26 16:58:47,901 ERROR [o.a.c.s.v.VolumeServiceImpl] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Take snapshot: 6156 failed
2024-09-26 16:58:47,902 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Invocation exception, caused by: com.cloud.utils.exception.CloudRuntimeException: BackupSnapshot Failed due to Exception in backupsnapshot stage due to com.cloud.utils.exception.CloudRuntimeException: Could not retrieve an already used file SR for path [/var/cloud_mount/440acca8-622d-3dfb-825d-b3e62d7bba87/snapshots/225/6156] or create a new file SR on host [4208d709-b553-47c0-aee2-7942d370b70c]
2024-09-26 16:58:47,902 INFO  [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455 ctx-d1890501) (logid:f365dd96) Rethrow exception com.cloud.utils.exception.CloudRuntimeException: BackupSnapshot Failed due to Exception in backupsnapshot stage due to com.cloud.utils.exception.CloudRuntimeException: Could not retrieve an already used file SR for path [/var/cloud_mount/440acca8-622d-3dfb-825d-b3e62d7bba87/snapshots/225/6156] or create a new file SR on host [4208d709-b553-47c0-aee2-7942d370b70c]
2024-09-26 16:58:47,902 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455) (logid:f365dd96) Done with run of VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot for VM 5468, job origin: 72454
2024-09-26 16:58:47,902 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455) (logid:f365dd96) Unable to complete AsyncJobVO: {id:72455, userId: 298, accountId: 225, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkTakeVolumeSnapshot, cmdInfo: rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrVGFrZVZvbHVtZVNuYXBzaG90BL5gG4Li1c8CAAdaAAthc3luY0JhY2t1cFoACXF1aWVzY2VWbUwADGxvY2F0aW9uVHlwZXQAKUxjb20vY2xvdWQvc3RvcmFnZS9TbmFwc2hvdCRMb2NhdGlvblR5cGU7TAAIcG9saWN5SWR0ABBMamF2YS9sYW5nL0xvbmc7TAAKc25hcHNob3RJZHEAfgACTAAIdm9sdW1lSWRxAH4AAkwAB3pvbmVJZHN0ABBMamF2YS91dGlsL0xpc3Q7eHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAOEAAAAAAAABKgAAAAAAABVcdAAUVm9sdW1lQXBpU2VydmljZUltcGwAAHBzcgAOamF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHIAEGphdmEubGFuZy5OdW1iZXKGrJUdC5TgiwIAAHhwAAAAAAAAAABzcQB-AAgAAAAAAAADY3NxAH4ACAAAAAAAABgMcA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 108597816265214, completeMsid: null, lastUpdated: null, lastPolled: null, created: Thu Sep 26 16:58:32 MSK 2024, removed: null}, job origin:72454
2024-09-26 16:58:47,904 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455) (logid:f365dd96) Complete async job-72455, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyAC9jb20uY2xvdWQudXRpbHMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGlvblZNT3AAAAACAwABSQALY3NFcnJvckNvZGV4cgAaamF2YS5sYW5nLlJ1bnRpbWVFeGNlcHRpb26eXwZHCjSD5QIAAHhyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAFY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwcQB-AAh0ATxCYWNrdXBTbmFwc2hvdCBGYWlsZWQgZHVlIHRvIEV4Y2VwdGlvbiBpbiBiYWNrdXBzbmFwc2hvdCBzdGFnZSBkdWUgdG8gY29tLmNsb3VkLnV0aWxzLmV4Y2VwdGlvbi5DbG91ZFJ1bnRpbWVFeGNlcHRpb246IENvdWxkIG5vdCByZXRyaWV2ZSBhbiBhbHJlYWR5IHVzZWQgZmlsZSBTUiBmb3IgcGF0aCBbL3Zhci9jbG91ZF9tb3VudC80NDBhY2NhOC02MjJkLTNkZmItODI1ZC1iM2U2MmQ3YmJhODcvc25hcHNob3RzLzIyNS82MTU2XSBvciBjcmVhdGUgYSBuZXcgZmlsZSBTUiBvbiBob3N0IFs0MjA4ZDcwOS1iNTUzLTQ3YzAtYWVlMi03OTQyZDM3MGI3MGNddXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAAtc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAIQgAGZm9ybWF0SQAKbGluZU51bWJlckwAD2NsYXNzTG9hZGVyTmFtZXEAfgAFTAAOZGVjbGFyaW5nQ2xhc3NxAH4ABUwACGZpbGVOYW1lcQB-AAVMAAptZXRob2ROYW1lcQB-AAVMAAptb2R1bGVOYW1lcQB-AAVMAA1tb2R1bGVWZXJzaW9ucQB-AAV4cAEAAAF-dAADYXBwdAA6b3JnLmFwYWNoZS5jbG91ZHN0YWNrLnN0b3JhZ2Uuc25hcHNob3QuU25hcHNob3RTZXJ2aWNlSW1wbHQAGFNuYXBzaG90U2VydmljZUltcGwuamF2YXQADmJhY2t1cFNuYXBzaG90cHBzcQB-AAwBAAAAwXEAfgAOdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLnN0b3JhZ2Uuc25hcHNob3QuRGVmYXVsdFNuYXBzaG90U3RyYXRlZ3l0ABxEZWZhdWx0U25hcHNob3RTdHJhdGVneS5qYXZhcQB-ABFwcHNxAH4ADAEAAAWfcQB-AA50AC5jb20uY2xvdWQuc3RvcmFnZS5zbmFwc2hvdC5TbmFwc2hvdE1hbmFnZXJJbXBsdAAYU25hcHNob3RNYW5hZ2VySW1wbC5qYXZhdAAZYmFja3VwU25hcHNob3RUb1NlY29uZGFyeXBwc3EAfgAMAQAABWxxAH4ADnEAfgAWcQB-ABd0AAx0YWtlU25hcHNob3RwcHNxAH4ADAD_____cHQAMGpkay5pbnRlcm5hbC5yZWZsZWN0LkdlbmVyYXRlZE1ldGhvZEFjY2Vzc29yMTk1N3B0AAZpbnZva2VwcHNxAH4ADAIAAAArcHQAMWpkay5pbnRlcm5hbC5yZWZsZWN0LkRlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGx0ACFEZWxlZ2F0aW5nTWV0aG9kQWNjZXNzb3JJbXBsLmphdmFxAH4AHXQACWphdmEuYmFzZXQABzExLjAuMjRzcQB-AAwCAAACNnB0ABhqYXZhLmxhbmcucmVmbGVjdC5NZXRob2R0AAtNZXRob2QuamF2YXEAfgAdcQB-ACFxAH4AInNxAH4ADAEAAAFYcQB-AA50AChvcmcuc3ByaW5nZnJhbWV3b3JrLmFvcC5zdXBwb3J0LkFvcFV0aWxzdAANQW9wVXRpbHMuamF2YXQAHmludm9rZUpvaW5wb2ludFVzaW5nUmVmbGVjdGlvbnBwc3EAfgAMAQAAAMZxAH4ADnQAPG9yZy5zcHJpbmdmcmFtZXdvcmsuYW9wLmZyYW1ld29yay5SZWZsZWN0aXZlTWV0aG9kSW52b2NhdGlvbnQAH1JlZmxlY3RpdmVNZXRob2RJbnZvY2F0aW9uLmphdmF0AA9pbnZva2VKb2lucG9pbnRwcHNxAH4ADAEAAACjcQB-AA5xAH4AK3EAfgAsdAAHcHJvY2VlZHBwc3EAfgAMAQAAAGFxAH4ADnQAP29yZy5zcHJpbmdmcmFtZXdvcmsuYW9wLmludGVyY2VwdG9yLkV4cG9zZUludm9jYXRpb25JbnRlcmNlcHRvcnQAIEV4cG9zZUludm9jYXRpb25JbnRlcmNlcHRvci5qYXZhcQB-AB1wcHNxAH4ADAEAAAC6cQB-AA5xAH4AK3EAfgAscQB-AC9wcHNxAH4ADAEAAADXcQB-AA50ADRvcmcuc3ByaW5nZnJhbWV3b3JrLmFvcC5mcmFtZXdvcmsuSmRrRHluYW1pY0FvcFByb3h5dAAXSmRrRHluYW1pY0FvcFByb3h5LmphdmFxAH4AHXBwc3EAfgAMAP____9wdAAXY29tLnN1bi5wcm94eS4kUHJveHkyMzhwcQB-ABpwcHNxAH4ADAEAAArYcQB-AA50ADZvcmcuYXBhY2hlLmNsb3Vkc3RhY2suc3RvcmFnZS52b2x1bWUuVm9sdW1lU2VydmljZUltcGx0ABZWb2x1bWVTZXJ2aWNlSW1wbC5qYXZhcQB-ABpwcHNxAH4ADAEAAA68cQB-AA50ACZjb20uY2xvdWQuc3RvcmFnZS5Wb2x1bWVBcGlTZXJ2aWNlSW1wbHQAGVZvbHVtZUFwaVNlcnZpY2VJbXBsLmphdmF0AB1vcmNoZXN0cmF0ZVRha2VWb2x1bWVTbmFwc2hvdHBwc3EAfgAMAQAAE7lxAH4ADnEAfgA9cQB-AD5xAH4AP3Bwc3EAfgAMAP____9wdAAwamRrLmludGVybmFsLnJlZmxlY3QuR2VuZXJhdGVkTWV0aG9kQWNjZXNzb3IxOTU2cHEAfgAdcHBzcQB-AAwCAAAAK3BxAH4AH3EAfgAgcQB-AB1xAH4AIXEAfgAic3EAfgAMAgAAAjZwcQB-ACRxAH4AJXEAfgAdcQB-ACFxAH4AInNxAH4ADAEAAABpcQB-AA50ACJjb20uY2xvdWQudm0uVm1Xb3JrSm9iSGFuZGxlclByb3h5dAAaVm1Xb3JrSm9iSGFuZGxlclByb3h5LmphdmF0AA9oYW5kbGVWbVdvcmtKb2JwcHNxAH4ADAEAABPHcQB-AA5xAH4APXEAfgA-cQB-AEhwcHNxAH4ADAD_____cHQAMGpkay5pbnRlcm5hbC5yZWZsZWN0LkdlbmVyYXRlZE1ldGhvZEFjY2Vzc29yMTAzNnBxAH4AHXBwc3EAfgAMAgAAACtwcQB-AB9xAH4AIHEAfgAdcQB-ACFxAH4AInNxAH4ADAIAAAI2cHEAfgAkcQB-ACVxAH4AHXEAfgAhcQB-ACJzcQB-AAwBAAABWHEAfgAOcQB-ACdxAH4AKHEAfgApcHBzcQB-AAwBAAAAxnEAfgAOcQB-ACtxAH4ALHEAfgAtcHBzcQB-AAwBAAAAo3EAfgAOcQB-ACtxAH4ALHEAfgAvcHBzcQB-AAwBAAAAYXEAfgAOcQB-ADFxAH4AMnEAfgAdcHBzcQB-AAwBAAAAunEAfgAOcQB-ACtxAH4ALHEAfgAvcHBzcQB-AAwBAAAA13EAfgAOcQB-ADVxAH4ANnEAfgAdcHBzcQB-AAwA_____3B0ABdjb20uc3VuLnByb3h5LiRQcm94eTI0N3BxAH4ASHBwc3EAfgAMAQAAAGZxAH4ADnQAIGNvbS5jbG91ZC52bS5WbVdvcmtKb2JEaXNwYXRjaGVydAAYVm1Xb3JrSm9iRGlzcGF0Y2hlci5qYXZhdAAGcnVuSm9icHBzcQB-AAwBAAACjnEAfgAOdAA_b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmZyYW1ld29yay5qb2JzLmltcGwuQXN5bmNKb2JNYW5hZ2VySW1wbCQ1dAAYQXN5bmNKb2JNYW5hZ2VySW1wbC5qYXZhdAAMcnVuSW5Db250ZXh0cHBzcQB-AAwBAAAAMHEAfgAOdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5wcHNxAH4ADAEAAAA3cQB-AA50AEJvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0JDF0ABpEZWZhdWx0TWFuYWdlZENvbnRleHQuamF2YXQABGNhbGxwcHNxAH4ADAEAAABmcQB-AA50AEBvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0cQB-AGR0AA9jYWxsV2l0aENvbnRleHRwcHNxAH4ADAEAAAA0cQB-AA5xAH4AZ3EAfgBkdAAOcnVuV2l0aENvbnRleHRwcHNxAH4ADAEAAAAtcQB-AA50ADxvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGVxAH4AYHEAfgBhcHBzcQB-AAwBAAACWnEAfgAOcQB-AFtxAH4AXHEAfgBhcHBzcQB-AAwCAAACA3B0AC5qYXZhLnV0aWwuY29uY3VycmVudC5FeGVjdXRvcnMkUnVubmFibGVBZGFwdGVydAAORXhlY3V0b3JzLmphdmFxAH4AZXEAfgAhcQB-ACJzcQB-AAwCAAABCHB0AB9qYXZhLnV0aWwuY29uY3VycmVudC5GdXR1cmVUYXNrdAAPRnV0dXJlVGFzay5qYXZhcQB-AGFxAH4AIXEAfgAic3EAfgAMAgAABGhwdAAnamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9ydAAXVGhyZWFkUG9vbEV4ZWN1dG9yLmphdmF0AAlydW5Xb3JrZXJxAH4AIXEAfgAic3EAfgAMAgAAAnRwdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9yJFdvcmtlcnEAfgB2cQB-AGFxAH4AIXEAfgAic3EAfgAMAgAAAz1wdAAQamF2YS5sYW5nLlRocmVhZHQAC1RocmVhZC5qYXZhcQB-AGFxAH4AIXEAfgAic3IAH2phdmEudXRpbC5Db2xsZWN0aW9ucyRFbXB0eUxpc3R6uBe0PKee3gIAAHhweAAAEJp3CAAAAAAAAAAAeA
2024-09-26 16:58:47,905 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455) (logid:f365dd96) Publish async job-72455 complete on message bus
2024-09-26 16:58:47,905 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455) (logid:f365dd96) Wake up jobs related to job-72455
2024-09-26 16:58:47,905 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455) (logid:f365dd96) Update db status for job-72455
2024-09-26 16:58:47,906 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455) (logid:f365dd96) Wake up jobs joined with job-72455 and disjoin all subjobs created from job- 72455
2024-09-26 16:58:47,914 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455) (logid:f365dd96) Done executing com.cloud.vm.VmWorkTakeVolumeSnapshot for job-72455
2024-09-26 16:58:47,916 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-148:ctx-ef42787d job-72454/job-72455) (logid:f365dd96) Remove job-72455 from job monitoring
2024-09-26 16:58:47,930 ERROR [o.a.c.a.c.u.s.CreateSnapshotCmd] (API-Job-Executor-58:ctx-c9d433a7 job-72454 ctx-829ed64e) (logid:f365dd96) Failed to create snapshot due to an internal error creating snapshot for volume da420806-0ff3-43b8-9ee0-4aa2adfd9b99
2024-09-26 16:58:47,935 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-58:ctx-c9d433a7 job-72454) (logid:f365dd96) Complete async job-72454, 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 da420806-0ff3-43b8-9ee0-4aa2adfd9b99"}
2024-09-26 16:58:47,936 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-58:ctx-c9d433a7 job-72454) (logid:f365dd96) Publish async job-72454 complete on message bus
2024-09-26 16:58:47,936 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-58:ctx-c9d433a7 job-72454) (logid:f365dd96) Wake up jobs related to job-72454
2024-09-26 16:58:47,936 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-58:ctx-c9d433a7 job-72454) (logid:f365dd96) Update db status for job-72454
2024-09-26 16:58:47,937 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-58:ctx-c9d433a7 job-72454) (logid:f365dd96) Wake up jobs joined with job-72454 and disjoin all subjobs created from job- 72454
2024-09-26 16:58:47,941 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-58:ctx-c9d433a7 job-72454) (logid:f365dd96) Done executing org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd for job-72454
2024-09-26 16:58:47,941 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-58:ctx-c9d433a7 job-72454) (logid:f365dd96) Remove job-72454 from job monitoring
2024-09-26 16:58:50,891 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824742:ctx-04767efc) (logid:00d3b60a) ===START===  172.16.11.61 -- GET  jobId=f365dd96-c018-454a-874c-37dce9396d96&command=queryAsyncJobResult&response=json
2024-09-26 16:58:50,913 DEBUG [c.c.a.ApiServlet] (qtp501107890-4824742:ctx-04767efc ctx-ff2eca28) (logid:00d3b60a) ===END===  172.16.11.61 -- GET  jobId=f365dd96-c018-454a-874c-37dce9396d96&command=queryAsyncJobResult&response=json

0 replies

Pearl1594 · 2024-09-26T21:57:42Z

Pearl1594
Sep 26, 2024
Collaborator

Regarding the first issue of all/most snapshots going to one store, it would be helpful knowing the following:

Are the 2 secondary stores of same or similar capacity?
What is the value set for the global setting: image.store.allocation.algorithm ?

0 replies

top-secrett · 2024-09-27T06:10:15Z

top-secrett
Sep 27, 2024
Author

@Pearl1594 1. the same capacity. Second is a copy of first
2. firstfitleastconsumed

0 replies

top-secrett · 2024-09-27T12:30:21Z

top-secrett
Sep 27, 2024
Author

@Pearl1594 if I set first secstore Read-Only, snapshots are copied to the second secstore. But after I unset Read-Only all snapshots are copied to the first secstore again

0 replies

Pearl1594 · 2024-09-27T14:06:35Z

Pearl1594
Sep 27, 2024
Collaborator

when creating the volume snaphots, were they are initiated at the same time i.e, either via API or through recurring snapshot schedule. If that was the case, this could possible happen because the stats collector would not have run to has updated the stats of the secondary store(s) to make the decision that store1 has capacity < than store2. Marking store1 to read only excludes it from the list of stores to which snapshot would be backed up to - expected behaviour.

0 replies

top-secrett · 2024-10-02T11:18:05Z

top-secrett
Oct 2, 2024
Author

@Pearl1594 Why is it converted into disscussion? It is a really problem. I can add multiple sectores, but it is useless because only the first secstore will work.
I want to use secstore for backup purpose. I am planning add two baremetal servers with 2 LUNs attached to each server and create 4 NFS secstores for fault tolerance and load balancing.

0 replies

top-secrett · 2024-10-07T14:18:28Z

top-secrett
Oct 7, 2024
Author

@Pearl1594 Any suggestions how to use several secstores at the same time?

0 replies

Pearl1594 · 2024-10-07T15:00:33Z

Pearl1594
Oct 7, 2024
Collaborator

@top-secrett about converting it to a discussion, the reason was to first understand if this is a bug or an issue with the setup / just the behaviour.

Could you also please shed some more light on this point:

when creating the volume snaphots, were they are initiated at the same time i.e, either via API or through recurring snapshot schedule. If that was the case, this could possible happen because the stats collector would not have run to has updated the stats of the secondary store(s) to make the decision that store1 has capacity < than store2.
thanks

0 replies

top-secrett · 2024-10-08T06:50:28Z

top-secrett
Oct 8, 2024
Author

@top-secrett ok, for now I have 2 secstores. New snapshot of new VM was placed on second secstore.
First:

Second:

Why all new snapshots are placed on only one storage even if its capacity is almost full?

2024-10-08 09:35:56,237 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-109:ctx-42ac2243 job-75567) (logid:c49c9ce3) Executing AsyncJobVO: {id:75567, userId: 63, accountId: 60, instanceType: Snapshot, instanceId: 1170, cmd: org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd, cmdInfo: {"quiescevm":"false","httpmethod":"GET","ctxAccountId":"60","uuid":"9a38809f-72e5-4436-998b-c8e67a066e2b","cmdEventType":"SNAPSHOT.CREATE","asyncBackup":"false","response":"json","ctxUserId":"63","volumeId":"2bb3eeac-0c70-4f1f-84b0-21bb7c449c3f","name":"test-karasev","ctxStartEventId":"1821908","id":"1170","ctxDetails":"{\"interface com.cloud.storage.Volume\":\"2bb3eeac-0c70-4f1f-84b0-21bb7c449c3f\",\"interface com.cloud.storage.Snapshot\":\"9a38809f-72e5-4436-998b-c8e67a066e2b\"}"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 108597816265214, completeMsid: null, lastUpdated: null, lastPolled: null, created: null, removed: null}
2024-10-08 09:35:56,261 DEBUG [c.c.a.ApiServlet] (qtp501107890-757360:ctx-7422ae44) (logid:8eac6395) ===START===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:35:56,285 DEBUG [c.c.a.ApiServlet] (qtp501107890-757360:ctx-7422ae44 ctx-64db583d) (logid:8eac6395) ===END===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:35:56,298 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-109:ctx-42ac2243 job-75567 ctx-29a24e5f) (logid:c49c9ce3) Sync job-75568 execution on object VmWorkJobQueue.5492
2024-10-08 09:35:58,082 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568) (logid:c49c9ce3) Executing AsyncJobVO: {id:75568, userId: 63, accountId: 60, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkTakeVolumeSnapshot, cmdInfo: rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrVGFrZVZvbHVtZVNuYXBzaG90BL5gG4Li1c8CAAdaAAthc3luY0JhY2t1cFoACXF1aWVzY2VWbUwADGxvY2F0aW9uVHlwZXQAKUxjb20vY2xvdWQvc3RvcmFnZS9TbmFwc2hvdCRMb2NhdGlvblR5cGU7TAAIcG9saWN5SWR0ABBMamF2YS9sYW5nL0xvbmc7TAAKc25hcHNob3RJZHEAfgACTAAIdm9sdW1lSWRxAH4AAkwAB3pvbmVJZHN0ABBMamF2YS91dGlsL0xpc3Q7eHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAADwAAAAAAAAAPwAAAAAAABV0dAAUVm9sdW1lQXBpU2VydmljZUltcGwAAHBzcgAOamF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHIAEGphdmEubGFuZy5OdW1iZXKGrJUdC5TgiwIAAHhwAAAAAAAAAABzcQB-AAgAAAAAAAAEknNxAH4ACAAAAAAAABg7cA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 108597816265214, completeMsid: null, lastUpdated: null, lastPolled: null, created: Tue Oct 08 09:35:56 MSK 2024, removed: null}
2024-10-08 09:35:58,082 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568) (logid:c49c9ce3) Run VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot for VM 5492, job origin: 75567
2024-10-08 09:35:58,085 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Execute VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot{"volumeId":6203,"policyId":0,"snapshotId":1170,"quiesceVm":false,"asyncBackup":false,"userId":63,"accountId":60,"vmId":5492,"handlerName":"VolumeApiServiceImpl"}
2024-10-08 09:35:58,098 DEBUG [o.a.c.s.s.StorPoolSnapshotStrategy] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) StorpoolSnapshotStrategy.canHandle: snapshot=test-karasev, uuid=9a38809f-72e5-4436-998b-c8e67a066e2b, op=TAKE
2024-10-08 09:35:58,138 DEBUG [o.a.c.s.d.d.CloudStackPrimaryDataStoreDriverImpl] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Taking snapshot of org.apache.cloudstack.storage.snapshot.SnapshotObject@3a2fbae5
2024-10-08 09:35:58,176 DEBUG [o.a.c.s.d.d.CloudStackPrimaryDataStoreDriverImpl] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Taking snapshot of org.apache.cloudstack.storage.snapshot.SnapshotObject@3a2fbae5 and encryption required is false
2024-10-08 09:35:58,176 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) getCommandHostDelegation: class org.apache.cloudstack.storage.command.CreateObjectCommand
2024-10-08 09:35:58,177 DEBUG [c.c.h.XenServerGuru] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) We are returning the default host to execute commands because the command is not of Copy type.
2024-10-08 09:35:58,220 DEBUG [c.c.a.t.Request] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Seq 77352-1081145385545647332: Sending  { Cmd , MgmtId: 108597816265214, via: 77352(xcp-sr247-u0910.aisrp.local), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"2bb3eeac-0c70-4f1f-84b0-21bb7c449c3f","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"name":"ROOT-5492","size":"(10.00 GB) 10737418240","path":"cd4d9886-55ed-49a7-a086-5edef8f77067","volumeId":"6203","vmName":"i-60-5492-VM","accountId":"60","format":"VHD","provisioningType":"THIN","poolId":"54","id":"6203","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"vmName":"i-60-5492-VM","name":"test-karasev","hypervisorType":"XenServer","id":"1170","quiescevm":"false","physicalSize":"0","accountId":"60","followRedirects":"false"}},"wait":"0","bypassHostMaintenance":"false"}}] }
2024-10-08 09:35:58,221 DEBUG [c.c.a.t.Request] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Seq 77352-1081145385545647332: Executing:  { Cmd , MgmtId: 108597816265214, via: 77352(xcp-sr247-u0910.aisrp.local), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"2bb3eeac-0c70-4f1f-84b0-21bb7c449c3f","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"name":"ROOT-5492","size":"(10.00 GB) 10737418240","path":"cd4d9886-55ed-49a7-a086-5edef8f77067","volumeId":"6203","vmName":"i-60-5492-VM","accountId":"60","format":"VHD","provisioningType":"THIN","poolId":"54","id":"6203","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"vmName":"i-60-5492-VM","name":"test-karasev","hypervisorType":"XenServer","id":"1170","quiescevm":"false","physicalSize":"0","accountId":"60","followRedirects":"false"}},"wait":"0","bypassHostMaintenance":"false"}}] }
2024-10-08 09:35:58,222 DEBUG [c.c.s.r.StorageSubsystemCommandHandlerBase] (DirectAgent-31:ctx-8affc615) (logid:c49c9ce3) Executing command CreateObjectCommand: [{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"2bb3eeac-0c70-4f1f-84b0-21bb7c449c3f","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":54,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":0,"url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":false}},"name":"ROOT-5492","size":10737418240,"path":"cd4d9886-55ed-49a7-a086-5edef8f77067","volumeId":6203,"vmName":"i-60-5492-VM","accountId":60,"format":"VHD","provisioningType":"THIN","poolId":54,"id":6203,"deviceId":0,"cacheMode":"NONE","hypervisorType":"XenServer","directDownload":false,"deployAsIs":false,"followRedirects":true},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":54,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":0,"url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":false}},"vmName":"i-60-5492-VM","name":"test-karasev","hypervisorType":"XenServer","id":1170,"quiescevm":false,"physicalSize":0,"accountId":60,"followRedirects":false}},"wait":0,"bypassHostMaintenance":false}].
2024-10-08 09:35:59,315 DEBUG [c.c.a.ApiServlet] (qtp501107890-923975:ctx-3ad490b5) (logid:a7956111) ===START===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:35:59,338 DEBUG [c.c.a.ApiServlet] (qtp501107890-923975:ctx-3ad490b5 ctx-b7640e87) (logid:a7956111) ===END===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:02,353 DEBUG [c.c.a.ApiServlet] (qtp501107890-920932:ctx-072feeae) (logid:02659f8f) ===START===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:02,378 DEBUG [c.c.a.ApiServlet] (qtp501107890-920932:ctx-072feeae ctx-b2058784) (logid:02659f8f) ===END===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:05,308 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-31:ctx-8affc615) (logid:c49c9ce3) Seq 77352-1081145385545647332: Response Received:
2024-10-08 09:36:05,308 DEBUG [c.c.a.t.Request] (DirectAgent-31:ctx-8affc615) (logid:c49c9ce3) Seq 77352-1081145385545647332: Processing:  { Ans: , MgmtId: 108597816265214, via: 77352(xcp-sr247-u0910.aisrp.local), Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"488f6825-bba8-419e-90ee-53996277abb8","id":"0","quiescevm":"false","physicalSize":"0","accountId":"0","followRedirects":"false"}},"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2024-10-08 09:36:05,308 DEBUG [c.c.a.t.Request] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Seq 77352-1081145385545647332: Received:  { Ans: , MgmtId: 108597816265214, via: 77352(xcp-sr247-u0910.aisrp.local), Ver: v1, Flags: 10, { CreateObjectAnswer } }
2024-10-08 09:36:05,381 DEBUG [o.a.c.s.h.HeuristicRuleHelper] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) No heuristic rules found for zone with ID [7] and heuristic type [SNAPSHOT]. Returning null.
2024-10-08 09:36:05,385 DEBUG [c.c.s.StatsCollector] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Verifying image storage [10]. Capacity: total=[2 TB], used=[1 TB], threshold=[89.99999761581421%].
2024-10-08 09:36:05,397 DEBUG [c.c.a.ApiServlet] (qtp501107890-922834:ctx-a232aee6) (logid:dc1d5623) ===START===  127.0.0.1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:05,426 DEBUG [c.c.a.ApiServlet] (qtp501107890-922834:ctx-a232aee6 ctx-49c349e5) (logid:dc1d5623) ===END===  127.0.0.1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:05,433 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) copyAsync inspecting src type SNAPSHOT copyAsync inspecting dest type SNAPSHOT
2024-10-08 09:36:05,558 ERROR [o.a.c.s.e.DefaultEndPointSelector] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) IR24 select BACKUPSNAPSHOT from primary to secondary 1170 dest=1170
2024-10-08 09:36:05,565 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) getCommandHostDelegation: class org.apache.cloudstack.storage.command.CopyCommand
2024-10-08 09:36:05,566 DEBUG [c.c.h.XenServerGuru] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) We are returning the default host to execute commands because the source and destination objects are not NFS type.
2024-10-08 09:36:05,570 DEBUG [c.c.a.t.Request] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Seq 77357-4446460207098250533: Sending  { Cmd , MgmtId: 108597816265214, via: 77357(xcp-sr247-u0708.aisrp.local), Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"488f6825-bba8-419e-90ee-53996277abb8","volume":{"uuid":"2bb3eeac-0c70-4f1f-84b0-21bb7c449c3f","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"name":"ROOT-5492","size":"(10.00 GB) 10737418240","path":"cd4d9886-55ed-49a7-a086-5edef8f77067","volumeId":"6203","vmName":"i-60-5492-VM","accountId":"60","format":"VHD","provisioningType":"THIN","poolId":"54","id":"6203","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"vmName":"i-60-5492-VM","name":"test-karasev","hypervisorType":"XenServer","id":"1170","quiescevm":"false","physicalSize":"0","accountId":"60","followRedirects":"false"}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/60/6203","volume":{"uuid":"2bb3eeac-0c70-4f1f-84b0-21bb7c449c3f","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"name":"ROOT-5492","size":"(10.00 GB) 10737418240","path":"cd4d9886-55ed-49a7-a086-5edef8f77067","volumeId":"6203","vmName":"i-60-5492-VM","accountId":"60","format":"VHD","provisioningType":"THIN","poolId":"54","id":"6203","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.69.105.243/var/NFS3","_role":"Image"}},"vmName":"i-60-5492-VM","name":"test-karasev","hypervisorType":"XenServer","id":"1170","quiescevm":"false","physicalSize":"0","accountId":"60","followRedirects":"false"}},"executeInSequence":"true","options":{"snapshot.backup.to.secondary":"true","fullSnapshot":"true"},"options2":{},"wait":"21600","bypassHostMaintenance":"false"}}] }
2024-10-08 09:36:05,572 DEBUG [c.c.a.t.Request] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Seq 77357-4446460207098250533: Executing:  { Cmd , MgmtId: 108597816265214, via: 77357(xcp-sr247-u0708.aisrp.local), Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"488f6825-bba8-419e-90ee-53996277abb8","volume":{"uuid":"2bb3eeac-0c70-4f1f-84b0-21bb7c449c3f","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"name":"ROOT-5492","size":"(10.00 GB) 10737418240","path":"cd4d9886-55ed-49a7-a086-5edef8f77067","volumeId":"6203","vmName":"i-60-5492-VM","accountId":"60","format":"VHD","provisioningType":"THIN","poolId":"54","id":"6203","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"vmName":"i-60-5492-VM","name":"test-karasev","hypervisorType":"XenServer","id":"1170","quiescevm":"false","physicalSize":"0","accountId":"60","followRedirects":"false"}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/60/6203","volume":{"uuid":"2bb3eeac-0c70-4f1f-84b0-21bb7c449c3f","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":"54","poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":"0","url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":"false"}},"name":"ROOT-5492","size":"(10.00 GB) 10737418240","path":"cd4d9886-55ed-49a7-a086-5edef8f77067","volumeId":"6203","vmName":"i-60-5492-VM","accountId":"60","format":"VHD","provisioningType":"THIN","poolId":"54","id":"6203","deviceId":"0","cacheMode":"NONE","hypervisorType":"XenServer","directDownload":"false","deployAsIs":"false","followRedirects":"true"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.69.105.243/var/NFS3","_role":"Image"}},"vmName":"i-60-5492-VM","name":"test-karasev","hypervisorType":"XenServer","id":"1170","quiescevm":"false","physicalSize":"0","accountId":"60","followRedirects":"false"}},"executeInSequence":"true","options":{"snapshot.backup.to.secondary":"true","fullSnapshot":"true"},"options2":{},"wait":"21600","bypassHostMaintenance":"false"}}] }
2024-10-08 09:36:05,572 DEBUG [c.c.s.r.StorageSubsystemCommandHandlerBase] (DirectAgent-219:ctx-11fc864d) (logid:c49c9ce3) Executing command CopyCommand: [{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"488f6825-bba8-419e-90ee-53996277abb8","volume":{"uuid":"2bb3eeac-0c70-4f1f-84b0-21bb7c449c3f","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":54,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":0,"url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":false}},"name":"ROOT-5492","size":10737418240,"path":"cd4d9886-55ed-49a7-a086-5edef8f77067","volumeId":6203,"vmName":"i-60-5492-VM","accountId":60,"format":"VHD","provisioningType":"THIN","poolId":54,"id":6203,"deviceId":0,"cacheMode":"NONE","hypervisorType":"XenServer","directDownload":false,"deployAsIs":false,"followRedirects":true},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":54,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":0,"url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":false}},"vmName":"i-60-5492-VM","name":"test-karasev","hypervisorType":"XenServer","id":1170,"quiescevm":false,"physicalSize":0,"accountId":60,"followRedirects":false}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/60/6203","volume":{"uuid":"2bb3eeac-0c70-4f1f-84b0-21bb7c449c3f","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"DM7100_LUN4","name":"cluster5-dm7100_lun4","id":54,"poolType":"PreSetup","host":"localhost","path":"/DM7100_LUN4","port":0,"url":"PreSetup://localhost/DM7100_LUN4/?ROLE=Primary&STOREUUID=DM7100_LUN4","isManaged":false}},"name":"ROOT-5492","size":10737418240,"path":"cd4d9886-55ed-49a7-a086-5edef8f77067","volumeId":6203,"vmName":"i-60-5492-VM","accountId":60,"format":"VHD","provisioningType":"THIN","poolId":54,"id":6203,"deviceId":0,"cacheMode":"NONE","hypervisorType":"XenServer","directDownload":false,"deployAsIs":false,"followRedirects":true},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.69.105.243/var/NFS3","_role":"Image"}},"vmName":"i-60-5492-VM","name":"test-karasev","hypervisorType":"XenServer","id":1170,"quiescevm":false,"physicalSize":0,"accountId":60,"followRedirects":false}},"executeInSequence":true,"options":{"snapshot.backup.to.secondary":"true","fullSnapshot":"true"},"options2":{},"wait":21600,"bypassHostMaintenance":false}].
2024-10-08 09:36:07,732 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-219:ctx-11fc864d) (logid:c49c9ce3) No file SR found for path: /var/cloud_mount/38f03c70-7d69-3505-85fd-a108790bfde3/snapshots/60/6203
2024-10-08 09:36:07,732 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-219:ctx-11fc864d) (logid:c49c9ce3) Creating file SR for path [/var/cloud_mount/38f03c70-7d69-3505-85fd-a108790bfde3/snapshots/60/6203] on host [32ed12ed-6b7c-4274-92a4-807b32075733]
2024-10-08 09:36:08,448 DEBUG [c.c.a.ApiServlet] (qtp501107890-757360:ctx-4021b50a) (logid:57b35f1c) ===START===  127.0.0.1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:08,471 DEBUG [c.c.a.ApiServlet] (qtp501107890-757360:ctx-4021b50a ctx-40e17e8a) (logid:57b35f1c) ===END===  127.0.0.1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:11,486 DEBUG [c.c.a.ApiServlet] (qtp501107890-920932:ctx-2fd102d2) (logid:c39505de) ===START===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:11,512 DEBUG [c.c.a.ApiServlet] (qtp501107890-920932:ctx-2fd102d2 ctx-e4be5e15) (logid:c39505de) ===END===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:14,539 DEBUG [c.c.a.ApiServlet] (qtp501107890-922834:ctx-7df66d9f) (logid:311c29c3) ===START===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:14,564 DEBUG [c.c.a.ApiServlet] (qtp501107890-922834:ctx-7df66d9f ctx-4808f0aa) (logid:311c29c3) ===END===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:17,586 DEBUG [c.c.a.ApiServlet] (qtp501107890-926241:ctx-ef4e8e3c) (logid:8cd14435) ===START===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:17,608 DEBUG [c.c.a.ApiServlet] (qtp501107890-926241:ctx-ef4e8e3c ctx-09238735) (logid:8cd14435) ===END===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:20,621 DEBUG [c.c.a.ApiServlet] (qtp501107890-926242:ctx-bc3d1597) (logid:1113a64b) ===START===  127.0.0.1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:20,644 DEBUG [c.c.a.ApiServlet] (qtp501107890-926242:ctx-bc3d1597 ctx-cc7870e5) (logid:1113a64b) ===END===  127.0.0.1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:23,664 DEBUG [c.c.a.ApiServlet] (qtp501107890-922834:ctx-d5db471b) (logid:4e29dc0f) ===START===  127.0.0.1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:23,686 DEBUG [c.c.a.ApiServlet] (qtp501107890-922834:ctx-d5db471b ctx-5bd913bf) (logid:4e29dc0f) ===END===  127.0.0.1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:26,699 DEBUG [c.c.a.ApiServlet] (qtp501107890-926241:ctx-151bdf90) (logid:f6adbae1) ===START===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:26,727 DEBUG [c.c.a.ApiServlet] (qtp501107890-926241:ctx-151bdf90 ctx-be666c59) (logid:f6adbae1) ===END===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:29,752 DEBUG [c.c.a.ApiServlet] (qtp501107890-757360:ctx-e68b35d0) (logid:8bb6246d) ===START===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:29,773 DEBUG [c.c.a.ApiServlet] (qtp501107890-757360:ctx-e68b35d0 ctx-67af04ec) (logid:8bb6246d) ===END===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:32,787 DEBUG [c.c.a.ApiServlet] (qtp501107890-922834:ctx-4c729b88) (logid:3a88ff96) ===START===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:32,811 DEBUG [c.c.a.ApiServlet] (qtp501107890-922834:ctx-4c729b88 ctx-ebe31ca1) (logid:3a88ff96) ===END===  0:0:0:0:0:0:0:1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:33,817 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-219:ctx-11fc864d) (logid:c49c9ce3) Host 10.69.105.27 OpaqueRef:5f9f4d9a-eb89-4da1-88c8-e3c71ca2b2af: Removing SR
2024-10-08 09:36:33,831 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-219:ctx-11fc864d) (logid:c49c9ce3) Host 10.69.105.27 OpaqueRef:7b2cf5a2-e6dd-4a66-ae7a-ebb1aface613: Unplugging pbd
2024-10-08 09:36:34,272 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-219:ctx-11fc864d) (logid:c49c9ce3) Host 10.69.105.27 OpaqueRef:5f9f4d9a-eb89-4da1-88c8-e3c71ca2b2af: Forgetting
2024-10-08 09:36:34,279 DEBUG [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-219:ctx-11fc864d) (logid:c49c9ce3) Successfully destroyed snapshot on volume: cd4d9886-55ed-49a7-a086-5edef8f77067 execept this current snapshot 488f6825-bba8-419e-90ee-53996277abb8
2024-10-08 09:36:34,279 INFO  [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-219:ctx-11fc864d) (logid:c49c9ce3) New snapshot details: SnapshotTO[datastore=null|volume=null|pathsnapshots/60/6203/9d6af389-3e09-49cc-a12c-4df6d06e1779.vhd]
2024-10-08 09:36:34,279 INFO  [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-219:ctx-11fc864d) (logid:c49c9ce3) New snapshot physical utilization: (4.48 GB) 4809777664
2024-10-08 09:36:34,279 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-219:ctx-11fc864d) (logid:c49c9ce3) Seq 77357-4446460207098250533: Response Received:
2024-10-08 09:36:34,280 DEBUG [c.c.a.t.Request] (DirectAgent-219:ctx-11fc864d) (logid:c49c9ce3) Seq 77357-4446460207098250533: Processing:  { Ans: , MgmtId: 108597816265214, via: 77357(xcp-sr247-u0708.aisrp.local), Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/60/6203/9d6af389-3e09-49cc-a12c-4df6d06e1779.vhd","id":"0","quiescevm":"false","physicalSize":"4809777664","accountId":"0","followRedirects":"false"}},"result":"true","wait":"0","bypassHostMaintenance":"false"}}] }
2024-10-08 09:36:34,280 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-219:ctx-11fc864d) (logid:c49c9ce3) Seq 77357-4446460207098250533: No more commands found
2024-10-08 09:36:34,280 DEBUG [c.c.a.t.Request] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Seq 77357-4446460207098250533: Received:  { Ans: , MgmtId: 108597816265214, via: 77357(xcp-sr247-u0708.aisrp.local), Ver: v1, Flags: 110, { CopyCmdAnswer } }
2024-10-08 09:36:34,327 DEBUG [c.c.r.ResourceLimitManagerImpl] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Updating resource Type = secondary_storage count for Account = 60 Operation = decreasing Amount = (5.52 GB) 5927640576
2024-10-08 09:36:34,336 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Done executing VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot{"volumeId":6203,"policyId":0,"snapshotId":1170,"quiesceVm":false,"asyncBackup":false,"userId":63,"accountId":60,"vmId":5492,"handlerName":"VolumeApiServiceImpl"}
2024-10-08 09:36:34,337 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Complete async job-75568, jobStatus: SUCCEEDED, resultCode: 0, result: rO0ABXNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgABSgAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAAAAAAAAEkg
2024-10-08 09:36:34,338 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Publish async job-75568 complete on message bus
2024-10-08 09:36:34,338 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Wake up jobs related to job-75568
2024-10-08 09:36:34,338 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Update db status for job-75568
2024-10-08 09:36:34,339 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568 ctx-7f4fab53) (logid:c49c9ce3) Wake up jobs joined with job-75568 and disjoin all subjobs created from job- 75568
2024-10-08 09:36:34,348 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568) (logid:c49c9ce3) Done with run of VM work job: com.cloud.vm.VmWorkTakeVolumeSnapshot for VM 5492, job origin: 75567
2024-10-08 09:36:34,348 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568) (logid:c49c9ce3) Done executing com.cloud.vm.VmWorkTakeVolumeSnapshot for job-75568
2024-10-08 09:36:34,349 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-11:ctx-b410a074 job-75567/job-75568) (logid:c49c9ce3) Remove job-75568 from job monitoring
2024-10-08 09:36:34,395 DEBUG [o.a.c.s.s.StorPoolSnapshotStrategy] (API-Job-Executor-109:ctx-42ac2243 job-75567 ctx-29a24e5f) (logid:c49c9ce3) StorpoolSnapshotStrategy.canHandle: snapshot=test-karasev, uuid=9a38809f-72e5-4436-998b-c8e67a066e2b, op=REVERT
2024-10-08 09:36:34,401 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-109:ctx-42ac2243 job-75567 ctx-29a24e5f) (logid:c49c9ce3) Complete async job-75567, jobStatus: SUCCEEDED, resultCode: 0, result: org.apache.cloudstack.api.response.SnapshotResponse/snapshot/{"id":"9a38809f-72e5-4436-998b-c8e67a066e2b","account":"dkarasev","domainid":"35e53f94-4224-11ec-8697-62c4e64309fe","domain":"ROOT","snapshottype":"MANUAL","volumeid":"2bb3eeac-0c70-4f1f-84b0-21bb7c449c3f","volumename":"ROOT-5492","volumetype":"ROOT","created":"2024-10-08T09:35:56+0300","name":"test-karasev","intervaltype":"MANUAL","state":"BackedUp","physicalsize":"4809777664","zoneid":"9505445a-7164-4675-876d-1a2fee1f7e46","zonename":"xcp-zone-02","revertable":"false","ostypeid":"c7dbb910-46b3-11ec-afc7-62c4e64309fe","osdisplayname":"AlmaLinux 8.3","virtualsize":"10737418240","tags":[],"hasannotations":"false"}
2024-10-08 09:36:34,402 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-109:ctx-42ac2243 job-75567 ctx-29a24e5f) (logid:c49c9ce3) Publish async job-75567 complete on message bus
2024-10-08 09:36:34,402 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-109:ctx-42ac2243 job-75567 ctx-29a24e5f) (logid:c49c9ce3) Wake up jobs related to job-75567
2024-10-08 09:36:34,402 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-109:ctx-42ac2243 job-75567 ctx-29a24e5f) (logid:c49c9ce3) Update db status for job-75567
2024-10-08 09:36:34,403 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-109:ctx-42ac2243 job-75567 ctx-29a24e5f) (logid:c49c9ce3) Wake up jobs joined with job-75567 and disjoin all subjobs created from job- 75567
2024-10-08 09:36:34,408 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-109:ctx-42ac2243 job-75567) (logid:c49c9ce3) Done executing org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd for job-75567
2024-10-08 09:36:34,408 INFO  [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-109:ctx-42ac2243 job-75567) (logid:c49c9ce3) Remove job-75567 from job monitoring
2024-10-08 09:36:35,824 DEBUG [c.c.a.ApiServlet] (qtp501107890-920932:ctx-cd5b6739) (logid:a075da24) ===START===  127.0.0.1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json
2024-10-08 09:36:35,845 DEBUG [c.c.a.ApiServlet] (qtp501107890-920932:ctx-cd5b6739 ctx-220a40e9) (logid:a075da24) ===END===  127.0.0.1 -- GET  jobId=c49c9ce3-4117-4c72-9572-716ae35d8f3b&command=queryAsyncJobResult&response=json

0 replies

top-secrett · 2024-10-15T06:45:18Z

top-secrett
Oct 15, 2024
Author

@Pearl1594 any suggestions how to solve this?

0 replies

DaanHoogland · 2025-04-30T14:38:35Z

DaanHoogland
Apr 30, 2025
Collaborator

@top-secrett , do you have a resolution to this query, yet?

0 replies

DaanHoogland · 2025-05-07T09:40:38Z

DaanHoogland
May 7, 2025
Collaborator

closing this for lack of activity. please re-open or open a new one if it becomes relevant again.

0 replies

Uh oh!

Multiple secondary storage in one zone; problem with volume snapshots #9754

Uh oh!

Uh oh!

top-secrett Sep 26, 2024

ISSUE TYPE

CLOUDSTACK VERSION

SUMMARY

STEPS TO REPRODUCE

EXPECTED RESULTS

ACTUAL RESULTS

Replies: 13 comments

Uh oh!

Uh oh!

top-secrett Sep 26, 2024 Author

Uh oh!

Uh oh!

top-secrett Sep 26, 2024 Author

Uh oh!

Pearl1594 Sep 26, 2024 Collaborator

Uh oh!

top-secrett Sep 27, 2024 Author

Uh oh!

top-secrett Sep 27, 2024 Author

Uh oh!

Pearl1594 Sep 27, 2024 Collaborator

Uh oh!

Uh oh!

top-secrett Oct 2, 2024 Author

Uh oh!

top-secrett Oct 7, 2024 Author

Uh oh!

Pearl1594 Oct 7, 2024 Collaborator

Uh oh!

Uh oh!

top-secrett Oct 8, 2024 Author

Uh oh!

top-secrett Oct 15, 2024 Author

Uh oh!

DaanHoogland Apr 30, 2025 Collaborator

Uh oh!

DaanHoogland May 7, 2025 Collaborator

top-secrett
Sep 26, 2024

top-secrett
Sep 26, 2024
Author

top-secrett
Sep 26, 2024
Author

Pearl1594
Sep 26, 2024
Collaborator

top-secrett
Sep 27, 2024
Author

top-secrett
Sep 27, 2024
Author

Pearl1594
Sep 27, 2024
Collaborator

top-secrett
Oct 2, 2024
Author

top-secrett
Oct 7, 2024
Author

Pearl1594
Oct 7, 2024
Collaborator

top-secrett
Oct 8, 2024
Author

top-secrett
Oct 15, 2024
Author

DaanHoogland
Apr 30, 2025
Collaborator

DaanHoogland
May 7, 2025
Collaborator