cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Rayees Namathponnan (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (CLOUDSTACK-4456) [Automation] Vm deployment from template is failed; due to some race condition in KVM
Date Thu, 22 Aug 2013 18:39:56 GMT

     [ https://issues.apache.org/jira/browse/CLOUDSTACK-4456?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Rayees Namathponnan updated CLOUDSTACK-4456:
--------------------------------------------

    Summary: [Automation] Vm deployment from template is failed; due to some race condition
in KVM  (was: [Automation] Vm deployment while creating from template is failed; due to some
race condition in KVM)
    
> [Automation] Vm deployment from template is failed; due to some race condition in KVM
> -------------------------------------------------------------------------------------
>
>                 Key: CLOUDSTACK-4456
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4456
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>          Components: Automation, KVM, Management Server, Template
>    Affects Versions: 4.2.0
>         Environment: Automation 
> 4.2
>            Reporter: Rayees Namathponnan
>            Priority: Critical
>             Fix For: 4.2.0
>
>
> This issue observed during automation run, In attached log i can see multiple deployment
failed due to same issue, here the once effected test case 
> integration.component.test_blocker_bugs.TestTemplate.test_01_create_template
> Test case performing below operation 
> 1) Create template from http url (ubuntu-10-04-64bit-server.qcow2)
> 2) Deploy vm from this template 
> Actual Result 
> ---------------------
> Deployment failed with below error;  look like MS deleting template after creating the
volume 
> IN MS Search for job-899 
> 2013-08-21 22:07:12,383 DEBUG [cloud.network.NetworkManagerImpl] (Job-Executor-66:job-899
= [ 461fc03f-6d0a-488f-9cf3-7cf1a537b26c ]) Asking BareMetalUserdata to prepare for Nic[194-188-97ae23d5-67ea-46c1-91e6-4e6ef35c22ae-10.223.250.231]
> 2013-08-21 22:07:12,389 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-66:job-899
= [ 461fc03f-6d0a-488f-9cf3-7cf1a537b26c ]) Checking if we need to prepare 1 volumes for VM[User|daf71095-b010-45f0-9e46-3bf51ee6a59c]
> 2013-08-21 22:07:12,389 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-66:job-899
= [ 461fc03f-6d0a-488f-9cf3-7cf1a537b26c ]) No need to recreate the volume: Vol[238|vm=188|ROOT],
since it already has a pool assigned: 1, adding disk to VM
> 2013-08-21 22:07:12,408 DEBUG [agent.transport.Request] (Job-Executor-66:job-899 = [
461fc03f-6d0a-488f-9cf3-7cf1a537b26c ]) Seq 2-949159112: Sending  { Cmd , MgmtId: 73187150500751,
via: 2, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StartCommand":{"vm":{"id":188,"name":"i-287-188-TestVM","type":"User","cpus":1,"minSpeed":100,"maxSpeed":100,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"CentOS
5.5 (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"a79bd4d41d554b1a","params":{"Message.ReservedCapacityFreed.Flag":"false"},"uuid":"daf71095-b010-45f0-9e46-3bf51ee6a59c","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"eba8fc74-aa6e-43a9-8dae-5501a0dd490f","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9d444441-b138-3a13-974c-fa506683da4d","id":1,"poolType":"NetworkFilesystem","host":"nfs1-ccp.citrix.com","path":"/home/common/automation/SC_QA_AUTO5/primary1","port":2049}},"name":"ROOT-188","size":5368709120,"path":"5ce3b7d0-07c1-4d3b-9c00-2c6ad8716635","volumeId":238,"vmName":"i-287-188-TestVM","accountId":287,"format":"QCOW2","id":238,"hypervisorType":"KVM"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"3cf9efdc-212d-46f6-b818-071450e602fd","ip":"10.223.250.231","netmask":"255.255.255.192","gateway":"10.223.250.193","mac":"06:5f:a0:00:00:24","dns1":"8.8.8.8","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true}]},"hostIp":"10.223.250.195","executeInSequence":false,"wait":0}}]
}
> 2013-08-21 22:07:12,957 DEBUG [agent.transport.Request] (AgentManager-Handler-7:null)
Seq 2-949159112: Processing:  { Ans: , MgmtId: 73187150500751, via: 2, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StartAnswer":{"vm":{"id":188,"name":"i-287-188-TestVM","type":"User","cpus":1,"minSpeed":100,"maxSpeed":100,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"CentOS
5.5 (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"a79bd4d41d554b1a","vncAddr":"10.223.250.195","params":{"Message.ReservedCapacityFreed.Flag":"false"},"uuid":"daf71095-b010-45f0-9e46-3bf51ee6a59c","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"eba8fc74-aa6e-43a9-8dae-5501a0dd490f","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9d444441-b138-3a13-974c-fa506683da4d","id":1,"poolType":"NetworkFilesystem","host":"nfs1-ccp.citrix.com","path":"/home/common/automation/SC_QA_AUTO5/primary1","port":2049}},"name":"ROOT-188","size":5368709120,"path":"5ce3b7d0-07c1-4d3b-9c00-2c6ad8716635","volumeId":238,"vmName":"i-287-188-TestVM","accountId":287,"format":"QCOW2","id":238,"hypervisorType":"KVM"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"3cf9efdc-212d-46f6-b818-071450e602fd","ip":"10.223.250.231","netmask":"255.255.255.192","gateway":"10.223.250.193","mac":"06:5f:a0:00:00:24","dns1":"8.8.8.8","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true}]},"result":false,"details":"internal
error Process exited while reading console log output: char device redirected to /dev/pts/3\nqemu-kvm:
-drive file=/mnt/9d444441-b138-3a13-974c-fa506683da4d/5ce3b7d0-07c1-4d3b-9c00-2c6ad8716635,if=none,id=drive-virtio-disk0,format=qcow2,cache=none:
could not open disk image /mnt/9d444441-b138-3a13-974c-fa506683da4d/5ce3b7d0-07c1-4d3b-9c00-2c6ad8716635:
Operation not supported\n","wait":0}}] }
> 2013-08-21 22:07:12,957 DEBUG [agent.transport.Request] (Job-Executor-66:job-899 = [
461fc03f-6d0a-488f-9cf3-7cf1a537b26c ]) Seq 2-949159112: Received:  { Ans: , MgmtId: 73187150500751,
via: 2, Ver: v1, Flags: 10, { StartAnswer } }
> 2013-08-21 22:07:12,960 INFO  [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-66:job-899
= [ 461fc03f-6d0a-488f-9cf3-7cf1a537b26c ]) Unable to start VM on Host[-2-Routing] due to
internal error Process exited while reading console log output: char device redirected to
/dev/pts/3
> qemu-kvm: -drive file=/mnt/9d444441-b138-3a13-974c-fa506683da4d/5ce3b7d0-07c1-4d3b-9c00-2c6ad8716635,if=none,id=drive-virtio-disk0,format=qcow2,cache=none:
could not open disk image /mnt/9d444441-b138-3a13-974c-fa506683da4d/5ce3b7d0-07c1-4d3b-9c00-2c6ad8716635:
Operation not supported
> 2013-08-21 22:07:12,963 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-66:job-899
= [ 461fc03f-6d0a-488f-9cf3-7cf1a537b26c ]) Cleaning up resources for the vm VM[User|daf71095-b010-45f0-9e46-3bf51ee6a59c]
in Starting state
> 2013-08-21 22:07:12,964 DEBUG [agent.transport.Request] (Job-Executor-66:job-899 = [
461fc03f-6d0a-488f-9cf3-7cf1a537b26c ]) Seq 2-949159113: Sending  { Cmd , MgmtId: 73187150500751,
via: 2, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-287-188-TestVM","wait":0}}]
}
> 2013-08-21 22:07:13,253 DEBUG [agent.transport.Request] (AgentManager-Handler-4:null)
Seq 2-949159113: Processing:  { Ans: , MgmtId: 73187150500751, via: 2, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StopAnswer":{"vncPort":0,"result":true,"wait":0}}] } 
> Agent log
> --------------
> <on_reboot>restart</on_reboot>
> <on_poweroff>destroy</on_poweroff>
> <on_crash>destroy</on_crash>
> </domain>
> 2013-08-21 22:33:40,793 WARN  [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null)
LibvirtException
> org.libvirt.LibvirtException: internal error Process exited while reading console log
output: char device redirected to /dev/pts/3
> qemu-kvm: -drive file=/mnt/9d444441-b138-3a13-974c-fa506683da4d/5ce3b7d0-07c1-4d3b-9c00-2c6ad8716635,if=none,id=drive-virtio-disk0,format=qcow2,cache=none:
could not open disk image /mnt/9d444441-b138-3a13-974c-fa506683da4d/5ce3b7d0-07c1-4d3b-9c00-2c6ad8716635:
Operation not supported
>         at org.libvirt.ErrorHandler.processError(Unknown Source)
>         at org.libvirt.Connect.processError(Unknown Source)
>         at org.libvirt.Connect.domainCreateXML(Unknown Source)
>         at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.startVM(LibvirtComputingResource.java:1156)
>         at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:3524)
>         at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1252)
>         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-08-21 22:33:40,796 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Seq 2-949159112:
 { Ans: , MgmtId: 73187150500751, via: 2, Ver: v1, Flags: 10, [{"com.cloud.agent.api.StartAnswer":{"vm":{"id":188,"name":"i-287-188-TestVM","type":"User","cpus":1,"minSpeed":100,"maxSpeed":100,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"CentOS
5.5 (64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"a79bd4d41d554b1a","vncAddr":"10.223.250.195","params":{"Message.ReservedCapacityFreed.Flag":"false"},"uuid":"daf71095-b010-45f0-9e46-3bf51ee6a59c","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"eba8fc74-aa6e-43a9-8dae-5501a0dd490f","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9d444441-b138-3a13-974c-fa506683da4d","id":1,"poolType":"NetworkFilesystem","host":"nfs1-ccp.citrix.com","path":"/home/common/automation/SC_QA_AUTO5/primary1","port":2049}},"name":"ROOT-188","size":5368709120,"path":"5ce3b7d0-07c1-4d3b-9c00-2c6ad8716635","volumeId":238,"vmName":"i-287-188-TestVM","accountId":287,"format":"QCOW2","id":238,"hypervisorType":"KVM"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"3cf9efdc-212d-46f6-b818-071450e602fd","ip":"10.223.250.231","netmask":"255.255.255.192","gateway":"10.223.250.193","mac":"06:5f:a0:00:00:24","dns1":"8.8.8.8","broadcastType":"Native","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true}]},"result":false,"details":"internal
error Process exited while reading console log output: char device redirected to /dev/pts/3\nqemu-kvm:
-drive file=/mnt/9d444441-b138-3a13-974c-fa506683da4d/5ce3b7d0-07c1-4d3b-9c00-2c6ad8716635,if=none,id=drive-virtio-disk0,format=qcow2,cache=none:
could not open disk image /mnt/9d444441-b138-3a13-974c-fa506683da4d/5ce3b7d0-07c1-4d3b-9c00-2c6ad8716635:
Operation not supported\n","wait":0}}] }
> 2013-08-21 22:33:40,811 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Request:Seq
2-949159113:  { Cmd , MgmtId: 73187150500751, via: 2, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"i-287-188-TestVM","wait":0}}]
}
> 2013-08-21 22:33:40,811 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing
command: com.cloud.agent.api.StopCommand

--
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

Mime
View raw message