RE: problem with current master and vmware for even create systemvm

[Fang Wang <fa...@citrix.com>]

I have problem create system vm as well for vmware.

1. I have the newest master branch with commit d67d435e00427ed4b8c33a77b28545bec2f8e230

2. I did the " mvn clean install -P developer,systemvm -Dnonoss". Before start the MS;

3. When I create the zone, I can see the system VM have problem. Checking the vmops.log,
I see the first exception:

2013-03-01 14:14:15,652 ERROR [web.context.ContextLoader] (main:null) Context initialization failed
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'volumeTypeHelper': Injection of autowired dependencies failed; nested exception is org.springframework.beans.factory.BeanCreationException: Could not autowire method: public void org.apache.cloudstack.engine.subsystem.api.storage.type.VolumeTypeHelper.setTypes(java.util.List); nested exception is org.springframework.beans.factory.CannotLoadBeanClassException: Cannot find class [com.cloud.storage.allocator.LocalStoragePoolAllocator] for bean with name 'LocalStoragePoolAllocator' defined in class path resource [nonossComponentContext.xml]; nested exception is java.lang.ClassNotFoundException: com.cloud.storage.allocator.LocalStoragePoolAllocator
Related cause: org.springframework.beans.factory.CannotLoadBeanClassException: Cannot find class [com.cloud.storage.allocator.LocalStoragePoolAllocator] for bean with name 'LocalStoragePoolAllocator' defined in class path resource [nonossComponentContext.xml]; nested exception is java.lang.ClassNotFoundException: com.cloud.storage.allocator.LocalStoragePoolAllocator
Related cause: org.springframework.beans.factory.CannotLoadBeanClassException: Cannot find class [com.cloud.storage.allocator.FirstFitStoragePoolAllocator] for bean with name 'FirstFitStoragePoolAllocator' defined in class path resource [nonossComponentContext.xml]; nested exception is java.lang.ClassNotFoundException: com.cloud.storage.allocator.FirstFitStoragePoolAllocator

There seems to be a problem with the Bean class. Any idea?

4. on my deployment, it keeps trying to creating a new s-vm, and eventually run out of heap space.
(Vmware ESX 5.0 and vSphere 5.0)

Thanks,
-Fang

-----Original Message-----
From: Min Chen [mailto:min.chen@citrix.com]
Sent: Friday, March 01, 2013 4:56 PM
To: cloudstack-dev@incubator.apache.org
Subject: Re: problem with current master and vmware for creating instances

Are you talking about systemvm.iso or systemvm template? I am also using Burbank system vm template for my testing. But systemvm.iso needs to be rebuilt by running "mvn clean install -P developer,systemvm -Dnonoss".
Remember to clear your previous systemvm-4.2.0-SNAPSHOT.iso from your secondary storage to avoid using any old code.

Thanks
-min

On 3/1/13 4:13 PM, "Julien Garet" <ju...@inria.fr> wrote:

>That's strange, i've been using this branch. Do system VMs remain the
>same ? I am using the burbank system VMs, are they still OK ?
>
>Julien Garet
>
>Le 2 mars 2013 à 00:14, Min Chen <mi...@citrix.com> a écrit :
>
>> Yes, systemvm.log is not activated on master, I have enabled it on
>> vim51_win8 branch.
>> On vim51_win8, I used to encounter this certificate issue, then fixed
>> it with this commit 525fe14c25877aeb0c49a6ca8aa9d18f62ff97e2. In
>> running VMWare from source, remember that you need to manually run
>> chmod +x to make injectkeys.sh become executables, other systemvm.iso
>> will not have correct keys.
>>
>> Thanks
>> -min
>>
>>
>>
>>
>> On 3/1/13 1:49 PM, "Julien Garet" <ju...@inria.fr> wrote:
>>
>>> systemvm.log is not activated by default, documentation is missing
>>>on how  to activate it.
>>>
>>> The main problem is linked to certificate validation
>>>
>>> 2013-03-01 21:15:40,157 ERROR
>>> [storage.resource.VmwareSecondaryStorageResourceHandler]
>>> (agentRequest-Handler-1:) Unexpected exception
>>> com.sun.xml.internal.ws.client.ClientTransportException: HTTP
>>> transport
>>> error: javax.net.ssl.SSLHandshakeException:
>>> sun.security.validator.ValidatorException: PKIX path building failed:
>>> sun.security.provider.certpath.SunCertPathBuilderException: unable
>>> to find valid certification path to requested target
>>> com.sun.xml.internal.ws.client.ClientTransportException: HTTP
>>> transport
>>> error: javax.net.ssl.SSLHandshakeException:
>>> sun.security.validator.ValidatorException: PKIX path building failed:
>>> sun.security.provider.certpath.SunCertPathBuilderException: unable
>>> to find valid certification path to requested target
>>>
>>> and later
>>>
>>> 2013-03-01 21:15:40,159 WARN
>>> [storage.resource.VmwareSecondaryStorageResourceHandler]
>>> (agentRequest-Handler-1:) Unable to retrive host network information
>>>due  to exception java.lang.NullPointerException, host:
>>>HostSystem-host-132
>>> 2013-03-01 21:15:40,159 ERROR
>>>[vmware.manager.VmwareStorageManagerImpl]
>>> (agentRequest-Handler-1:) Unable to execute
>>>PrimaryStorageDownloadCommand  due to exception
>>>java.lang.NullPointerException
>>>
>>> Is that validation for vcenter server connection ?
>>>
>>> ----
>>> Julien Garet
>>>
>>> ----- Mail original -----
>>>
>>>> De: "Min Chen" <mi...@citrix.com>
>>>> À: cloudstack-dev@incubator.apache.org
>>>> Cc: cloudstack-dev@incubator.apache.org
>>>> Envoyé: Vendredi 1 Mars 2013 20:15:31
>>>> Objet: Re: problem with current master and vmware for creating
>>>> instances
>>>
>>>> This command is executed from SSVM, so you need to log into SSVM to
>>>> find the systemvm.log from /var/log/cloud to see what exception you
>>>> got.
>>>
>>>> Thanks
>>>
>>>> -min
>>>
>>>> Sent from my iPhone
>>>
>>>> On Mar 1, 2013, at 4:58 AM, "Julien Garet" <ju...@inria.fr>
>>>> wrote:
>>>
>>>>> I've found something, I think. The template was refered in the
>>>>> template_spool_ref with all NULL values.
>>>>> Removing this entry make it trying to download the template. But
>>>>> it does not complete due to errors :
>>>>>
>>>>> 013-03-01 13:48:27,559 DEBUG [cloud.storage.VolumeManagerImpl]
>>>>> (Job-Executor-1:job-35) Checking if we need to prepare 1 volumes
>>>>> for VM[User|e6fbcefb-9098-4eab-8f6c-0b8370907edd]
>>>>> 2013-03-01 13:48:27,722 DEBUG [cloud.template.TemplateManagerImpl]
>>>>> (Job-Executor-1:job-35) Downloading 7 via 1
>>>>> 2013-03-01 13:48:27,732 DEBUG [agent.transport.Request]
>>>>> (Job-Executor-1:job-35) Seq 3-1058930794: Sending { Cmd , MgmtId:
>>>>> 345042876358, via: 3, Ver: v1, Flags: 100111,
>>>>> [{"storage.PrimaryStorageDownloadCommand":{
>>>>
>>>>"localPath":"/mnt/cc08b902-cbe8-3b8d-a987-3167edafafc7","poolUuid":"
>>>>cc0
>>>>8b
>>>>
>>>>902-cbe8-3b8d-a987-3167edafafc7","poolId":200,"primaryPool":{"id":200,"
>>>>uu
>>>> id":"cc08b902-cbe8-3b8d-a987-3167edafafc7","host":"172.21.4.2","pa
>>>>
>>>>th":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"seconda
>>>>ryS
>>>>to
>>>>
>>>>rageUrl":"nfs://172.21.4.3/containers/testosx","primaryStorageUrl":"
>>>>nfs
>>>>:/
>>>> /172.21.4.2/data/testosx","url":"nfs://172.21.4.3/containers/testo
>>>>
>>>>sx/template/tmpl//1/7//caf8bd2a-d967-3094-95aa-2d9d1764f9a8.ova","fo
>>>>rma
>>>>t"
>>>> :"OVA","accountId":1,"name":"centos53-x64","wait":10800}}]
>>>>> }
>>>>> 2013-03-01 13:48:28,865 DEBUG [agent.manager.DirectAgentAttache]
>>>>> (DirectAgent-49:null) Ping from 1
>>>>> 2013-03-01 13:48:30,233 DEBUG [cloud.api.ApiServlet]
>>>>> (240631270@qtp-1414103908-11:null) ===START=== 193.51.236.13 --
>>>>> GET
>>>>
>>>>command=queryAsyncJobResult&jobId=6cc79eca-d3b8-4448-8ebc-688c2616c8
>>>>64&
>>>>re
>>>> sponse=json&sess
>>>>> ionkey=2Td9NDaZwm1%2B6nTzvXfktYu3fo0%3D&_=1362142110235
>>>>> 2013-03-01 13:48:30,255 DEBUG [cloud.api.ApiServlet]
>>>>> (240631270@qtp-1414103908-11:null) ===END=== 193.51.236.13 -- GET
>>>>
>>>>command=queryAsyncJobResult&jobId=6cc79eca-d3b8-4448-8ebc-688c2616c8
>>>>64&
>>>>re
>>>> sponse=json&sessio
>>>>> nkey=2Td9NDaZwm1%2B6nTzvXfktYu3fo0%3D&_=1362142110235
>>>>> 2013-03-01 13:48:32,805 DEBUG [agent.transport.Request]
>>>>> (AgentManager-Handler-3:null) Seq 3-1058930794: Processing: { Ans:
>>>>> , MgmtId: 345042876358, via: 3, Ver: v1, Flags: 110,
>>>>> [{"storage.PrimaryStorageDownloadAn
>>>>> swer":{"templateSize":0,"result":false,"details":"Unable to
>>>>> execute PrimaryStorageDownloadCommand due to
>>>>> exception","wait":0}}] }
>>>>> 2013-03-01 13:48:32,805 DEBUG [agent.transport.Request]
>>>>> (Job-Executor-1:job-35) Seq 3-1058930794: Received: { Ans: ,
>>>>> MgmtId: 345042876358, via: 3, Ver: v1, Flags: 110, {
>>>>> PrimaryStorageDownloadAnswer } }
>>>>> 2013-03-01 13:48:32,808 DEBUG [agent.manager.AgentAttache]
>>>>> (AgentManager-Handler-3:null) Seq 3-1058930794: No more commands
>>>>> found
>>>>>
>>>>> I can't find the exception trace anywhere so I don't know why it
>>>>> is failing... do you know if it is logged somewhere ?
>>>>>
>>>>> ----
>>>>> Julien Garet
>>>>>
>>>>> ----- Mail original -----
>>>>>
>>>>>> De: "Julien Garet" <ju...@inria.fr>
>>>>>> À: cloudstack-dev@incubator.apache.org
>>>>>> Envoyé: Vendredi 1 Mars 2013 11:04:04
>>>>>> Objet: problem with current master and vmware for creating
>>>>>> instances
>>>>>
>>>>>> Hello,
>>>>>
>>>>>> I am facing a problem I don't understand when I try to use the
>>>>>> current master with a vmware cluster.
>>>>>
>>>>>> When I create an instance for the first time, it does not
>>>>>> download the template to primary storage... But It works for the
>>>>>> systemvms !
>>>>>
>>>>>> Here is what I see in the logs :
>>>>>
>>>>>> 2013-03-01 09:03:57,386 DEBUG [cloud.storage.VolumeManagerImpl]
>>>>>> (Job-Executor-3:job-19) Checking if we need to prepare 1 volumes
>>>>>> for VM[User|1c0da489-3c4d-4225-92be-40d62ee662b0]
>>>>>> 2013-03-01 09:03:57,482 DEBUG [agent.transport.Request]
>>>>>> (Job-Executor-3:job-19) Seq 1-1105592333: Sending { Cmd , MgmtId:
>>>>>> 345042876358, via: 1, Ver: v1, Flags: 100111,
>>>>
>>>>[{"storage.CreateCommand":{"volId":9,"pool":{"id":200,"uuid":"cc08b9
>>>>02-
>>>>cb
>>>>
>>>>e8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","
>>>>po
>>>>
>>>>rt":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2
>>>>147
>>>>48
>>>>
>>>>3648,"tags":[],"type":"ROOT","name":"ROOT-37","useLocalStorage":false,"
>>>>re
>>>> creatable":true,"diskOfferingId":1,"volumeId":9},"wait":0}}]
>>>>>> }
>>>>>> 2013-03-01 09:03:57,482 DEBUG [agent.transport.Request]
>>>>>> (Job-Executor-3:job-19) Seq 1-1105592333: Executing: { Cmd ,
>>>>>> MgmtId:
>>>>>> 345042876358, via: 1, Ver: v1, Flags: 100111,
>>>>
>>>>[{"storage.CreateCommand":{"volId":9,"pool":{"id":200,"uuid":"cc08b9
>>>>02-
>>>>cb
>>>>
>>>>e8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","
>>>>po
>>>>
>>>>rt":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2
>>>>147
>>>>48
>>>>
>>>>3648,"tags":[],"type":"ROOT","name":"ROOT-37","useLocalStorage":false,"
>>>>re
>>>> creatable":true,"diskOfferingId":1,"volumeId":9},"wait":0}}]
>>>>>> }
>>>>>> 2013-03-01 09:03:57,482 DEBUG [agent.manager.DirectAgentAttache]
>>>>>> (DirectAgent-15:null) Seq 1-1105592333: Executing request
>>>>>> 2013-03-01 09:03:57,483 INFO [vmware.resource.VmwareResource]
>>>>>> (DirectAgent-15:172.21.0.251) Executing resource CreateCommand:
>>>>
>>>>{"volId":9,"pool":{"id":200,"uuid":"cc08b902-cbe8-3b8d-a987-3167edaf
>>>>afc
>>>>7"
>>>>
>>>>,"host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"Netw
>>>>ork
>>>>Fi
>>>>
>>>>lesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type"
>>>>:"R
>>>>OO
>>>>
>>>>T","name":"ROOT-37","useLocalStorage":false,"recreatable":true,"disk
>>>>Off
>>>>er
>>>> ingId":1,"volumeId":9},"wait":0}
>>>>>> 2013-03-01 09:03:59,628 DEBUG [vmware.mo.HostMO]
>>>>>> (DirectAgent-15:172.21.0.251) find VM
>>>>>> 81298a3a70c2490f854f162c52d6c40e on host
>>>>>
>>>>>> And here is what I expect to see (same action for systemvm) :
>>>>>
>>>>>> 2013-02-28 09:43:09,503 DEBUG [cloud.storage.StorageManagerImpl]
>>>>>> (Job-Executor-11:job-44) Checking if we need to prepare 1 volumes
>>>>>> for VM[SecondaryStorageVm|s-1-TEST]
>>>>>> 2013-02-28 09:43:09,503 DEBUG [cloud.storage.StorageManagerImpl]
>>>>>> (Job-Executor-11:job-44) Volume Vol[1|vm=1|ROOT] will be
>>>>>> recreated on storage pool Pool[201|NetworkFilesystem] assigned by
>>>>>> deploymentPlanner
>>>>>> 2013-02-28 09:43:09,509 DEBUG [cloud.storage.StorageManagerImpl]
>>>>>> (Job-Executor-11:job-44) Created new volume Vol[18|vm=1|ROOT] for
>>>>>> old volume Vol[1|vm=1|ROOT]
>>>>>> 2013-02-28 09:43:09,513 DEBUG [cloud.storage.StorageManagerImpl]
>>>>>> (Job-Executor-11:job-44) Creating volume: Vol[18|vm=1|ROOT]
>>>>>> 2013-02-28 09:43:09,513 DEBUG [cloud.storage.StorageManagerImpl]
>>>>>> (Job-Executor-11:job-44) Trying to create in
>>>>>> Pool[201|NetworkFilesystem]
>>>>>> 2013-02-28 09:43:09,521 DEBUG
>>>>>> [cloud.template.TemplateManagerImpl]
>>>>>> (Job-Executor-11:job-44) Downloading template 8 to pool 201
>>>>>> 2013-02-28 09:43:09,528 DEBUG
>>>>>> [cloud.template.TemplateManagerImpl]
>>>>>> (Job-Executor-11:job-44) Downloading 8 via 1
>>>>>> 2013-02-28 09:43:09,532 DEBUG [agent.transport.Request]
>>>>>> (Job-Executor-11:job-44) Seq 1-1846938487: Sending { Cmd , MgmtId:
>>>>>> 345042876358, via: 1, Ver: v1, Flags: 100111,
>>>>
>>>>[{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/cc08b90
>>>>2-c
>>>>be
>>>>
>>>>8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167ed
>>>>afa
>>>>fc
>>>>
>>>>7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/t
>>>>est
>>>>os
>>>>
>>>>x","primaryStorageUrl":"nfs://172.21.4.2/data/testosx","url":"nfs://
>>>>172
>>>>.2
>>>>
>>>>1.4.3/containers/testosx/template/tmpl/1/8//6bc0866b-077f-4153-a04a-
>>>>884
>>>>2c
>>>>
>>>>4c3a2bd.ova","format":"OVA","accountId":1,"name":"routing-8","wait":
>>>>108
>>>>00
>>>> }}]
>>>>>> }
>>>>>> 2013-02-28 09:43:09,532 DEBUG [agent.transport.Request]
>>>>>> (Job-Executor-11:job-44) Seq 1-1846938487: Executing: { Cmd ,
>>>>>> MgmtId: 345042876358, via: 1, Ver: v1, Flags: 100111,
>>>>
>>>>[{"storage.PrimaryStorageDownloadCommand":{"localPath":"/mnt/cc08b90
>>>>2-c
>>>>be
>>>>
>>>>8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167ed
>>>>afa
>>>>fc
>>>>
>>>>7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/t
>>>>est
>>>>os
>>>>
>>>>x","primaryStorageUrl":"nfs://172.21.4.2/data/testosx","url":"nfs://
>>>>172
>>>>.2
>>>>
>>>>1.4.3/containers/testosx/template/tmpl/1/8//6bc0866b-077f-4153-a04a-
>>>>884
>>>>2c
>>>>
>>>>4c3a2bd.ova","format":"OVA","accountId":1,"name":"routing-8","wait":
>>>>108
>>>>00
>>>> }}]
>>>>>> }
>>>>>> 2013-02-28 09:43:09,532 DEBUG [agent.manager.DirectAgentAttache]
>>>>>> (DirectAgent-433:null) Seq 1-1846938487: Executing request
>>>>>> 2013-02-28 09:43:09,532 INFO [vmware.resource.VmwareResource]
>>>>>> (DirectAgent-433:172.21.0.251) Executing resource
>>>>>> PrimaryStorageDownloadCommand:
>>>>
>>>>{"localPath":"/mnt/cc08b902-cbe8-3b8d-a987-3167edafafc7","poolUuid":
>>>>"cc
>>>>08
>>>>
>>>>b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl"
>>>>:"n
>>>>fs
>>>>
>>>>://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.
>>>>4.2
>>>>/d
>>>>
>>>>ata/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmp
>>>>l/1
>>>>/8
>>>>
>>>>//6bc0866b-077f-4153-a04a-8842c4c3a2bd.ova","format":"OVA","accountId":
>>>>1,
>>>> "name":"routing-8","wait":10800}
>>>>>
>>>>>> Result is : ROOT disk for Instance shows in vCenter it uses 3KB
>>>>>> of storage resource, so no OS is copied... The tests were done
>>>>>> with the
>>>>>> CentOS5.3 template automatically downloaded and installed.
>>>>>> Template
>>>>>> seems to have a good size on secondary storage et is marked as
>>>>>> ready to use in the UI.
>>>>>
>>>>>> Any clues on that ?
>>>>>
>>>>>> ----
>>>>>> Julien Garet
>>>>>> P.S. : full clones is disabled if it matters
>>