[ https://issues.apache.org/jira/browse/CLOUDSTACK-4867?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Valery Ciareszka closed CLOUDSTACK-4867. ---------------------------------------- Resolution: Duplicate Fix Version/s: 4.2.1 > NullPointerException on agent while remounting primary storage > -------------------------------------------------------------- > > Key: CLOUDSTACK-4867 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4867 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the > default.) > Components: Hypervisor Controller > Affects Versions: 4.2.0 > Environment: KVM (CentOS 6.4)/CloudStack 4.2 > Reporter: Valery Ciareszka > Fix For: 4.2.1 > > > This issue appeared suddenly, I have no idea, how has that happened. > Sympthoms: > -no new virtalmachines are created on one of hypervisor servers > -there are NullPointerExceptions in agent log on problem server > -virsh shows no pools > After doing some debugging I was able to repeat this bug manually(see below), > but still have no idea how it occured initially. > Here are steps to reproduce this bug: > I have two primary storages mounted via NFS: > 10.6.20.1:/GIGO1/p1 7.2T 90G 7.1T 2% > /mnt/c59065c8-4d4c-3276-9d12-f170e4cd445e > 10.6.20.2:/GIGO2/p2 7.3T 31G 7.3T 1% > /mnt/bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5 > You should have at least one VM running from NFS storage to reproduce this > issue. > [root@ad111 libvirt]# virsh pool-list > Name State Autostart > ----------------------------------------- > 63cacc3d-185f-45f0-981c-5c4d9d79d665 active no > bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5 active no > c59065c8-4d4c-3276-9d12-f170e4cd445e active no > for now all is ok, I can see localstorage and two NFS shares in pool-list > Let's restart libvirtd: > [root@ad111 ~]# /etc/init.d/libvirtd restart > Stopping libvirtd daemon: [ OK ] > Starting libvirtd daemon: [ OK ] > And pools are gone: > [root@ad111 ~]# virsh pool-list > Name State Autostart > ----------------------------------------- > [root@ad111 ~]# > According to agent log it tries to add pool to libvirt but it fails because > libvirt tries to mount share (which is already mounted) upon adding it: > [root@ad111 ~]# cat << _EOF > pool.xml > <pool type='netfs'> > <name>c59065c8-4d4c-3276-9d12-f170e4cd445e</name> > <uuid>c59065c8-4d4c-3276-9d12-f170e4cd445e</uuid> > <capacity unit='bytes'>7869416079360</capacity> > <allocation unit='bytes'>95770640384</allocation> > <available unit='bytes'>7773645438976</available> > <source> > <host name='10.6.20.1'/> > <dir path='/GIGO1/p1'/> > <format type='auto'/> > </source> > <target> > <path>/mnt/c59065c8-4d4c-3276-9d12-f170e4cd445e</path> > <permissions> > <mode>0755</mode> > <owner>-1</owner> > <group>-1</group> > </permissions> > </target> > </pool> > _EOF > [root@ad111 ~]# virsh pool-create pool.xml > error: Failed to create pool from pool.xml > error: Requested operation is not valid: Target > '/mnt/c59065c8-4d4c-3276-9d12-f170e4cd445e' is already mounted > Agent loops in java.lang.NullPointerExceptions, restart does not help. As a > result, no new VMs could be created on this host. > I was able to resolve this issue next way: > -migrated all vms to another node > -switched on maintenance mode on the problem host > -umount all NFS shares > -switched off maintenance mode on the problem host > Logs: > 2013-10-14 15:25:29,770 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-3:null) Processing command: > com.cloud.agent.api.GetVmStatsCommand > 2013-10-14 15:25:29,771 DEBUG [kvm.resource.LibvirtConnection] > (agentRequest-Handler-3:null) Connection with libvirtd is broken, due to > Cannot write data: Broken pipe > 2013-10-14 15:25:33,091 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-4:null) Processing command: > com.cloud.agent.api.GetHostStatsCommand > 2013-10-14 15:25:33,092 DEBUG [kvm.resource.LibvirtComputingResource] > (agentRequest-Handler-4:null) Executing: /bin/bash -c idle=$(top -b -n 1|grep > Cpu\(s\):|cut -d% -f4|cut -d, -f2);echo $idle > 2013-10-14 15:25:33,224 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-5:null) Processing command: > com.cloud.agent.api.GetStorageStatsCommand > 2013-10-14 15:25:33,228 DEBUG [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-5: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.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2466) > at > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1230) > 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:1146) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > at java.lang.Thread.run(Thread.java:679) > 2013-10-14 15:25:33,236 DEBUG [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-5:null) createStoragePool didn't find existing running > pool: org.libvirt.LibvirtException: Storage pool not found: no pool with > matching uuid, need to create it > 2013-10-14 15:25:33,236 DEBUG [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-5:null) Didn't find an existing storage pool > c59065c8-4d4c-3276-9d12-f170e4cd445e by UUID, checking for pools with > duplicate paths > 2013-10-14 15:25:33,238 DEBUG [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-5:null) Attempting to create storage pool > c59065c8-4d4c-3276-9d12-f170e4cd445e > 2013-10-14 15:25:33,239 DEBUG [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-5:null) <pool type='netfs'> > <name>c59065c8-4d4c-3276-9d12-f170e4cd445e</name> > <uuid>c59065c8-4d4c-3276-9d12-f170e4cd445e</uuid> > <source> > <host name='10.6.20.1'/> > <dir path='/GIGO1/p1'/> > </source> > <target> > <path>/mnt/c59065c8-4d4c-3276-9d12-f170e4cd445e</path> > </target> > </pool> > 2013-10-14 15:25:33,242 ERROR [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-5:null) org.libvirt.LibvirtException: Requested > operation is not valid: Target '/mnt/c59065c8-4d4c-3276-9d12-f170e4cd445e' is > already mounted > 2013-10-14 15:25:33,242 ERROR [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-5:null) Attempting to unmount old mount libvirt is > unaware of at /mnt/c59065c8-4d4c-3276-9d12-f170e4cd445e > 2013-10-14 15:25:33,242 DEBUG [utils.script.Script] > (agentRequest-Handler-5:null) Executing: /bin/bash -c umount > /mnt/c59065c8-4d4c-3276-9d12-f170e4cd445e > 2013-10-14 15:25:33,260 DEBUG [utils.script.Script] > (agentRequest-Handler-5:null) Exit value is 16 > 2013-10-14 15:25:33,261 DEBUG [utils.script.Script] > (agentRequest-Handler-5:null) umount.nfs: > /mnt/c59065c8-4d4c-3276-9d12-f170e4cd445e: device is busyumount.nfs: > /mnt/c59065c8-4d4c-3276-9d12-f170e4cd445e: device is busy > 2013-10-14 15:25:33,262 ERROR [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-5:null) Succeeded in unmounting > /mnt/c59065c8-4d4c-3276-9d12-f170e4cd445e > 2013-10-14 15:25:33,264 ERROR [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-5:null) Target was already mounted, unmounted it but > failed to redefine storage:org.libvirt.LibvirtException: Requested operation > is not valid: Target '/mnt/c59065c8-4d4c-3276-9d12-f170e4cd445e' is already > mounted > 2013-10-14 15:25:33,264 WARN [cloud.agent.Agent] > (agentRequest-Handler-5:null) Caught: > java.lang.NullPointerException > at > com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:539) > at > com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.createStoragePool(KVMStoragePoolManager.java:185) > at > com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePool(KVMStoragePoolManager.java:108) > at > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2466) > at > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1230) > 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:1146) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > at java.lang.Thread.run(Thread.java:679) > 2013-10-14 15:25:33,266 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-5:null) Seq 2-428146789: { Ans: , MgmtId: > 159303462925110, via: 2, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.Answer":{"result":false,"details":"java.lang.NullPointerException\n\tat > > com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:539)\n\tat > > com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.createStoragePool(KVMStoragePoolManager.java:185)\n\tat > > com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePool(KVMStoragePoolManager.java:108)\n\tat > > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2466)\n\tat > > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1230)\n\tat > com.cloud.agent.Agent.processRequest(Agent.java:525)\n\tat > com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)\n\tat > com.cloud.utils.nio.Task.run(Task.java:83)\n\tat > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)\n\tat > > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\n\tat > java.lang.Thread.run(Thread.java:679)\n","wait":0}}] } > 2013-10-14 15:25:33,275 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-2:null) Processing command: > com.cloud.agent.api.GetStorageStatsCommand > 2013-10-14 15:25:33,278 DEBUG [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-2: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.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2466) > at > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1230) > 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:1146) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > at java.lang.Thread.run(Thread.java:679) > 2013-10-14 15:25:33,281 DEBUG [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-2:null) createStoragePool didn't find existing running > pool: org.libvirt.LibvirtException: Storage pool not found: no pool with > matching uuid, need to create it > 2013-10-14 15:25:33,281 DEBUG [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-2:null) Didn't find an existing storage pool > bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5 by UUID, checking for pools with > duplicate paths > 2013-10-14 15:25:33,284 DEBUG [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-2:null) Attempting to create storage pool > bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5 > 2013-10-14 15:25:33,284 DEBUG [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-2:null) <pool type='netfs'> > <name>bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5</name> > <uuid>bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5</uuid> > <source> > <host name='10.6.20.2'/> > <dir path='/GIGO2/p2'/> > </source> > <target> > <path>/mnt/bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5</path> > </target> > </pool> > 2013-10-14 15:25:33,286 ERROR [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-2:null) org.libvirt.LibvirtException: Requested > operation is not valid: Target '/mnt/bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5' is > already mounted > 2013-10-14 15:25:33,287 ERROR [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-2:null) Attempting to unmount old mount libvirt is > unaware of at /mnt/bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5 > 2013-10-14 15:25:33,287 DEBUG [utils.script.Script] > (agentRequest-Handler-2:null) Executing: /bin/bash -c umount > /mnt/bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5 > 2013-10-14 15:25:33,303 DEBUG [utils.script.Script] > (agentRequest-Handler-2:null) Exit value is 16 > 2013-10-14 15:25:33,304 DEBUG [utils.script.Script] > (agentRequest-Handler-2:null) umount.nfs: > /mnt/bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5: device is busyumount.nfs: > /mnt/bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5: device is busy > 2013-10-14 15:25:33,304 ERROR [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-2:null) Succeeded in unmounting > /mnt/bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5 > 2013-10-14 15:25:33,306 ERROR [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-2:null) Target was already mounted, unmounted it but > failed to redefine storage:org.libvirt.LibvirtException: Requested operation > is not valid: Target '/mnt/bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5' is already > mounted > 2013-10-14 15:25:33,307 WARN [cloud.agent.Agent] > (agentRequest-Handler-2:null) Caught: > java.lang.NullPointerException > at > com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:539) > at > com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.createStoragePool(KVMStoragePoolManager.java:185) > at > com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePool(KVMStoragePoolManager.java:108) > at > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2466) > at > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1230) > 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:1146) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) > at java.lang.Thread.run(Thread.java:679) > 2013-10-14 15:25:33,308 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-2:null) Seq 2-428146790: { Ans: , MgmtId: > 159303462925110, via: 2, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.Answer":{"result":false,"details":"java.lang.NullPointerException\n\tat > > com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:539)\n\tat > > com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.createStoragePool(KVMStoragePoolManager.java:185)\n\tat > > com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePool(KVMStoragePoolManager.java:108)\n\tat > > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2466)\n\tat > > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1230)\n\tat > com.cloud.agent.Agent.processRequest(Agent.java:525)\n\tat > com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)\n\tat > com.cloud.utils.nio.Task.run(Task.java:83)\n\tat > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)\n\tat > > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\n\tat > java.lang.Thread.run(Thread.java:679)\n","wait":0}}] } > 2013-10-14 15:25:33,650 DEBUG [kvm.resource.LibvirtComputingResource] > (agentRequest-Handler-4:null) Execution is successful. > 2013-10-14 15:25:33,651 DEBUG [kvm.resource.LibvirtComputingResource] > (agentRequest-Handler-4:null) Executing: /bin/bash -c freeMem=$(free|grep > cache:|awk '{print $4}');echo $freeMem > 2013-10-14 15:25:33,666 DEBUG [kvm.resource.LibvirtComputingResource] > (agentRequest-Handler-4:null) Execution is successful. > 2013-10-14 15:25:33,667 DEBUG [kvm.resource.LibvirtComputingResource] > (agentRequest-Handler-4:null) Executing: /bin/bash -c free|grep Mem:|awk > '{print $2}' > 2013-10-14 15:25:33,680 DEBUG [kvm.resource.LibvirtComputingResource] > (agentRequest-Handler-4:null) Execution is successful. > 2013-10-14 15:25:47,694 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-3:null) Request:Seq 2-428146792: { Cmd , MgmtId: > 159303462925110, via: 2, Ver: v1, Flags: 100011, > [{"com.cloud.agent.api.CheckRouterCommand":{"accessDetails":{"router.name":"r-178-VM","router.ip":"169.254.3.68"},"wait":30}}] > } > 2013-10-14 15:25:47,694 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-1:null) Request:Seq 2-428146791: { Cmd , MgmtId: > 159303462925110, via: 2, Ver: v1, Flags: 100011, > [{"com.cloud.agent.api.CheckRouterCommand":{"accessDetails":{"router.name":"r-178-VM","router.ip":"169.254.3.68"},"wait":30}}] > } > 2013-10-14 15:25:47,695 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-3:null) Processing command: > com.cloud.agent.api.CheckRouterCommand > 2013-10-14 15:25:47,696 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-1:null) Processing command: > com.cloud.agent.api.CheckRouterCommand > 2013-10-14 15:25:47,696 DEBUG > [resource.virtualnetwork.VirtualRoutingResource] > (agentRequest-Handler-3:null) Executing: > /usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh > checkrouter.sh 169.254.3.68 > 2013-10-14 15:25:47,696 DEBUG > [resource.virtualnetwork.VirtualRoutingResource] > (agentRequest-Handler-1:null) Executing: > /usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh > checkrouter.sh 169.254.3.68 > 2013-10-14 15:25:47,846 DEBUG > [resource.virtualnetwork.VirtualRoutingResource] > (agentRequest-Handler-1:null) Execution is successful. > 2013-10-14 15:25:47,848 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-1:null) Seq 2-428146791: { Ans: , MgmtId: > 159303462925110, via: 2, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.CheckRouterAnswer":{"state":"BACKUP","isBumped":false,"result":true,"details":"Status: > BACKUP&Bumped: NO","wait":0}}] } > 2013-10-14 15:25:47,951 DEBUG > [resource.virtualnetwork.VirtualRoutingResource] > (agentRequest-Handler-3:null) Execution is successful. > 2013-10-14 15:25:47,953 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-3:null) Seq 2-428146792: { Ans: , MgmtId: > 159303462925110, via: 2, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.CheckRouterAnswer":{"state":"BACKUP","isBumped":false,"result":true,"details":"Status: > BACKUP&Bumped: NO","wait":0}}] } > 2013-10-14 15:25:56,631 DEBUG [kvm.resource.LibvirtComputingResource] > (UgentTask-5:null) Executing: > /usr/share/cloudstack-common/scripts/vm/network/security_group.py > get_rule_logs_for_vms > 2013-10-14 15:25:56,821 DEBUG [kvm.resource.LibvirtComputingResource] > (UgentTask-5:null) Execution is successful. > 2013-10-14 15:25:56,823 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending > ping: Seq 2-28: { Cmd , MgmtId: -1, via: 2, Ver: v1, Flags: 11, > [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":2,"wait":0}}] > } > 2013-10-14 15:25:56,834 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) > Received response: Seq 2-28: { Ans: , MgmtId: 159303462925110, via: 2, Ver: > v1, Flags: 100010, > [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":2,"wait":0},"result":true,"wait":0}}] > } > 2013-10-14 15:25:57,470 DEBUG [kvm.resource.KVMHAMonitor] (Thread-30:null) > Failed to lookup libvirt storage pool c59065c8-4d4c-3276-9d12-f170e4cd445e > due to: org.libvirt.LibvirtException: Storage pool not found: no pool with > matching uuid > 2013-10-14 15:25:57,471 DEBUG [kvm.resource.KVMHAMonitor] (Thread-30:null) > removing pool from HA monitor since it was deleted > 2013-10-14 15:25:57,471 DEBUG [utils.script.Script] (Thread-30:null) > Executing: /bin/bash -c umount /mnt/c59065c8-4d4c-3276-9d12-f170e4cd445e > 2013-10-14 15:25:57,490 DEBUG [utils.script.Script] (Thread-30:null) Exit > value is 16 > 2013-10-14 15:25:57,490 DEBUG [utils.script.Script] (Thread-30:null) > umount.nfs: /mnt/c59065c8-4d4c-3276-9d12-f170e4cd445e: device is > busyumount.nfs: /mnt/c59065c8-4d4c-3276-9d12-f170e4cd445e: device is busy > 2013-10-14 15:25:57,493 DEBUG [kvm.resource.KVMHAMonitor] (Thread-30:null) > Failed to lookup libvirt storage pool bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5 > due to: org.libvirt.LibvirtException: Storage pool not found: no pool with > matching uuid > 2013-10-14 15:25:57,494 DEBUG [kvm.resource.KVMHAMonitor] (Thread-30:null) > removing pool from HA monitor since it was deleted > 2013-10-14 15:25:57,494 DEBUG [utils.script.Script] (Thread-30:null) > Executing: /bin/bash -c umount /mnt/bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5 > 2013-10-14 15:25:57,511 DEBUG [utils.script.Script] (Thread-30:null) Exit > value is 16 > 2013-10-14 15:25:57,512 DEBUG [utils.script.Script] (Thread-30:null) > umount.nfs: /mnt/bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5: device is > busyumount.nfs: /mnt/bd32f762-a1f0-3a65-b9bc-fdb6d1d681b5: device is busy -- This message was sent by Atlassian JIRA (v6.1#6144)