[CLOUDSTACK-4631] [Automation] Failed to create snapshot from volume due to storage pool missing error in libvirtd

• Type: Bug
• Status: Closed
• Priority: Critical
• Resolution: Fixed
• Affects Version/s: 4.2.1
• Fix Version/s: 4.3.0
• Component/s: KVM, Snapshot
• Security Level: Public (Anyone can view this level - this is the default.)
• Environment: RHEL 6.3; Automation env; Branch : 4.2.0-forward
• Assignee: Disheng Su
• Reporter: Rayees Namathponnan
• Created: 09/Sep/13 19:51
• Updated: 06/Nov/13 00:20
• Resolved: 06/Nov/13 00:20

Description

This issue found while running regression test case
integration.component.test_project_resources.TestSnapshots.test_06_create_snapshots_in_project

Test case failing while creating snapshot, observed below error MS log; there are some other snapshot test cases; its not effect; looks like its a inconsistent issue

2013-09-09 10:45:47,445 DEBUG [agent.transport.Request] (AgentManager-Handler-14:null) Seq 1-1436357958: Processing: { Ans: , MgmtId: 29066118877352, via: 1
, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException: co
m.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException: internal error Child process (/bin/umount /mnt/fff90cb5-06dd-33b3-8815-d78c08ca0
1d9) status unexpected: exit status 16","wait":0}}] }
2013-09-09 10:45:47,446 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-14:null) Seq 1-1436357970: Sending now. is current sequence.
2013-09-09 10:45:47,446 DEBUG [agent.transport.Request] (Job-Executor-146:job-1770 = [ 53db2ef6-6a92-4b69-bc5a-ea673814a4b9 ]) Seq 1-1436357958: Received: {
Ans: , MgmtId: 29066118877352, via: 1, Ver: v1, Flags: 110,

{ CopyCmdAnswer }

}
2013-09-09 10:45:47,458 DEBUG [storage.snapshot.SnapshotManagerImpl] (Job-Executor-146:job-1770 = [ 53db2ef6-6a92-4b69-bc5a-ea673814a4b9 ]) Failed to create
snapshot
com.cloud.utils.exception.CloudRuntimeException: com.cloud.utils.exception.CloudRuntimeException: com.cloud.utils.exception.CloudRuntimeException: org.libvir
t.LibvirtException: internal error Child process (/bin/umount /mnt/fff90cb5-06dd-33b3-8815-d78c08ca01d9) status unexpected: exit status 16
at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:280)
at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:138)
at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:264)
at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1013)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1307)
at com.cloud.storage.VolumeManagerImpl.takeSnapshot(VolumeManagerImpl.java:2738)
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-09-09 10:45:47,465 DEBUG [storage.volume.VolumeServiceImpl] (Job-Executor-146:job-1770 = [ 53db2ef6-6a92-4b69-bc5a-ea673814a4b9 ]) Take snapshot: 498 fa
iled
com.cloud.utils.exception.CloudRuntimeException: Failed to create snapshot
at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1040)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1307)
at com.cloud.storage.VolumeManagerImpl.takeSnapshot(VolumeManagerImpl.java:2738)
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)
Caused by: com.cloud.utils.exception.CloudRuntimeException: com.cloud.utils.exception.CloudRuntimeException: com.cloud.utils.exception.CloudRuntimeException:
org.libvirt.LibvirtException: internal error Child process (/bin/umount /mnt/fff90cb5-06dd-33b3-8815-d78c08ca01d9) status unexpected: exit status 16
at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:280)
at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:138)
at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:264)

Agent log

2013-09-09 10:41:59,446 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) Received response: Seq 1-740: { Ans: , MgmtId: 29066118877352, via: 1, Ver: v1, Flags: 100010, [{"com
.cloud.agent.api.PingAnswer":{"_command":

{"hostType":"Routing","hostId":1,"wait":0}

,"result":true,"wait":0}}] }
2013-09-09 10:42:07,696 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) Processing command: com.cloud.agent.api.GetVmStatsCommand
2013-09-09 10:42:14,959 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) can't get storage pool
org.libvirt.LibvirtException: Storage pool not found: no pool with matching uuid
at org.libvirt.ErrorHandler.processError(Unknown Source)
at org.libvirt.Connect.processError(Unknown Source)
at org.libvirt.Connect.storagePoolLookupByUUIDString(Unknown Source)
at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePool(LibvirtStorageAdaptor.java:363)
at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePool(KVMStoragePoolManager.java:104)
at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getPhysicalDisk(KVMStoragePoolManager.java:148)
at com.cloud.hypervisor.kvm.storage.KVMStorageProcessor.backupSnapshot(KVMStorageProcessor.java:657)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:84)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1286)
at com.cloud.agent.Agent.processRequest(Agent.java:525)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)
at com.cloud.utils.nio.Task.run(Task.java:83)
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-09-09 10:42:14,961 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) createStoragePool didn't find existing running pool: org.libvirt.LibvirtExcepti
on: Storage pool not found: no pool with matching uuid, need to create it