[
https://issues.apache.org/jira/browse/CLOUDSTACK-2729?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13745968#comment-13745968
]
Wei Zhou commented on CLOUDSTACK-2729:
--------------------------------------
The same issue.
Host 3 delete volume d8a957a3-67ec-478c-b10a-c5c0e829a1dd at 2013-08-18
04:24:49,724
When Host 2 want to delete another volume be9438e9-62b8-4d88-833e-95357af3b240
at 2013-08-18 04:25:11,353, it failed.
The error in libvirtd.log on host 2 shows:
2013-08-18 11:25:21.680+0000: 5692: error :
virStorageBackendVolOpenCheckMode:1028 : cannot stat file
'/mnt/fff90cb5-06dd-33b3-8815-d78c08ca01d9/d8a957a3-67ec-478c-b10a-c5c0e829a1dd':
Stale NFS file handle
It is a bit different from previous error. I checked on website, the error
(Stale NFS file handle) is also because of the file is removed from server.
maybe some latency between NFS clients?
Do we need to lock the thread for some seconds after deleting a volume?
Any idea?
> [Automation] Libvirt failed find primary storage and VM deployment failed
> ----------------------------------------------------------------------------
>
> Key: CLOUDSTACK-2729
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-2729
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Storage Controller
> Affects Versions: 4.2.0
> Environment: Master branch build
> Automation environment - KVM
> Reporter: Rayees Namathponnan
> Assignee: edison su
> Priority: Blocker
> Fix For: 4.2.0
>
> Attachments: 2729_08_13_13_Agents.rar, 2729_08_13_13_Managment.rar,
> 2729.rar, Agent_2729.rar, agent.log, cloud.dmp,
> CLOUDSTACK-2729_8_18_Agent.rar, CLOUDSTACK-2729_8_18_MS.rar,
> CLOUDSTACK-2729.rar, management-server.rar
>
>
> Failed to deploy VM in automation, environment created with , 2 hosts and 2
> primary storages in a cluster
> 1) /export/home/rayees/SC_QA_AUTO4/primary2
> 2) /export/home/rayees/SC_QA_AUTO4/primary
> Libvirt failed to find the primary storage
> /export/home/rayees/SC_QA_AUTO4/primary and VM deployment failed
> MS log
> 2013-05-28 21:11:44,540 DEBUG [agent.transport.Request] (consoleproxy-1:null)
> Seq 4-936706756: Sending { Cmd , MgmtId: 29066118877352, via: 4, Ver: v1,
> Flags: 100111,
> [{"StartCommand":{"vm":{"id":29,"name":"v-29-QA","type":"ConsoleProxy","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"Debian
> GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP type=consoleproxy
> host=10.223.49.195 port=8250 name=v-29-QA premium=true zone=1 pod=1
> guid=Proxy.29 proxy_vm=29 disable_rp_filter=true eth2ip=10.223.122.73
> eth2mask=255.255.255.192 gateway=10.223.122.65 eth0ip=169.254.0.154
> eth0mask=255.255.0.0 eth1ip=10.223.50.96 eth1mask=255.255.255.192
> mgmtcidr=10.223.49.192/26 localgw=10.223.50.65 internaldns1=10.223.110.254
> dns1=72.52.126.11","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"d099568827911cef","params":{},"uuid":"5a146833-6a8c-44e5-83c0-50f34accf513","disks":[{"id":32,"name":"ROOT-29","mountPoint":"/export/home/rayees/SC_QA_AUTO4/primary","path":"f6f8d865-e9c0-4188-8a33-6c6383ca5075","size":276406784,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"fff90cb5-06dd-33b3-8815-d78c08ca01d9","deviceId":0}],"nics":[{"deviceId":2,"networkRateMbps":-1,"defaultNic":true,"uuid":"21175978-96bd-4160-8228-8ad15aa40c66","ip":"10.223.122.73","netmask":"255.255.255.192","gateway":"10.223.122.65","mac":"06:2e:5a:00:00:42","dns1":"72.52.126.11","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://1221","isolationUri":"vlan://1221","isSecurityGroupEnabled":false},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"e0651452-a76e-4564-96b2-3d5d51e9bcd6","ip":"169.254.0.154","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:00:9a","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"0765c229-468e-4dfd-8382-24ac49791a8d","ip":"10.223.50.96","netmask":"255.255.255.192","gateway":"10.223.50.65","mac":"06:a8:e8:00:00:1d","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false}]},"hostIp":"10.223.50.66","wait":0}},{"check.CheckSshCommand":{"ip":"169.254.0.154","port":3922,"interval":6,"retries":100,"name":"v-29-QA","wait":0}}]
> }
> 2013-05-28 21:11:44,552 DEBUG [agent.transport.Request]
> (AgentManager-Handler-1:null) Seq 4-936706756: Processing: { Ans: , MgmtId:
> 29066118877352, via: 4, Ver: v1, Flags: 110,
> [{"Answer":{"result":false,"details":"com.cloud.utils.exception.CloudRuntimeException:
> org.libvirt.LibvirtException: Storage pool not found: no pool with matching
> uuid\n\tat
> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePool(LibvirtStorageAdaptor.java:380)\n\tat
>
> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePool(KVMStoragePoolManager.java:72)\n\tat
>
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.createVbd(LibvirtComputingResource.java:3399)\n\tat
>
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3293)\n\tat
>
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1187)\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:1110)\n\tat
>
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)\n\tat
>
> java.lang.Thread.run(Thread.java:679)\n","wait":0}},{"Answer":{"result":false,"details":"Stopped
> by previous failure","wait":0}}] }
> 2013-05-28 21:11:44,552 DEBUG [agent.manager.AgentAttache]
> (AgentManager-Handler-1:null) Seq 4-936706756: No more commands found
> 2013-05-28 21:11:44,552 DEBUG [agent.transport.Request] (consoleproxy-1:null)
> Seq 4-936706756: Received: { Ans: , MgmtId: 29066118877352, via: 4, Ver: v1,
> Flags: 110, { Answer, Answer } }
> 2013-05-28 21:11:44,559 ERROR [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Failed to start instance VM[ConsoleProxy|v-29-QA]
> com.cloud.utils.exception.CloudRuntimeException: Unable to get answer that is
> of class com.cloud.agent.api.StartAnswer
> at com.cloud.agent.manager.Commands.getAnswer(Commands.java:80)
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:873)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:550)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:543)
> at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:561)
> at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:923)
> at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1667)
> at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
> at
> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111)
> Agent log
> 2013-05-29 01:06:07,911 DEBUG [cloud.agent.Agent]
> (agentRequest-Handler-4:null) Request:Seq 4-936706739: { Cmd , MgmtId:
> 29066118877352, via: 4, Ver: v1, Flags: 100111,
> [{"StartCommand":{"vm":{"id":29,"name":"v-29-QA","type":"ConsoleProxy","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"Debian
> GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP type=consoleproxy
> host=10.223.49.195 port=8250 name=v-29-QA premium=true zone=1 pod=1
> guid=Proxy.29 proxy_vm=29 disable_rp_filter=true eth2ip=10.223.122.73
> eth2mask=255.255.255.192 gateway=10.223.122.65 eth0ip=169.254.1.243
> eth0mask=255.255.0.0 eth1ip=10.223.50.93 eth1mask=255.255.255.192
> mgmtcidr=10.223.49.192/26 localgw=10.223.50.65 internaldns1=10.223.110.254
> dns1=72.52.126.11","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"d099568827911cef","params":{},"uuid":"5a146833-6a8c-44e5-83c0-50f34accf513","disks":[{"id":32,"name":"ROOT-29","mountPoint":"/export/home/rayees/SC_QA_AUTO4/primary","path":"f6f8d865-e9c0-4188-8a33-6c6383ca5075","size":276406784,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"fff90cb5-06dd-33b3-8815-d78c08ca01d9","deviceId":0}],"nics":[{"deviceId":2,"networkRateMbps":-1,"defaultNic":true,"uuid":"21175978-96bd-4160-8228-8ad15aa40c66","ip":"10.223.122.73","netmask":"255.255.255.192","gateway":"10.223.122.65","mac":"06:2e:5a:00:00:42","dns1":"72.52.126.11","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://1221","isolationUri":"vlan://1221","isSecurityGroupEnabled":false},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"e0651452-a76e-4564-96b2-3d5d51e9bcd6","ip":"169.254.1.243","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:01:f3","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"0765c229-468e-4dfd-8382-24ac49791a8d","ip":"10.223.50.93","netmask":"255.255.255.192","gateway":"10.223.50.65","mac":"06:49:6a:00:00:1a","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false}]},"hostIp":"10.223.50.66","wait":0}},{"check.CheckSshCommand":{"ip":"169.254.1.243","port":3922,"interval":6,"retries":100,"name":"v-29-QA","wait":0}}]
> }
> 2013-05-29 01:06:07,912 DEBUG [cloud.agent.Agent]
> (agentRequest-Handler-4:null) Processing command:
> com.cloud.agent.api.StartCommand
> 2013-05-29 01:06:07,923 WARN [cloud.agent.Agent]
> (agentRequest-Handler-4:null) Caught:
> com.cloud.utils.exception.CloudRuntimeException:
> org.libvirt.LibvirtException: Storage pool not found: no pool with matching
> uuid
> at
> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePool(LibvirtStorageAdaptor.java:380)
> at
> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePool(KVMStoragePoolManager.java:72)
> at
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.createVbd(LibvirtComputingResource.java:3399)
> at
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3293)
> at
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1187)
> 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)
> > create VM issuing create command with primary storage
> > “/export/home/rayees/SC_QA_AUTO4/primary” but its not available in pool-list
> [root@Rack2Host11 ~]# virsh pool-list --all
> Name State Autostart
> -----------------------------------------
> 1c9fcb9a-aece-453b-8510-4de4b4dbffdc active no
> 41b632b5-40b3-3024-a38b-ea259c72579f active no
> [root@Rack2Host11 ~]#
> [root@Rack2Host11 ~]#
> [root@Rack2Host11 ~]# virsh pool-dumpxml 1c9fcb9a-aece-453b-8510-4de4b4dbffdc
> <pool type='dir'>
> <name>1c9fcb9a-aece-453b-8510-4de4b4dbffdc</name>
> <uuid>1c9fcb9a-aece-453b-8510-4de4b4dbffdc</uuid>
> <capacity unit='bytes'>237777190912</capacity>
> <allocation unit='bytes'>2098745344</allocation>
> <available unit='bytes'>235678445568</available>
> <source>
> </source>
> <target>
> <path>/var/lib/libvirt/images</path>
> <permissions>
> <mode>0700</mode>
> <owner>-1</owner>
> <group>-1</group>
> </permissions>
> </target>
> </pool>
> [root@Rack2Host11 ~]# virsh pool-dumpxml 41b632b5-40b3-3024-a38b-ea259c72579f
> <pool type='netfs'>
> <name>41b632b5-40b3-3024-a38b-ea259c72579f</name>
> <uuid>41b632b5-40b3-3024-a38b-ea259c72579f</uuid>
> <capacity unit='bytes'>11810778316800</capacity>
> <allocation unit='bytes'>9045745336320</allocation>
> <available unit='bytes'>2765032980480</available>
> <source>
> <host name='10.223.110.232'/>
> <dir path='/export/home/rayees/SC_QA_AUTO4/primary2'/>
> <format type='auto'/>
> </source>
> <target>
> <path>/mnt/41b632b5-40b3-3024-a38b-ea259c72579f</path>
> <permissions>
> <mode>0700</mode>
> <owner>-1</owner>
> <group>-1</group>
> </permissions>
> </target>
> </pool>
--
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
