You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@cloudstack.apache.org by Julien Garet <ju...@inria.fr> on 2013/03/01 11:04:04 UTC
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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"ROOT","name":"ROOT-37","useLocalStorage":false,"recreatable":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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"ROOT","name":"ROOT-37","useLocalStorage":false,"recreatable":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-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"ROOT","name":"ROOT-37","useLocalStorage":false,"recreatable":true,"diskOfferingId":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/cc08b902-cbe8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.4.2/data/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmpl/1/8//6bc0866b-077f-4153-a04a-8842c4c3a2bd.ova","format":"OVA","accountId":1,"name":"routing-8","wait":10800}}] }
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/cc08b902-cbe8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.4.2/data/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmpl/1/8//6bc0866b-077f-4153-a04a-8842c4c3a2bd.ova","format":"OVA","accountId":1,"name":"routing-8","wait":10800}}] }
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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.4.2/data/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmpl/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
Re: problem with current master and vmware for creating instances
Posted by Julien Garet <ju...@inria.fr>.
Thanks a lot. The problem was the compilation command. I was using mvn install -Dnonoss maybe because i've read a lot of pages describing the build process and I stopped on one that has worked the first time ;-)
----
Julien Garet
----- Mail original -----
> De: "Min Chen" <mi...@citrix.com>
> À: cloudstack-dev@incubator.apache.org
> Envoyé: Samedi 2 Mars 2013 01:55:52
> Objet: 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"},"secondaryS
> >>>>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","forma
> >>>>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-688c2616c864&
> >>>>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-688c2616c864&
> >>>>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":"cc08b902-
> >>>>cb
> >>>>
> >>>>e8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","
> >>>>po
> >>>>
> >>>>rt":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147
> >>>>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":"cc08b902-
> >>>>cb
> >>>>
> >>>>e8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","
> >>>>po
> >>>>
> >>>>rt":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147
> >>>>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-3167edafafc
> >>>>7"
> >>>>
> >>>>,"host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"Network
> >>>>Fi
> >>>>
> >>>>lesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"R
> >>>>OO
> >>>>
> >>>>T","name":"ROOT-37","useLocalStorage":false,"recreatable":true,"diskOff
> >>>>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/cc08b902-c
> >>>>be
> >>>>
> >>>>8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafa
> >>>>fc
> >>>>
> >>>>7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/test
> >>>>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/cc08b902-c
> >>>>be
> >>>>
> >>>>8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafa
> >>>>fc
> >>>>
> >>>>7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/test
> >>>>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/tmpl/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
> >>
Re: problem with current master and vmware for creating instances
Posted by Min Chen <mi...@citrix.com>.
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"},"secondaryS
>>>>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","forma
>>>>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-688c2616c864&
>>>>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-688c2616c864&
>>>>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":"cc08b902-
>>>>cb
>>>>
>>>>e8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","
>>>>po
>>>>
>>>>rt":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147
>>>>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":"cc08b902-
>>>>cb
>>>>
>>>>e8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","
>>>>po
>>>>
>>>>rt":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147
>>>>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-3167edafafc
>>>>7"
>>>>
>>>>,"host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"Network
>>>>Fi
>>>>
>>>>lesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"R
>>>>OO
>>>>
>>>>T","name":"ROOT-37","useLocalStorage":false,"recreatable":true,"diskOff
>>>>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/cc08b902-c
>>>>be
>>>>
>>>>8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafa
>>>>fc
>>>>
>>>>7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/test
>>>>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/cc08b902-c
>>>>be
>>>>
>>>>8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafa
>>>>fc
>>>>
>>>>7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/test
>>>>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/tmpl/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
>>
Re: problem with current master and vmware for creating instances
Posted by Julien Garet <ju...@inria.fr>.
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":"cc08b
>>> 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"},"secondarySto
>>> 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","format"
>>> :"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-688c2616c864&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-688c2616c864&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":"cc08b902-cb
>>> e8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","po
>>> rt":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":214748
>>> 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":"cc08b902-cb
>>> e8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","po
>>> rt":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":214748
>>> 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-3167edafafc7"
>>> ,"host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"NetworkFi
>>> lesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"ROO
>>> T","name":"ROOT-37","useLocalStorage":false,"recreatable":true,"diskOffer
>>> 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/cc08b902-cbe
>>> 8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafafc
>>> 7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testos
>>> 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-8842c
>>> 4c3a2bd.ova","format":"OVA","accountId":1,"name":"routing-8","wait":10800
>>> }}]
>>>>> }
>>>>> 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/cc08b902-cbe
>>> 8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafafc
>>> 7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testos
>>> 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-8842c
>>> 4c3a2bd.ova","format":"OVA","accountId":1,"name":"routing-8","wait":10800
>>> }}]
>>>>> }
>>>>> 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":"cc08
>>> b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl":"nfs
>>> ://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.4.2/d
>>> ata/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmpl/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
>
Re: problem with current master and vmware for creating instances
Posted by Min Chen <mi...@citrix.com>.
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":"cc08b
>>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"},"secondarySto
>>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","format"
>>:"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-688c2616c864&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-688c2616c864&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":"cc08b902-cb
>>e8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","po
>>rt":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":214748
>>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":"cc08b902-cb
>>e8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","po
>>rt":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":214748
>>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-3167edafafc7"
>>,"host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"NetworkFi
>>lesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"ROO
>>T","name":"ROOT-37","useLocalStorage":false,"recreatable":true,"diskOffer
>>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/cc08b902-cbe
>>8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafafc
>>7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testos
>>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-8842c
>>4c3a2bd.ova","format":"OVA","accountId":1,"name":"routing-8","wait":10800
>>}}]
>> >> }
>> >> 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/cc08b902-cbe
>>8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafafc
>>7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testos
>>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-8842c
>>4c3a2bd.ova","format":"OVA","accountId":1,"name":"routing-8","wait":10800
>>}}]
>> >> }
>> >> 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":"cc08
>>b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl":"nfs
>>://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.4.2/d
>>ata/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmpl/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
Re: problem with current master and vmware for creating instances
Posted by Julien Garet <ju...@inria.fr>.
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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":200,"primaryPool":{"id":200,"uuid":"cc08b902-cbe8-3b8d-a987-3167edafafc7","host":"172.21.4.2","pa
> > th":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"secondaryStorageUrl":"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","format":"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-688c2616c864&response=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-688c2616c864&response=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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"ROOT","name":"ROOT-37","useLocalStorage":false,"recreatable":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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"ROOT","name":"ROOT-37","useLocalStorage":false,"recreatable":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-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"ROOT","name":"ROOT-37","useLocalStorage":false,"recreatable":true,"diskOfferingId":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/cc08b902-cbe8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.4.2/data/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmpl/1/8//6bc0866b-077f-4153-a04a-8842c4c3a2bd.ova","format":"OVA","accountId":1,"name":"routing-8","wait":10800}}]
> >> }
> >> 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/cc08b902-cbe8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.4.2/data/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmpl/1/8//6bc0866b-077f-4153-a04a-8842c4c3a2bd.ova","format":"OVA","accountId":1,"name":"routing-8","wait":10800}}]
> >> }
> >> 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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.4.2/data/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmpl/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
Re: problem with current master and vmware for creating instances
Posted by Min Chen <mi...@citrix.com>.
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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":200,"primaryPool":{"id":200,"uuid":"cc08b902-cbe8-3b8d-a987-3167edafafc7","host":"172.21.4.2","pa
> th":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"secondaryStorageUrl":"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","format":"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-688c2616c864&response=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-688c2616c864&response=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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"ROOT","name":"ROOT-37","useLocalStorage":false,"recreatable":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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"ROOT","name":"ROOT-37","useLocalStorage":false,"recreatable":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-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"ROOT","name":"ROOT-37","useLocalStorage":false,"recreatable":true,"diskOfferingId":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/cc08b902-cbe8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.4.2/data/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmpl/1/8//6bc0866b-077f-4153-a04a-8842c4c3a2bd.ova","format":"OVA","accountId":1,"name":"routing-8","wait":10800}}]
>> }
>> 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/cc08b902-cbe8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.4.2/data/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmpl/1/8//6bc0866b-077f-4153-a04a-8842c4c3a2bd.ova","format":"OVA","accountId":1,"name":"routing-8","wait":10800}}]
>> }
>> 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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.4.2/data/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmpl/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
Re: problem with current master and vmware for creating instances
Posted by Julien Garet <ju...@inria.fr>.
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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":200,"primaryPool":{"id":200,"uuid":"cc08b902-cbe8-3b8d-a987-3167edafafc7","host":"172.21.4.2","pa
th":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"secondaryStorageUrl":"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","format":"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-688c2616c864&response=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-688c2616c864&response=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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"ROOT","name":"ROOT-37","useLocalStorage":false,"recreatable":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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"ROOT","name":"ROOT-37","useLocalStorage":false,"recreatable":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-3167edafafc7","host":"172.21.4.2","path":"/data/testosx","port":2049,"type":"NetworkFilesystem"},"diskCharacteristics":{"size":2147483648,"tags":[],"type":"ROOT","name":"ROOT-37","useLocalStorage":false,"recreatable":true,"diskOfferingId":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/cc08b902-cbe8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.4.2/data/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmpl/1/8//6bc0866b-077f-4153-a04a-8842c4c3a2bd.ova","format":"OVA","accountId":1,"name":"routing-8","wait":10800}}]
> }
> 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/cc08b902-cbe8-3b8d-a987-3167edafafc7","poolUuid":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.4.2/data/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmpl/1/8//6bc0866b-077f-4153-a04a-8842c4c3a2bd.ova","format":"OVA","accountId":1,"name":"routing-8","wait":10800}}]
> }
> 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":"cc08b902-cbe8-3b8d-a987-3167edafafc7","poolId":201,"secondaryStorageUrl":"nfs://172.21.4.3/containers/testosx","primaryStorageUrl":"nfs://172.21.4.2/data/testosx","url":"nfs://172.21.4.3/containers/testosx/template/tmpl/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