[ https://issues.apache.org/jira/browse/CLOUDSTACK-3790?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
angeline shen updated CLOUDSTACK-3790: -------------------------------------- Attachment: management-server.log.gz management-server.log.2013-07-23.gz Screenshot-CloudPlatform™ - Mozilla Firefox-1.png Screenshot-CloudPlatform™ - Mozilla Firefox-1.png > KVM - Fail to create recurring snapshot : pool is already active > ---------------------------------------------------------------- > > Key: CLOUDSTACK-3790 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-3790 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the > default.) > Components: Management Server > Affects Versions: 4.2.0 > Environment: MS build > CloudPlatform-4.2-246-rhel6.3.tar.gz > host KVM build CloudPlatform-4.2-246-rhel6.3.tar.gz > Reporter: angeline shen > Assignee: edison su > Priority: Critical > Fix For: 4.2.0 > > Attachments: management-server.log.2013-07-23.gz, > management-server.log.gz, Screenshot-CloudPlatform™ - Mozilla Firefox-1.png, > Screenshot-CloudPlatform™ - Mozilla Firefox-1.png > > > 1. advance zone. domain: d1 domain admin: d1domain domain: d2 > user : d2user > 2. login : admin . create VPC network & VMs with DATA disk > login: d1domain. create VPC network & VMs with DATA disk > login: d2user. create VPC network & VMs with DATA disk > 3. login as each of above users. > setup hourly recurring snapshots for all ROOT and DATA disks to same > recurring schedule, > for example , all at 9 minutes pass the hour. > > Result: > there are some snapshots generated with status CreateOnPrimary , Failed to > create snapshot due to pool is already active : > 2013-07-23 22:04:49,920 DEBUG [agent.transport.Request] > (Job-Executor-42:job-56 = [ 3def22de-176e-45a7-b72b-98aaef57b906 ]) Seq > 1-1490617925: Sending { Cmd , MgmtId: 6655051826959, via: 1, Ver: v1, Flags: > 100011, [{"or > g.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/b52e5c2b-fc3e-4292-bda5-cb961efb94c7/c733fc4e-4d16-481f-9 > e20-2ed2519d6b3d","volume":{"uuid":"a39f007b-b014-4e6c-a3fa-8bce7a9ba213","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poo > lType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"name":"ROOT-13","size":147456,"path":"b52e5c2b-fc3e-4292-bda5-cb961efb94c7","volumeId":15,"vmName":"i-4-13-VM", > "accountId":4,"format":"QCOW2","id":15},"parentSnapshotPath":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/b52e5c2b-fc3e-4292-bda5-cb961efb94c7/29669eb5-1525-4745-81c4-6ca6ad239af0","dataStore":{"org.apache.cloudstack.stor > age.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"vmName":"i-4-13-VM","name" > :"z1vpc3G3d2userV32_ROOT-13_20130724050449","hypervisorType":"None","id":28}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/4/15","volume":{"uuid":"a39f007b-b014-4e6c-a3fa-8bce7a9ba213 > ","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/ > angie/primary/kvm63","port":2049}},"name":"ROOT-13","size":147456,"path":"b52e5c2b-fc3e-4292-bda5-cb961efb94c7","volumeId":15,"vmName":"i-4-13-VM","accountId":4,"format":"QCOW2","id":15},"parentSnapshotPath":"snapshots/ > 4/15/29669eb5-1525-4745-81c4-6ca6ad239af0","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.223.110.232/export/home/angie/secondary/kvm63","_role":"Image"}},"vmName":"i-4-13-VM","name":"z1vpc3G3d2userV32_RO > OT-13_20130724050449","hypervisorType":"None","id":28}},"executeInSequence":false,"wait":21600}}] > } > 2013-07-23 22:04:50,085 DEBUG [agent.transport.Request] > (AgentManager-Handler-6:null) Seq 1-1490617925: Processing: { Ans: , MgmtId: > 6655051826959, via: 1, Ver: v1, Flags: 10, > [{"org.apache.cloudstack.storage.command.C > opyCmdAnswer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException: > org.libvirt.LibvirtException: Requested operation is not valid: pool is > already active as '83602b3b-9b52-3016-871d-10883d294c18'" > ,"wait":0}}] } > 2013-07-23 22:04:50,085 DEBUG [agent.transport.Request] > (Job-Executor-42:job-56 = [ 3def22de-176e-45a7-b72b-98aaef57b906 ]) Seq > 1-1490617925: Received: { Ans: , MgmtId: 6655051826959, via: 1, Ver: v1, > Flags: 10, { Copy > CmdAnswer } } > 2013-07-23 22:04:50,097 DEBUG [storage.snapshot.SnapshotManagerImpl] > (Job-Executor-42:job-56 = [ 3def22de-176e-45a7-b72b-98aaef57b906 ]) Failed to > create snapshot > com.cloud.utils.exception.CloudRuntimeException: > com.cloud.utils.exception.CloudRuntimeException: > org.libvirt.LibvirtException: Requested operation is not valid: pool is > already active as '83602b3b-9b52-3016-871d-10883d > 294c18' > at > org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:286) > at > org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:127) > at > org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:217) > at > com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:992) > at > org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1185) > at > com.cloud.storage.VolumeManagerImpl.takeSnapshot(VolumeManagerImpl.java:2654) > at > org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170) > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158) > at > com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531) > at > java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) > at java.util.concurrent.FutureTask.run(FutureTask.java:166) > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > at java.lang.Thread.run(Thread.java:679) > 2013-07-23 22:04:50,106 DEBUG [storage.volume.VolumeServiceImpl] > (Job-Executor-42:job-56 = [ 3def22de-176e-45a7-b72b-98aaef57b906 ]) Take > snapshot: 15 failed: com.cloud.utils.exception.CloudRuntimeException: Failed > to c > reate snapshot > 2013-07-23 22:04:50,114 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-42:job-56 = [ 3def22de-176e-45a7-b72b-98aaef57b906 ]) Complete > async job-56 = [ 3def22de-176e-45a7-b72b-98aaef57b906 ], jobStatus: 2, resultC > ode: 530, result: Error Code: 530 Error text: Failed to create snapshot due > to an internal error creating snapshot for volume 15 > 2013-07-23 22:04:51,383 DEBUG [cloud.server.StatsCollector] > (StatsCollector-2:null) StorageCollector is running... > .................. > 2013-07-23 20:04:49,902 DEBUG [agent.transport.Request] > (Job-Executor-29:job-43 = [ 2362369a-a0ed-4554-852c-844b0e078670 ]) Seq > 1-1490617352: Sending { Cmd , MgmtId: 6655051826959, via: 1, Ver: v1, Flags: > 100011, [{"or > g.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/925e81ef-205a-4fd4-b3cf-923b709a2e3b/44e288de-1158-4343-b > 660-703b53208d2a","volume":{"uuid":"6c1d767f-c297-4bf2-8108-c0fa4d8c4862","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poo > lType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"name":"ROOT-12","size":147456,"path":"925e81ef-205a-4fd4-b3cf-923b709a2e3b","volumeId":14,"vmName":"i-4-12-VM", > "accountId":4,"format":"QCOW2","id":14},"parentSnapshotPath":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/925e81ef-205a-4fd4-b3cf-923b709a2e3b/3a91bcf2-9121-46b7-a720-c53daf617269","dataStore":{"org.apache.cloudstack.stor > age.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"vmName":"i-4-12-VM","name" > :"z1vpc3d2userV31_ROOT-12_20130724030449","hypervisorType":"None","id":15}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/4/14","volume":{"uuid":"6c1d767f-c297-4bf2-8108-c0fa4d8c4862", > "volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/an > gie/primary/kvm63","port":2049}},"name":"ROOT-12","size":147456,"path":"925e81ef-205a-4fd4-b3cf-923b709a2e3b","volumeId":14,"vmName":"i-4-12-VM","accountId":4,"format":"QCOW2","id":14},"parentSnapshotPath":"snapshots/4/ > 14/3a91bcf2-9121-46b7-a720-c53daf617269","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.223.110.232/export/home/angie/secondary/kvm63","_role":"Image"}},"vmName":"i-4-12-VM","name":"z1vpc3d2userV31_ROOT-1 > 2_20130724030449","hypervisorType":"None","id":15}},"executeInSequence":false,"wait":21600}}] > } > 2013-07-23 20:04:50,023 DEBUG [cloud.server.StatsCollector] > (StatsCollector-3:null) HostStatsCollector is running... > 2013-07-23 20:04:50,029 DEBUG [agent.manager.AgentAttache] > (StatsCollector-3:null) Request seq: 1490617353 > 2013-07-23 20:04:50,029 DEBUG [agent.manager.AgentAttache] > (StatsCollector-3:null) waiting to send 1490617353 > 2013-07-23 20:04:50,029 DEBUG [agent.manager.AgentAttache] > (StatsCollector-3:null) entering synchronize block for sending 1490617353 > 2013-07-23 20:04:50,030 DEBUG [agent.transport.Request] > (AgentManager-Handler-11:null) Seq 1-1490617350: Processing: { Ans: , > MgmtId: 6655051826959, via: 1, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.NetworkUsageAnswer > ":{"routerName":"r-11-VM","bytesSent":156008,"bytesReceived":7127289,"result":true,"details":"","wait":0}}] > } > 2013-07-23 20:04:50,030 DEBUG [agent.transport.Request] > (RouterMonitor-1:null) Seq 1-1490617350: Received: { Ans: , MgmtId: > 6655051826959, via: 1, Ver: v1, Flags: 10, { NetworkUsageAnswer } } > 2013-07-23 20:04:50,030 DEBUG [agent.manager.AgentManagerImpl] > (RouterMonitor-1:null) Details from executing class > com.cloud.agent.api.NetworkUsageCommand: > 2013-07-23 20:04:50,127 DEBUG [agent.transport.Request] > (AgentManager-Handler-9:null) Seq 1-1490617352: Processing: { Ans: , MgmtId: > 6655051826959, via: 1, Ver: v1, Flags: 10, > [{"org.apache.cloudstack.storage.command.C > opyCmdAnswer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException: > org.libvirt.LibvirtException: Requested operation is not valid: pool is > already active as '83602b3b-9b52-3016-871d-10883d294c18'" > ,"wait":0}}] } > 2013-07-23 20:04:50,127 DEBUG [agent.transport.Request] > (Job-Executor-29:job-43 = [ 2362369a-a0ed-4554-852c-844b0e078670 ]) Seq > 1-1490617352: Received: { Ans: , MgmtId: 6655051826959, via: 1, Ver: v1, > Flags: 10, { Copy > CmdAnswer } } > 2013-07-23 20:04:50,139 DEBUG [storage.snapshot.SnapshotManagerImpl] > (Job-Executor-29:job-43 = [ 2362369a-a0ed-4554-852c-844b0e078670 ]) Failed to > create snapshot > com.cloud.utils.exception.CloudRuntimeException: > com.cloud.utils.exception.CloudRuntimeException: > org.libvirt.LibvirtException: Requested operation is not valid: pool is > already active as '83602b3b-9b52-3016-871d-10883d > 294c18' > at > org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:286) > at > org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:127) > at > org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:217) > at > com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:992) > at > org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1185) > at > com.cloud.storage.VolumeManagerImpl.takeSnapshot(VolumeManagerImpl.java:2654) > at > org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170) > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158) > at > com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531) > at > java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) > at java.util.concurrent.FutureTask.run(FutureTask.java:166) > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > at java.lang.Thread.run(Thread.java:679) > 2013-07-23 20:04:50,146 DEBUG [storage.volume.VolumeServiceImpl] > (Job-Executor-29:job-43 = [ 2362369a-a0ed-4554-852c-844b0e078670 ]) Take > snapshot: 14 failed: com.cloud.utils.exception.CloudRuntimeException: Failed > to c > reate snapshot > 2013-07-23 20:04:50,153 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-29:job-43 = [ 2362 -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators For more information on JIRA, see: http://www.atlassian.com/software/jira