Return-Path: X-Original-To: apmail-cloudstack-issues-archive@www.apache.org Delivered-To: apmail-cloudstack-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 4EE5E102E5 for ; Tue, 14 Jan 2014 00:17:10 +0000 (UTC) Received: (qmail 4131 invoked by uid 500); 14 Jan 2014 00:14:17 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 4114 invoked by uid 500); 14 Jan 2014 00:14:07 -0000 Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cloudstack.apache.org Delivered-To: mailing list issues@cloudstack.apache.org Received: (qmail 4032 invoked by uid 500); 14 Jan 2014 00:14:03 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 3968 invoked by uid 99); 14 Jan 2014 00:13:55 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 14 Jan 2014 00:13:55 +0000 Date: Tue, 14 Jan 2014 00:13:55 +0000 (UTC) From: "edison su (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Closed] (CLOUDSTACK-5737) KVM - Recurring Snapshots - Few snapshots fail to get created becasue of "org.libvirt.LibvirtException: Storage pool not found: no storage pool with matching uuid" MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-5737?page=3Dcom.atl= assian.jira.plugin.system.issuetabpanels:all-tabpanel ] edison su closed CLOUDSTACK-5737. --------------------------------- need to turn off concurrent commands send to hypervisor > KVM - Recurring Snapshots - Few snapshots fail to get created becasue of = "org.libvirt.LibvirtException: Storage pool not found: no storage pool with= matching uuid" > -------------------------------------------------------------------------= ---------------------------------------------------------------------------= --------------- > > Key: CLOUDSTACK-5737 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-573= 7 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the defa= ult.)=20 > Components: Management Server > Affects Versions: 4.3.0 > Environment: Build from 4.3 > Reporter: Sangeetha Hariharan > Assignee: edison su > Priority: Critical > Fix For: 4.3.0 > > Attachments: kvm.rar > > > Set up: > Advanced zone set up with 2 KVM (rhel 63) hosts. > Steps to reproduce the problem: > Deploy about 17 Vms in both hosts. > Start "Hourly" snapshot for all the ROOT volumes of these Vms. > Few snapshots fail to get created becasue of "org.libvirt.LibvirtExceptio= n: Storage pool not found: no storage pool with matching uuid" > Following exception seen in management server logs: > 2014-01-02 19:43:01,296 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Exec= utor-165:ctx-9fc82249 ctx-387acac1) Complete async job-238, jobStatus: SUCC= EEDED, resultCode: 0, result: rO0ABXNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgABS= gAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAAAAAAAAAEA > 2014-01-02 19:43:01,299 DEBUG [c.c.a.t.Request] (AgentManager-Handler-4:n= ull) Seq 1-1038163041: Processing: { Ans: , MgmtId: 82324189320212, via: 1= , Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false,"detai= ls":"com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtEx= ception: Storage pool not found: no storage pool with matching uuid\n\tat c= om.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.deleteStoragePool(Lib= virtStorageAdaptor.java:620)\n\tat com.cloud.hypervisor.kvm.storage.Libvirt= StorageAdaptor.deleteStoragePool(LibvirtStorageAdaptor.java:1214)\n\tat com= .cloud.hypervisor.kvm.storage.LibvirtStoragePool.delete(LibvirtStoragePool.= java:256)\n\tat com.cloud.hypervisor.kvm.storage.KVMStorageProcessor.backup= Snapshot(KVMStorageProcessor.java:807)\n\tat com.cloud.storage.resource.Sto= rageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.= java:90)\n\tat com.cloud.storage.resource.StorageSubsystemCommandHandlerBas= e.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:50)\n\tat c= om.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(Li= bvirtComputingResource.java:1316)\n\tat com.cloud.agent.Agent.processReques= t(Agent.java:498)\n\tat com.cloud.agent.Agent$AgentRequestHandler.doTask(Ag= ent.java:806)\n\tat com.cloud.utils.nio.Task.run(Task.java:83)\n\tat java.u= til.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)\n= \tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.= java:603)\n\tat java.lang.Thread.run(Thread.java:679)\n","wait":0}}] } > 2014-01-02 19:43:01,299 DEBUG [c.c.a.t.Request] (Job-Executor-164:ctx-af4= c7558 ctx-7d147b95) Seq 1-1038163041: Received: { Ans: , MgmtId: 823241893= 20212, via: 1, Ver: v1, Flags: 10, { Answer } } > 2014-01-02 19:43:01,300 DEBUG [c.c.a.t.Request] (AgentManager-Handler-1:n= ull) Seq 1-1038163040: Processing: { Ans: , MgmtId: 82324189320212, via: 1= , Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false,"detai= ls":"com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtEx= ception: Storage pool not found: no storage pool with matching uuid\n\tat c= om.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.deleteStoragePool(Lib= virtStorageAdaptor.java:620)\n\tat com.cloud.hypervisor.kvm.storage.Libvirt= StorageAdaptor.deleteStoragePool(LibvirtStorageAdaptor.java:1214)\n\tat com= .cloud.hypervisor.kvm.storage.LibvirtStoragePool.delete(LibvirtStoragePool.= java:256)\n\tat com.cloud.hypervisor.kvm.storage.KVMStorageProcessor.backup= Snapshot(KVMStorageProcessor.java:807)\n\tat com.cloud.storage.resource.Sto= rageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.= java:90)\n\tat com.cloud.storage.resource.StorageSubsystemCommandHandlerBas= e.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:50)\n\tat c= om.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(Li= bvirtComputingResource.java:1316)\n\tat com.cloud.agent.Agent.processReques= t(Agent.java:498)\n\tat com.cloud.agent.Agent$AgentRequestHandler.doTask(Ag= ent.java:806)\n\tat com.cloud.utils.nio.Task.run(Task.java:83)\n\tat java.u= til.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)\n= \tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.= java:603)\n\tat java.lang.Thread.run(Thread.java:679)\n","wait":0}}] } > 2014-01-02 19:43:01,300 DEBUG [c.c.a.t.Request] (AgentManager-Handler-1:n= ull) Seq 1-1038163042: Processing: { Ans: , MgmtId: 82324189320212, via: 1= , Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false,"detai= ls":"com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtEx= ception: Storage pool not found: no storage pool with matching uuid\n\tat c= om.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.deleteStoragePool(Lib= virtStorageAdaptor.java:620)\n\tat com.cloud.hypervisor.kvm.storage.Libvirt= StorageAdaptor.deleteStoragePool(LibvirtStorageAdaptor.java:1214)\n\tat com= .cloud.hypervisor.kvm.storage.LibvirtStoragePool.delete(LibvirtStoragePool.= java:256)\n\tat com.cloud.hypervisor.kvm.storage.KVMStorageProcessor.backup= Snapshot(KVMStorageProcessor.java:807)\n\tat com.cloud.storage.resource.Sto= rageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.= java:90)\n\tat com.cloud.storage.resource.StorageSubsystemCommandHandlerBas= e.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:50)\n\tat c= om.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(Li= bvirtComputingResource.java:1316)\n\tat com.cloud.agent.Agent.processReques= t(Agent.java:498)\n\tat com.cloud.agent.Agent$AgentRequestHandler.doTask(Ag= ent.java:806)\n\tat com.cloud.utils.nio.Task.run(Task.java:83)\n\tat java.u= til.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)\n= \tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.= java:603)\n\tat java.lang.Thread.run(Thread.java:679)\n","wait":0}}] } > 2014-01-02 19:43:01,300 DEBUG [c.c.a.t.Request] (Job-Executor-162:ctx-6ea= dd346 ctx-bfe82c20) Seq 1-1038163040: Received: { Ans: , MgmtId: 823241893= 20212, via: 1, Ver: v1, Flags: 10, { Answer } } > 2014-01-02 19:43:01,301 DEBUG [c.c.a.t.Request] (Job-Executor-163:ctx-b30= 2ed15 ctx-d6e2ae7f) Seq 1-1038163042: Received: { Ans: , MgmtId: 823241893= 20212, via: 1, Ver: v1, Flags: 10, { Answer } } > 2014-01-02 19:43:01,330 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor= -6:ctx-8795a455) Add job-236 into job monitoring > 2014-01-02 19:43:01,330 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Exec= utor-6:ctx-8795a455) Executing AsyncJobVO {id:236, userId: 1, accountId: 4,= instanceType: Snapshot, instanceId: 16, cmd: org.apache.cloudstack.api.com= mand.user.snapshot.CreateSnapshotCmd, cmdInfo: {"id":"16","ctxUserId":"1","= volumeid":"27","ctxAccountId":"4","ctxStartEventId":"1","policyid":"13"}, c= mdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:= null, initMsid: 82324189320212, completeMsid: null, lastUpdated: null, las= tPolled: null, created: Thu Jan 02 18:44:19 EST 2014} > 2014-01-02 19:43:01,343 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Exec= utor-165:ctx-9fc82249) Done executing com.cloud.storage.VmWorkTakeVolumeSna= pshot for job-238 > 2014-01-02 19:43:01,326 DEBUG [c.c.s.s.SnapshotManagerImpl] (Job-Executor= -164:ctx-af4c7558 ctx-7d147b95) Failed to create snapshot > com.cloud.utils.exception.CloudRuntimeException: com.cloud.utils.exceptio= n.CloudRuntimeException: org.libvirt.LibvirtException: Storage pool not fou= nd: no storage pool with matching uuid > at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.deleteS= toragePool(LibvirtStorageAdaptor.java:620) > at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.deleteS= toragePool(LibvirtStorageAdaptor.java:1214) > at com.cloud.hypervisor.kvm.storage.LibvirtStoragePool.delete(Lib= virtStoragePool.java:256) > at com.cloud.hypervisor.kvm.storage.KVMStorageProcessor.backupSna= pshot(KVMStorageProcessor.java:807) > at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.= execute(StorageSubsystemCommandHandlerBase.java:90) > at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.= handleStorageCommands(StorageSubsystemCommandHandlerBase.java:50) > at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.exe= cuteRequest(LibvirtComputingResource.java:1316) > at com.cloud.agent.Agent.processRequest(Agent.java:498) > at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:80= 6) > at com.cloud.utils.nio.Task.run(Task.java:83) > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolEx= ecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolE= xecutor.java:603) > at java.lang.Thread.run(Thread.java:679) > at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.bac= kupSnapshot(SnapshotServiceImpl.java:280) > at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrate= gy.backupSnapshot(XenserverSnapshotStrategy.java:142) > at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrate= gy.takeSnapshot(XenserverSnapshotStrategy.java:301) > at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(Sn= apshotManagerImpl.java:951) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccess= orImpl.java:57) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMeth= odAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:601) > at org.springframework.aop.support.AopUtils.invokeJoinpointUsingR= eflection(AopUtils.java:317) > at org.springframework.aop.framework.ReflectiveMethodInvocation.i= nvokeJoinpoint(ReflectiveMethodInvocation.java:183) > at org.springframework.aop.framework.ReflectiveMethodInvocation.p= roceed(ReflectiveMethodInvocation.java:150) > at org.springframework.aop.interceptor.ExposeInvocationIntercepto= r.invoke(ExposeInvocationInterceptor.java:91) > at org.springframework.aop.framework.ReflectiveMethodInvocation.p= roceed(ReflectiveMethodInvocation.java:172) > at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(Jd= kDynamicAopProxy.java:204) > at $Proxy160.takeSnapshot(Unknown Source) > at org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSna= pshot(VolumeServiceImpl.java:1371) > at com.cloud.storage.VolumeApiServiceImpl.orchestrateTakeVolumeSn= apshot(VolumeApiServiceImpl.java:1723) > at com.cloud.storage.VolumeApiServiceImpl.handleVmWorkJob(VolumeA= piServiceImpl.java:2478) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccess= orImpl.java:57) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMeth= odAccessorImpl.java:43) > at java.lang.reflect.Method.invoke(Method.java:601) > at org.springframework.aop.support.AopUtils.invokeJoinpointUsingR= eflection(AopUtils.java:317) > at org.springframework.aop.framework.ReflectiveMethodInvocation.i= nvokeJoinpoint(ReflectiveMethodInvocation.java:183) > at org.springframework.aop.framework.ReflectiveMethodInvocation.p= roceed(ReflectiveMethodInvocation.java:150) > at org.springframework.aop.interceptor.ExposeInvocationIntercepto= r.invoke(ExposeInvocationInterceptor.java:91) > at org.springframework.aop.framework.ReflectiveMethodInvocation.p= roceed(ReflectiveMethodInvocation.java:172) > at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(Jd= kDynamicAopProxy.java:204) > at $Proxy195.handleVmWorkJob(Unknown Source) > at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.ja= va:99) > at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$= 5.runInContext(AsyncJobManagerImpl.java:522) > at org.apache.cloudstack.managed.context.ManagedContextRunnable$1= .run(ManagedContextRunnable.java:49) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt$1.call(DefaultManagedContext.java:56) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt.callWithContext(DefaultManagedContext.java:103) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt.runWithContext(DefaultManagedContext.java:53) > at org.apache.cloudstack.managed.context.ManagedContextRunnable.r= un(ManagedContextRunnable.java:46) > 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(ThreadPoolEx= ecutor.java:1110) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolE= xecutor.java:603) > at java.lang.Thread.run(Thread.java:722) > 2014-01-02 19:43:01,346 DEBUG [c.c.s.s.SnapshotManagerImpl] (Job-Executor= -162:ctx-6eadd346 ctx-bfe82c20) Failed to create snapshot > com.cloud.utils.exception.CloudRuntimeException: com.cloud.utils.exceptio= n.CloudRuntimeException: org.libvirt.LibvirtException: Storage pool not fou= nd: no storage pool with matching uuid > at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.deleteS= toragePool(LibvirtStorageAdaptor.java:620) > at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.deleteS= toragePool(LibvirtStorageAdaptor.java:1214) > at com.cloud.hypervisor.kvm.storage.LibvirtStoragePool.delete(Lib= virtStoragePool.java:256) > at com.cloud.hypervisor.kvm.storage.KVMStorageProcessor.backupSna= pshot(KVMStorageProcessor.java:807) > at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.= execute(StorageSubsystemCommandHandlerBase.java:90) > at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.= handleStorageCommands(StorageSubsystemCommandHandlerBase.java:50) > at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.exe= cuteRequest(LibvirtComputingResource.java:1316) > at com.cloud.agent.Agent.processRequest(Agent.java:498) > at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:80= 6) > mysql> select id,volume_id,name,status from snapshots where status=3D"Err= or"; > +----+-----------+-------------------------------------------------+-----= ---+ > | id | volume_id | name | stat= us | > +----+-----------+-------------------------------------------------+-----= ---+ > | 13 | 30 | TestVM-tiny-host-1ps-0-4_ROOT-30_20140102234419 | Erro= r | > | 14 | 29 | TestVM-tiny-host-1ps-0-3_ROOT-29_20140102234419 | Erro= r | > | 15 | 28 | TestVM-tiny-host-1ps-0-2_ROOT-28_20140102234419 | Erro= r | > | 29 | 28 | TestVM-tiny-host-1ps-0-2_ROOT-28_20140103014419 | Erro= r | > +----+-----------+-------------------------------------------------+-----= ---+ > 4 rows in set (0.00 sec) -- This message was sent by Atlassian JIRA (v6.1.5#6160)