cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From ilya musayev <ilya.mailing.li...@gmail.com>
Subject Re: Template and ISO downloaded but stuck at "installing template / installing ISO"
Date Sat, 14 May 2016 05:42:05 GMT
Indra,

While I see there is a solution to your problem due to cloudstack changes
with web servers, there is also another tangent to this issue..

Let me know if your issue is resolved by leveraging a different web server
for image downloads.

But if not, or someone else comes across this message thread, here is a
another tangent to this problem.
----

Below is a summary to the problem we've seen that seem very similar

In the nutshell, here is what we've seen and what we believe cause the
issue.

CloudStack Java Agent initiates 2 https sessions when attempting to
download.

1) Session is established to web server to get the header information and
keep it open..
2) Session is established to download the content - this is usually a
longer stream operation


What we've seen happen, as session # 2 goes on downloading, somehow http
session #1 gets corrupted. Session #2 is eventually terminated as it
completes the operation, yet session #1 remains to be open.

This defies the logic in a way, because no packets are sent over the open
session between SSVM and HTTP server. I'd expect for one of two parties
sending termination packet - but that never happens. As the result - the
1st session hangs and prevents agent from proceed to the next stage of
installing the template. I've seen the socket being open for days on SSVM
and yet not a single packet comes - not even keep alive.

Patch should be out soon. Credit goes to Marcus for figuring this out.


I also have a shell script that can resolve the specific stuck template
download, but i've made it geared toward QCOW2.  I can post it if need be,
but we should probably release a proper fix..

Regards
ilya





On Wed, May 11, 2016 at 4:37 AM, Indra Pramana <indra@sg.or.id> wrote:

> Dear all,
>
> I setup a test environment using CloudStack 4.8.0 (latest from repository),
> one management server and two KVM agent hosts running Ubuntu 14.04 LTS.
> Setup a zone with basic networking because the test environment doesn't
> support VLAN and the test management server only have 1 NIC. The private
> and public network are using the same subnet. Using Ceph RBD as primary
> storage and NFS as secondary storage.
>
> Zone is created successfully, the two hosts are added successfully and
> connected to the management servers. SSVM and CPVM are created without any
> issues. However, the default
> "CentOS 5.5(64-bit) no GUI (KVM)" template is stuck at "Installing
> Template" status and Ready = "No" although it seems to be downloaded
> successfully. I also tried registering an Ubuntu ISO and it faces the same
> problem, it's downloaded successfully but then will stuck at "Installing
> ISO" status.
>
> I ran the SSVM health check and everything is OK. Also go through the
> troubleshooting steps as per below documentation but still unable to
> determine the root cause:
>
>
> https://cwiki.apache.org/confluence/display/CLOUDSTACK/SSVM,+templates,+Secondary+storage+troubleshooting
>
> I tried restarting the SSVM service, stop and start the SSVM and restarting
> the management-server service, it will cause the download of the ISO and
> template to be restarted, but it will then stuck at installing again.
>
> Logs from management server shows below lines which keeps on appearing /
> looping every several seconds:
>
> ===
> 2016-05-11 19:31:29,031 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru]
> (Timer-6:ctx-369bfc57) (logid:0b1754a2) getCommandHostDelegation: class
> org.apache.cloudstack.storage.command.DownloadProgressCommand
> 2016-05-11 19:31:29,031 DEBUG [c.c.h.XenServerGuru] (Timer-6:ctx-369bfc57)
> (logid:0b1754a2) getCommandHostDelegation: class
> org.apache.cloudstack.storage.command.DownloadProgressCommand
> 2016-05-11 19:31:29,031 DEBUG [o.a.c.s.RemoteHostEndPoint]
> (Timer-6:ctx-369bfc57) (logid:0b1754a2) Sending command
> org.apache.cloudstack.storage.command.DownloadProgressCommand to host: 3
> 2016-05-11 19:31:29,034 DEBUG [c.c.a.t.Request] (Timer-6:ctx-369bfc57)
> (logid:0b1754a2) Seq 3-3028107799453237894: Sending  { Cmd , MgmtId:
> 181122461655966, via: 3(s-3-VM), Ver: v1, Flags: 100011,
> [{"org.apache.cloudstack.storage.command
>
> .DownloadProgressCommand":{"jobId":"cab4ada2-e52f-4c25-9c30-9ec23dc3fcd4","request":"GET_STATUS","hvm":false,"description":"CentOS
> 5.5(64-bit) no GUI
>
> (KVM)","checksum":"ed0e788280ff2912ea40f7f91ca7a249","maxDownloadSizeInBytes":536870912
>
> 00,"id":4,"resourceType":"TEMPLATE","installPath":"template/tmpl/1/4","_store":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://x.x.0.242/export/cloudstack","_role":"Image"}},"url":"
> http://download.cloud.com/releases/2.2.0/eec2209b-987
>
> 5-3c8d-92be-c001bd8a0faf.qcow2.bz2","format":"QCOW2","accountId":1,"name":"centos55-x86_64","secUrl":"nfs://x.x.0.242/export/cloudstack","wait":0}}]
> }
> 2016-05-11 19:31:29,081 DEBUG [c.c.a.t.Request]
> (AgentManager-Handler-8:null) (logid:) Seq 3-3028107799453237894:
> Processing:  { Ans: , MgmtId: 181122461655966, via: 3, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.storage.DownloadAnswer":{
>
> "jobId":"cab4ada2-e52f-4c25-9c30-9ec23dc3fcd4","downloadPct":100,"errorString":"Downloaded
> 472312242 bytes (download complete
>
> remote=472312242bytes)","downloadStatus":"DOWNLOAD_IN_PROGRESS","downloadPath":"/mnt/SecStorage/1b8d363c-1a86-3
>
> 25d-b1b8-3c030ea93856/template/tmpl/1/4/dnld3801843575178925235tmp_","installPath":"template/tmpl/1/4","templateSize":0,"templatePhySicalSize":0,"checkSum":"ed0e788280ff2912ea40f7f91ca7a249","result":true,"details":"Downloaded
> 472312242
> bytes (download complete remote=472312242bytes)","wait":0}}] }
> 2016-05-11 19:31:33,039 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
> Timer:ctx-b98dc395) (logid:46e91a46) Resetting hosts suitable for reconnect
> 2016-05-11 19:31:33,041 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
> Timer:ctx-b98dc395) (logid:46e91a46) Completed resetting hosts suitable for
> reconnect
> 2016-05-11 19:31:33,041 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
> Timer:ctx-b98dc395) (logid:46e91a46) Acquiring hosts for clusters already
> owned by this management server
> 2016-05-11 19:31:33,042 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
> Timer:ctx-b98dc395) (logid:46e91a46) Completed acquiring hosts for clusters
> already owned by this management server
> 2016-05-11 19:31:33,042 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
> Timer:ctx-b98dc395) (logid:46e91a46) Acquiring hosts for clusters not owned
> by any management server
> 2016-05-11 19:31:33,043 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager
> Timer:ctx-b98dc395) (logid:46e91a46) Completed acquiring hosts for clusters
> not owned by any management server
> 2016-05-11 19:31:33,520 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-10:null) (logid:) SeqA 4-3326: Processing Seq
> 4-3326:  { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{
> "_proxyVmId":4,"_loadInfo":"{\n  \"connections\": []\n}","wait":0}}] }
> 2016-05-11 19:31:33,608 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-10:null) (logid:) SeqA 4-3326: Sending Seq 4-3326:  {
> Ans: , MgmtId: 181122461655966, via: 4, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswe
> r":{"result":true,"wait":0}}] }
> 2016-05-11 19:31:37,910 INFO  [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-e8a869c3) (logid:8c9bcefd) Begin cleanup
> expired async-jobs
> 2016-05-11 19:31:37,916 INFO  [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-e8a869c3) (logid:8c9bcefd) End cleanup expired
> async-jobs
> 2016-05-11 19:31:37,966 DEBUG [o.a.c.s.i.BaseImageStoreDriverImpl]
> (RemoteHostEndPoint-4:ctx-02c29196) (logid:cc402ab0) Performing image store
> createTemplate async callback
> 2016-05-11 19:31:38,522 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-11:null) (logid:) SeqA 4-3327: Processing Seq
> 4-3327:  { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{
> "_proxyVmId":4,"_loadInfo":"{\n  \"connections\": []\n}","wait":0}}] }
> 2016-05-11 19:31:38,604 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-11:null) (logid:) SeqA 4-3327: Sending Seq 4-3327:  {
> Ans: , MgmtId: 181122461655966, via: 4, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswe
> r":{"result":true,"wait":0}}] }
> 2016-05-11 19:31:39,081 DEBUG [o.a.c.s.i.BaseImageStoreDriverImpl]
> (RemoteHostEndPoint-4:ctx-7ac61961) (logid:f3094baf) Performing image store
> createTemplate async callback
> 2016-05-11 19:31:39,219 DEBUG [c.c.s.d.DownloadListener]
> (Timer-5:ctx-a9ee8fd5) (logid:b445ac5e) Scheduling timeout at 30000 ms,
> TEMPLATE: 203 at host 3
> 2016-05-11 19:31:39,472 DEBUG [c.c.s.d.DownloadListener]
> (Timer-6:ctx-e44234cf) (logid:bb7ce357) Scheduling timeout at 30000 ms,
> TEMPLATE: 4 at host 3
> 2016-05-11 19:31:41,786 DEBUG [o.s.b.f.a.InjectionMetadata]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Processing injected method of
> bean 'org.apache.cloudstack.storage.image.store.ImageStoreImpl':
> AutowiredFieldElement for com.cloud.s
> torage.dao.VMTemplateDao
> org.apache.cloudstack.storage.image.store.ImageStoreImpl.imageDao
> 2016-05-11 19:31:41,786 DEBUG [o.s.b.f.s.DefaultListableBeanFactory]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Returning cached instance of
> singleton bean 'VMTemplateDaoImpl'
> 2016-05-11 19:31:41,786 DEBUG [o.s.b.f.a.InjectionMetadata]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Processing injected method of
> bean 'org.apache.cloudstack.storage.image.store.ImageStoreImpl':
> AutowiredFieldElement for private org
> .apache.cloudstack.storage.datastore.ObjectInDataStoreManager
> org.apache.cloudstack.storage.image.store.ImageStoreImpl.objectInStoreMgr
> 2016-05-11 19:31:41,786 DEBUG [o.s.b.f.s.DefaultListableBeanFactory]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Returning cached instance of
> singleton bean 'objectInDataStoreManagerImpl'
> 2016-05-11 19:31:41,786 DEBUG [o.s.b.f.a.InjectionMetadata]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Processing injected method of
> bean 'org.apache.cloudstack.storage.image.store.ImageStoreImpl':
> AutowiredFieldElement for private com
> .cloud.capacity.dao.CapacityDao
> org.apache.cloudstack.storage.image.store.ImageStoreImpl.capacityDao
> 2016-05-11 19:31:41,787 DEBUG [o.s.b.f.s.DefaultListableBeanFactory]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Returning cached instance of
> singleton bean 'capacityDaoImpl'
> 2016-05-11 19:31:41,789 DEBUG [o.s.b.f.a.InjectionMetadata]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Processing injected method of
> bean 'org.apache.cloudstack.storage.image.store.ImageStoreImpl':
> AutowiredFieldElement for com.cloud.storage.dao.VMTemplateDao
> org.apache.cloudstack.storage.image.store.ImageStoreImpl.imageDao
> 2016-05-11 19:31:41,789 DEBUG [o.s.b.f.s.DefaultListableBeanFactory]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Returning cached instance of
> singleton bean 'VMTemplateDaoImpl'
> 2016-05-11 19:31:41,789 DEBUG [o.s.b.f.a.InjectionMetadata]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Processing injected method of
> bean 'org.apache.cloudstack.storage.image.store.ImageStoreImpl':
> AutowiredFieldElement for private
> org.apache.cloudstack.storage.datastore.ObjectInDataStoreManager
> org.apache.cloudstack.storage.image.store.ImageStoreImpl.objectInStoreMgr
> 2016-05-11 19:31:41,789 DEBUG [o.s.b.f.s.DefaultListableBeanFactory]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Returning cached instance of
> singleton bean 'objectInDataStoreManagerImpl'
> 2016-05-11 19:31:41,789 DEBUG [o.s.b.f.a.InjectionMetadata]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Processing injected method of
> bean 'org.apache.cloudstack.storage.image.store.ImageStoreImpl':
> AutowiredFieldElement for private com.cloud.capacity.dao.CapacityDao
> org.apache.cloudstack.storage.image.store.ImageStoreImpl.capacityDao
> 2016-05-11 19:31:41,790 DEBUG [o.s.b.f.s.DefaultListableBeanFactory]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Returning cached instance of
> singleton bean 'capacityDaoImpl'
> 2016-05-11 19:31:41,792 DEBUG [o.s.b.f.a.InjectionMetadata]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Processing injected method of
> bean 'org.apache.cloudstack.storage.image.store.ImageStoreImpl':
> AutowiredFieldElement for com.cloud.storage.dao.VMTemplateDao
> org.apache.cloudstack.storage.image.store.ImageStoreImpl.imageDao
> 2016-05-11 19:31:41,792 DEBUG [o.s.b.f.s.DefaultListableBeanFactory]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Returning cached instance of
> singleton bean 'VMTemplateDaoImpl'
> 2016-05-11 19:31:41,792 DEBUG [o.s.b.f.a.InjectionMetadata]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Processing injected method of
> bean 'org.apache.cloudstack.storage.image.store.ImageStoreImpl':
> AutowiredFieldElement for private
> org.apache.cloudstack.storage.datastore.ObjectInDataStoreManager
> org.apache.cloudstack.storage.image.store.ImageStoreImpl.objectInStoreMgr
> 2016-05-11 19:31:41,793 DEBUG [o.s.b.f.s.DefaultListableBeanFactory]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Returning cached instance of
> singleton bean 'objectInDataStoreManagerImpl'
> 2016-05-11 19:31:41,793 DEBUG [o.s.b.f.a.InjectionMetadata]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Processing injected method of
> bean 'org.apache.cloudstack.storage.image.store.ImageStoreImpl':
> AutowiredFieldElement for private com.cloud.capacity.dao.CapacityDao
> org.apache.cloudstack.storage.image.store.ImageStoreImpl.capacityDao
> 2016-05-11 19:31:41,793 DEBUG [o.s.b.f.s.DefaultListableBeanFactory]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Returning cached instance of
> singleton bean 'capacityDaoImpl'
> 2016-05-11 19:31:41,794 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
> (secstorage-1:ctx-1a3a9719) (logid:6bcbe476) Zone 1 is ready to launch
> secondary storage VM
> 2016-05-11 19:31:42,212 DEBUG [o.s.b.f.a.InjectionMetadata]
> (consoleproxy-1:ctx-0006665c) (logid:35d3c02d) Processing injected method
> of bean 'org.apache.cloudstack.storage.image.store.ImageStoreImpl':
> AutowiredFieldElement for com.cloud.storage.dao.VMTemplateDao
> org.apache.cloudstack.storage.image.store.ImageStoreImpl.imageDao
> 2016-05-11 19:31:42,212 DEBUG [o.s.b.f.s.DefaultListableBeanFactory]
> (consoleproxy-1:ctx-0006665c) (logid:35d3c02d) Returning cached instance of
> singleton bean 'VMTemplateDaoImpl'
> 2016-05-11 19:31:42,212 DEBUG [o.s.b.f.a.InjectionMetadata]
> (consoleproxy-1:ctx-0006665c) (logid:35d3c02d) Processing injected method
> of bean 'org.apache.cloudstack.storage.image.store.ImageStoreImpl':
> AutowiredFieldElement for private
> org.apache.cloudstack.storage.datastore.ObjectInDataStoreManager
> org.apache.cloudstack.storage.image.store.ImageStoreImpl.objectInStoreMgr
> 2016-05-11 19:31:42,212 DEBUG [o.s.b.f.s.DefaultListableBeanFactory]
> (consoleproxy-1:ctx-0006665c) (logid:35d3c02d) Returning cached instance of
> singleton bean 'objectInDataStoreManagerImpl'
> 2016-05-11 19:31:42,212 DEBUG [o.s.b.f.a.InjectionMetadata]
> (consoleproxy-1:ctx-0006665c) (logid:35d3c02d) Processing injected method
> of bean 'org.apache.cloudstack.storage.image.store.ImageStoreImpl':
> AutowiredFieldElement for private com.cloud.capacity.dao.CapacityDao
> org.apache.cloudstack.storage.image.store.ImageStoreImpl.capacityDao
> 2016-05-11 19:31:42,213 DEBUG [o.s.b.f.s.DefaultListableBeanFactory]
> (consoleproxy-1:ctx-0006665c) (logid:35d3c02d) Returning cached instance of
> singleton bean 'capacityDaoImpl'
> 2016-05-11 19:31:42,216 DEBUG [c.c.c.ConsoleProxyManagerImpl]
> (consoleproxy-1:ctx-0006665c) (logid:35d3c02d) Zone 1 is ready to launch
> console proxy
> 2016-05-11 19:31:43,523 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-15:null) (logid:) SeqA 4-3328: Processing Seq
> 4-3328:  { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11,
>
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":4,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
> 2016-05-11 19:31:43,606 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-15:null) (logid:) SeqA 4-3328: Sending Seq 4-3328:  {
> Ans: , MgmtId: 181122461655966, via: 4, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2016-05-11 19:31:47,908 INFO  [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-7a3cd65f) (logid:2832c3eb) Begin cleanup
> expired async-jobs
> 2016-05-11 19:31:47,917 INFO  [o.a.c.f.j.i.AsyncJobManagerImpl]
> (AsyncJobMgr-Heartbeat-1:ctx-7a3cd65f) (logid:2832c3eb) End cleanup expired
> async-jobs
> ====
>
> Anyone can advise what could be the problem?
>
> Looking forward to your reply, thank you.
>
> Cheers.
>
> -ip-
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message