Chandan Purushothama created CLOUDSTACK-278:
-----------------------------------------------
Summary: VMWare: System VMs fail to deploy due to
FileNotFoundException: /usr/lib/cloud/agent/vms/systemvm.iso (No such file or
directory)
Key: CLOUDSTACK-278
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-278
Project: CloudStack
Issue Type: Bug
Components: Management Server
Affects Versions: pre-4.0.0
Reporter: Chandan Purushothama
Priority: Blocker
Fix For: pre-4.0.0
================
Steps to Reproduce:
================
1. Deploy an Advanced Zone with Two Physical Networks. Add an ESXi 5.0 Cluster
to the Setup.
2. Cluster has only one ESXi 5.0 host, one Primary Storage and one Secondary
Storage.
3. Observe that one enabling the Zone, System VMs fail to deploy due to
FileNotFoundException.
==================================================================
FileNotFoundException: /usr/lib/cloud/agent/vms/systemvm.iso (No such file or
directory):
==================================================================
[root@vmwasfmgmt vms]# cd /usr/lib64/cloud/common/vms/
[root@vmwasfmgmt vms]# ls
systemvm.iso systemvm.iso.bak systemvm.iso.bak~ systemvm.zip
[root@vmwasfmgmt vms]# cd /usr/lib/cloud/agent/vms/
-bash: cd: /usr/lib/cloud/agent/vms/: No such file or directory
[root@vmwasfmgmt vms]#
======================
FileNotFoundException:
======================
2012-10-06 21:26:57,576 INFO [vmware.manager.VmwareManagerImpl]
(DirectAgent-11:10.223.59.4) Inject SSH key pairs before copying systemvm.iso
into secondary storage
2012-10-06 21:26:57,580 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Executing: /bin/bash -c echo ~cloud
2012-10-06 21:26:57,786 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Execution is successful.
2012-10-06 21:26:57,786 INFO [cloud.server.ConfigurationServerImpl]
(DirectAgent-11:10.223.59.4) Processing updateKeyPairs
2012-10-06 21:26:57,786 INFO [cloud.server.ConfigurationServerImpl]
(DirectAgent-11:10.223.59.4) Keypairs already in database
2012-10-06 21:26:57,786 INFO [cloud.server.ConfigurationServerImpl]
(DirectAgent-11:10.223.59.4) Keypairs already in database, updating local copy
2012-10-06 21:26:57,790 INFO [cloud.server.ConfigurationServerImpl]
(DirectAgent-11:10.223.59.4) Going to update systemvm iso with generated
keypairs if needed
2012-10-06 21:26:57,790 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for scripts/vm/systemvm/injectkeys.sh in
the classpath
2012-10-06 21:26:57,791 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) System resource: null
2012-10-06 21:26:57,791 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for scripts/vm/systemvm/injectkeys.sh
2012-10-06 21:26:57,791 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Current binaries reside at /usr/share/java
2012-10-06 21:26:57,791 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for scripts/vm/systemvm/injectkeys.sh in
/usr/share/java/scripts/vm/systemvm/injectkeys.sh
2012-10-06 21:26:57,791 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for scripts/vm/systemvm/injectkeys.sh in
/usr/share/java/scripts/vm/systemvm/injectkeys.sh
2012-10-06 21:26:57,791 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for scripts/vm/systemvm/injectkeys.sh in
/usr/share/scripts/vm/systemvm/injectkeys.sh
2012-10-06 21:26:57,791 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for scripts/vm/systemvm/injectkeys.sh in
/usr/scripts/vm/systemvm/injectkeys.sh
2012-10-06 21:26:57,791 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for scripts/vm/systemvm/injectkeys.sh in
/scripts/vm/systemvm/injectkeys.sh
2012-10-06 21:26:57,791 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Searching in environment.properties
2012-10-06 21:26:57,792 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) environment.properties says scripts should be in
/usr/lib64/cloud/common
2012-10-06 21:26:57,792 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for scripts/vm/systemvm/injectkeys.sh in
/usr/lib64/cloud/common/scripts/vm/systemvm/injectkeys.sh
2012-10-06 21:26:57,792 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for vms/systemvm.iso in the classpath
2012-10-06 21:26:57,792 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) System resource: null
2012-10-06 21:26:57,792 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for vms/systemvm.iso
2012-10-06 21:26:57,792 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Current binaries reside at /usr/share/java
2012-10-06 21:26:57,792 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for vms/systemvm.iso in
/usr/share/java/vms/systemvm.iso
2012-10-06 21:26:57,792 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for vms/systemvm.iso in
/usr/share/java/vms/systemvm.iso
2012-10-06 21:26:57,792 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for vms/systemvm.iso in
/usr/share/vms/systemvm.iso
2012-10-06 21:26:57,792 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for vms/systemvm.iso in
/usr/vms/systemvm.iso
2012-10-06 21:26:57,792 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for vms/systemvm.iso in /vms/systemvm.iso
2012-10-06 21:26:57,793 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Searching in environment.properties
2012-10-06 21:26:57,793 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) environment.properties says scripts should be in
/usr/lib64/cloud/common
2012-10-06 21:26:57,793 DEBUG [utils.script.Script]
(DirectAgent-11:10.223.59.4) Looking for vms/systemvm.iso in
/usr/lib64/cloud/common/vms/systemvm.iso
2012-10-06 21:26:57,793 DEBUG [cloud.server.ConfigurationServerImpl]
(DirectAgent-11:10.223.59.4) Executing:
/usr/lib64/cloud/common/scripts/vm/systemvm/injectkeys.sh
/var/lib/cloud/management/.ssh/id_rsa.pub /var/lib/cloud/management/.ssh/id_rsa
/usr/lib64/cloud/common/vms/systemvm.iso
2012-10-06 21:26:58,481 DEBUG [cloud.server.ConfigurationServerImpl]
(DirectAgent-11:10.223.59.4) Execution is successful.
2012-10-06 21:26:58,501 ERROR [vmware.manager.VmwareManagerImpl]
(DirectAgent-11:10.223.59.4) Unexpected exception
java.io.FileNotFoundException: /usr/lib/cloud/agent/vms/systemvm.iso (No such
file or directory)
at java.io.FileInputStream.open(Native Method)
at java.io.FileInputStream.<init>(FileInputStream.java:137)
at com.cloud.utils.FileUtil.copyfile(FileUtil.java:68)
at
com.cloud.hypervisor.vmware.manager.VmwareManagerImpl.prepareSecondaryStorageStore(VmwareManagerImpl.java:628)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2054)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:419)
at
com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:191)
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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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)
2012-10-06 21:26:58,502 ERROR [vmware.manager.VmwareManagerImpl]
(DirectAgent-11:10.223.59.4) Unable to copy systemvm ISO on secondary storage.
src location: /usr/lib/cloud/agent/vms/systemvm.iso, dest location:
/var/lib/cloud/mnt/ASFVMW/7508777239729.4378c47f/systemvm/systemvm-4.0.0.20121006195403.iso
2012-10-06 21:26:58,503 WARN [vmware.resource.VmwareResource]
(DirectAgent-11:10.223.59.4) StartCommand failed due to Exception:
com.cloud.utils.exception.CloudRuntimeException
Message: Unable to copy systemvm ISO on secondary storage. src location:
/usr/lib/cloud/agent/vms/systemvm.iso, dest location:
/var/lib/cloud/mnt/ASFVMW/7508777239729.4378c47f/systemvm/systemvm-4.0.0.20121006195403.iso
com.cloud.utils.exception.CloudRuntimeException: Unable to copy systemvm ISO on
secondary storage. src location: /usr/lib/cloud/agent/vms/systemvm.iso, dest
location:
/var/lib/cloud/mnt/ASFVMW/7508777239729.4378c47f/systemvm/systemvm-4.0.0.20121006195403.iso
at
com.cloud.hypervisor.vmware.manager.VmwareManagerImpl.prepareSecondaryStorageStore(VmwareManagerImpl.java:634)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2054)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:419)
at
com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:191)
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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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)
2012-10-06 21:26:58,506 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-11:null) Seq 1-2080374805: Cancelling because one of the answers
is false and it is stop on error.
2012-10-06 21:26:58,507 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-11:null) Seq 1-2080374805: Response Received:
2012-10-06 21:26:58,509 DEBUG [agent.transport.Request] (DirectAgent-11:null)
Seq 1-2080374805: Processing: { Ans: , MgmtId: 7508777239729, via: 1, Ver: v1,
Flags: 110,
[{"StartAnswer":{"vm":{"id":2,"name":"v-2-ASFVMW","bootloader":"HVM","type":"ConsoleProxy","cpus":1,"speed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"i686","os":"Debian
GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP type=consoleproxy
host=10.223.131.202 port=8250 name=v-2-ASFVMW premium=true zone=1 pod=1
guid=Proxy.2 proxy_vm=2 disable_rp_filter=true eth2ip=10.223.139.53
eth2mask=255.255.255.192 gateway=10.223.139.1 eth0ip=0.0.0.0 eth0mask=0.0.0.0
eth1ip=10.223.59.28 eth1mask=255.255.255.192 mgmtcidr=10.223.131.0/24
localgw=10.223.59.1 internaldns1=10.223.110.254 internaldns2=10.223.110.253
dns1=72.52.126.11
dns2=72.52.126.12","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"fd3926964c812968","params":{"nicAdapter":"E1000"},"uuid":"fba34543-7869-4ee3-83d0-fa00f192dcbd","disks":[{"id":2,"name":"ROOT-2","mountPoint":"/export/home/chandan/305-131-194/primary","path":"ROOT-2","size":0,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"fac925de-df4a-358c-85f8-ecc13c0981c6","deviceId":0}],"nics":[{"deviceId":2,"networkRateMbps":-1,"defaultNic":true,"uuid":"c3aa3be3-1ec8-4f99-a2b3-a4be83e5478f","ip":"10.223.139.53","netmask":"255.255.255.192","gateway":"10.223.139.1","mac":"06:17:c0:00:00:0d","dns1":"72.52.126.11","dns2":"72.52.126.12","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://1390","isolationUri":"vlan://1390","isSecurityGroupEnabled":false,"name":"vSwitch0"},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"6ad263a4-2a7b-4dfa-9538-a08b4233e22b","mac":"02:00:03:81:00:02","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"095056e6-6033-4fb3-9adc-d7136829efce","ip":"10.223.59.28","netmask":"255.255.255.192","gateway":"10.223.59.1","mac":"06:24:c4:00:00:03","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"vSwitch0"}]},"result":false,"details":"StartCommand
failed due to Exception:
com.cloud.utils.exception.CloudRuntimeException\nMessage: Unable to copy
systemvm ISO on secondary storage. src location:
/usr/lib/cloud/agent/vms/systemvm.iso, dest location:
/var/lib/cloud/mnt/ASFVMW/7508777239729.4378c47f/systemvm/systemvm-4.0.0.20121006195403.iso\n","wait":0}}]
}
2012-10-06 21:26:58,509 DEBUG [agent.transport.Request] (consoleproxy-1:null)
Seq 1-2080374805: Received: { Ans: , MgmtId: 7508777239729, via: 1, Ver: v1,
Flags: 110, { StartAnswer } }
2012-10-06 21:26:58,510 DEBUG [agent.manager.AgentAttache]
(DirectAgent-11:null) Seq 1-2080374806: Sending now. is current sequence.
2012-10-06 21:26:58,517 DEBUG [agent.transport.Request] (DirectAgent-11:null)
Seq 1-2080374806: Executing: { Cmd , MgmtId: 7508777239729, via: 1, Ver: v1,
Flags: 100111,
[{"StartCommand":{"vm":{"id":1,"name":"s-1-ASFVMW","bootloader":"HVM","type":"SecondaryStorageVm","cpus":1,"speed":500,"minRam":268435456,"maxRam":268435456,"arch":"i686","os":"Debian
GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP type=secstorage
host=10.223.131.202 port=8250 name=s-1-ASFVMW zone=1 pod=1 guid=s-1-ASFVMW
resource=com.cloud.storage.resource.PremiumSecondaryStorageResource
instance=SecStorage sslcopy=true role=templateProcessor mtu=1500
eth2ip=10.223.139.51 eth2mask=255.255.255.192 gateway=10.223.139.1
public.network.device=eth2 eth0mask=0.0.0.0 eth0ip=0.0.0.0 eth1ip=10.223.59.30
eth1mask=255.255.255.192 mgmtcidr=10.223.131.0/24 localgw=10.223.59.1
private.network.device=eth1 eth3ip=10.223.59.27 eth3mask=255.255.255.192
storageip=10.223.59.27 storagenetmask=255.255.255.192
storagegateway=10.223.59.1 internaldns1=10.223.110.254
internaldns2=10.223.110.253 dns1=72.52.126.11
dns2=72.52.126.12","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"17a5d4074307ded8","params":{"nicAdapter":"E1000"},"uuid":"c0d2acb4-4e80-43a0-9ce7-62ff294d8d0e","disks":[{"id":1,"name":"ROOT-1","mountPoint":"/export/home/chandan/305-131-194/primary","path":"ROOT-1","size":0,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"fac925de-df4a-358c-85f8-ecc13c0981c6","deviceId":0}],"nics":[{"deviceId":2,"networkRateMbps":-1,"defaultNic":true,"uuid":"49fdc75b-257b-4caa-adcf-a18d8c3029af","ip":"10.223.139.51","netmask":"255.255.255.192","gateway":"10.223.139.1","mac":"06:75:9a:00:00:0b","dns1":"72.52.126.11","dns2":"72.52.126.12","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://1390","isolationUri":"vlan://1390","isSecurityGroupEnabled":false,"name":"vSwitch0"},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"7c7e79fd-ec0c-4884-822d-eece60f85d0f","mac":"02:00:2b:34:00:01","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"9ba06f70-99d5-476a-b683-52bcbb572c3b","ip":"10.223.59.30","netmask":"255.255.255.192","gateway":"10.223.59.1","mac":"06:c2:9c:00:00:05","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"vSwitch0"},{"deviceId":3,"networkRateMbps":-1,"defaultNic":false,"uuid":"89232dd3-4886-42bd-810a-fc168d1cac13","ip":"10.223.59.27","netmask":"255.255.255.192","gateway":"10.223.59.1","mac":"06:51:50:00:00:02","broadcastType":"Native","type":"Storage","isSecurityGroupEnabled":false,"name":"vSwitch0"}]},"wait":0}},{"check.CheckSshCommand":{"ip":"10.223.59.30","port":3922,"interval":6,"retries":100,"name":"s-1-ASFVMW","wait":0}}]
}
2012-10-06 21:26:58,531 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-13:null) Seq 1-2080374806: Executing request
2012-10-06 21:26:58,535 INFO [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Unable to start VM on Host[-1-Routing] due to
StartCommand failed due to Exception:
com.cloud.utils.exception.CloudRuntimeException
Message: Unable to copy systemvm ISO on secondary storage. src location:
/usr/lib/cloud/agent/vms/systemvm.iso, dest location:
/var/lib/cloud/mnt/ASFVMW/7508777239729.4378c47f/systemvm/systemvm-4.0.0.20121006195403.iso
=======
Git Info:
=======
Git Revision: d758ed2c8d9f0c05c7437c198d5a88866f98b5ec
Git URL: https://git-wip-us.apache.org/repos/asf/incubator-cloudstack.git
--
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
