Register iso template get "Stream closed" error. Can not register self build iso template.

[wqmeng]

ISSUE TYPE

• Bug Report

COMPONENT NAME

TEMPLATE

CLOUDSTACK VERSION

4.13.0

CONFIGURATION

Advanced networking

OS / ENVIRONMENT

CentOS 7.7

SUMMARY

I have create a iso base on the windows system iso setup image, the new iso file had build with VirtIO windows drive which added by DISM.exe command.
When I register the new virtio.iso template file to cloudstack, I have check the Zones, and the template status shows Stream closed, Ready No.

I tested download the self-build iso via wget, and no errors.

But I test the original iso file downloaded from Microsoft, and there is no problem to successfully register the iso to CloudStack.

STEPS TO REPRODUCE

Use dism tool to add virtio win drive to the system setup iso file from MS. 
Create a new iso file from UltraISO with the replaced install.wim and boot.wim. 
I use the UltraISO 9.7.1.3519 .
Upload the iso file to web server.
Open the cloudstack templates page.  Select ISO,  register ISO.
Type name, description, URL, un-check Direct Download, All zones, check Bootable, OS Type: Windows PV, Public, Feature.
![Snipaste_2020-01-02_19-12-22](https://user-images.githubusercontent.com/216289/71664440-f01b8800-2d93-11ea-8dfa-ab5a42ef2c35.png)
Then OK button. 
Go to Zones, check the template status, Shows Stream closed,  Ready No.

Error logs. 
tail -n 100 /var/log/cloudstack/management/management-server.log

2020-01-01 22:05:07,225 DEBUG [c.c.a.ApiServlet] (qtp504527234-17:ctx-18f90ecb) (logid:6754cbdf) ===START===  119.181.121.208 -- GET  command=registerIso&response=json&name=W2008R2EN_PV&displayText=Windows%202008%20R2%20EN%20VirtIO&url=http%3A%2F%2F[URI]%2Fiso%2Fvirtio%2Fen_windows_server_2008_r2_with_sp1_vl_build_x64_dvd_617403_virtio.iso&zoneid=-1&isextractable=false&bootable=true&directdownload=false&osTypeId=c46ab375-27ed-11ea-98e2-00259047a58c&ispublic=true&isfeatured=true&_=1577940969173
2020-01-01 22:05:07,238 DEBUG [c.c.a.ApiServer] (qtp504527234-17:ctx-18f90ecb ctx-55174da4) (logid:6754cbdf) CIDRs from which account 'Acct[d5793fba-27ed-11ea-98e2-00259047a58c-admin]' is allowed to perform API calls: 0.0.0.0/0,::/0
2020-01-01 22:05:07,269 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (qtp504527234-17:ctx-18f90ecb ctx-55174da4) (logid:6754cbdf) template 213 is not in store:1, type:Image
2020-01-01 22:05:07,273 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (qtp504527234-17:ctx-18f90ecb ctx-55174da4) (logid:6754cbdf) template 213 is already in store:1, type:Image
2020-01-01 22:05:07,275 DEBUG [o.a.c.s.i.BaseImageStoreDriverImpl] (qtp504527234-17:ctx-18f90ecb ctx-55174da4) (logid:6754cbdf) Downloading template to data store 1
2020-01-01 22:05:07,281 DEBUG [o.a.c.s.i.BaseImageStoreDriverImpl] (qtp504527234-17:ctx-18f90ecb ctx-55174da4) (logid:6754cbdf) Performing image store createTemplate async callback
2020-01-01 22:05:07,284 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (qtp504527234-17:ctx-18f90ecb ctx-55174da4) (logid:6754cbdf) getCommandHostDelegation: class org.apache.cloudstack.storage.command.DownloadCommand
2020-01-01 22:05:07,285 DEBUG [c.c.h.XenServerGuru] (qtp504527234-17:ctx-18f90ecb ctx-55174da4) (logid:6754cbdf) We are returning the default host to execute commands because the command is not of Copy type.
2020-01-01 22:05:07,285 DEBUG [o.a.c.s.RemoteHostEndPoint] (qtp504527234-17:ctx-18f90ecb ctx-55174da4) (logid:6754cbdf) Sending command org.apache.cloudstack.storage.command.DownloadCommand to host: 3
2020-01-01 22:05:07,286 DEBUG [c.c.a.t.Request] (qtp504527234-17:ctx-18f90ecb ctx-55174da4) (logid:6754cbdf) Seq 3-6442962216906925465: Sending  { Cmd , MgmtId: 161334404492, via: 3(s-3-VM), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DownloadCommand":{"hvm":true,"description":"Windows 2008 R2 EN VirtIO","maxDownloadSizeInBytes":53687091200,"id":213,"resourceType":"TEMPLATE","installPath":"template/tmpl/2/213","_store":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://nfs.133.202/home/export/secondary","_role":"Image"}},"url":"http://[URI]/iso/virtio/en_windows_server_2008_r2_with_sp1_vl_build_x64_dvd_617403_virtio.iso","format":"ISO","accountId":2,"name":"213-2-92853e30-5996-383c-a53f-7c2d7a6b4e68","secUrl":"nfs://nfs.133.202/home/export/secondary","wait":0}}] }
2020-01-01 22:05:07,286 DEBUG [c.c.r.ResourceLimitManagerImpl] (qtp504527234-17:ctx-18f90ecb ctx-55174da4) (logid:6754cbdf) Updating resource Type = template count for Account = 2 Operation = increasing Amount = 1
2020-01-01 22:05:07,294 DEBUG [c.c.a.ApiServlet] (qtp504527234-17:ctx-18f90ecb ctx-55174da4) (logid:6754cbdf) ===END===  119.181.121.208 -- GET  command=registerIso&response=json&name=W2008R2EN_PV&displayText=Windows%202008%20R2%20EN%20VirtIO&url=http%3A%2F%2F[URI]%2Fiso%2Fvirtio%2Fen_windows_server_2008_r2_with_sp1_vl_build_x64_dvd_617403_virtio.iso&zoneid=-1&isextractable=false&bootable=true&directdownload=false&osTypeId=c46ab375-27ed-11ea-98e2-00259047a58c&ispublic=true&isfeatured=true&_=1577940969173
2020-01-01 22:05:07,904 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-12:null) (logid:) Ping from 3(s-3-VM)
2020-01-01 22:05:11,723 DEBUG [c.c.a.m.AgentManagerImpl] (AgentManager-Handler-7:null) (logid:) Ping from 2(v-1-VM)
2020-01-01 22:05:15,469 DEBUG [c.c.a.t.Request] (AgentManager-Handler-14:null) (logid:) Seq 3-6442962216906925465: Processing:  { Ans: , MgmtId: 161334404492, via: 3, Ver: v1, Flags: 10, [{"com.cloud.agent.api.storage.DownloadAnswer":{"jobId":"cf6deaf5-5c98-4524-8710-a82d4ba6aabc","downloadPct":0,"errorString":"Stream closed","downloadStatus":"DOWNLOAD_ERROR","downloadPath":"/mnt/SecStorage/85684c4e-5e7e-31f3-a9c4-d374747c3071/template/tmpl/2/213/dnld4723093890073855299tmp_","installPath":"template/tmpl/2/213","templateSize":0,"templatePhySicalSize":0,"result":true,"details":"Stream closed","wait":0}}] }
2020-01-01 22:05:15,472 DEBUG [o.a.c.s.i.BaseImageStoreDriverImpl] (RemoteHostEndPoint-9:ctx-d7bdc44a) (logid:1d17e810) Performing image store createTemplate async callback
2020-01-01 22:05:15,487 WARN  [c.c.a.AlertManagerImpl] (RemoteHostEndPoint-9:ctx-d7bdc44a) (logid:1d17e810) AlertType:: 28 | dataCenterId:: 1 | podId:: null | clusterId:: null | message:: Failed to register template: 988c78c1-c3b1-4771-8395-1a08c9801036 with error: Stream closed
2020-01-01 22:05:15,490 ERROR [o.a.c.s.i.BaseImageStoreDriverImpl] (RemoteHostEndPoint-9:ctx-d7bdc44a) (logid:1d17e810) Failed to register template: 988c78c1-c3b1-4771-8395-1a08c9801036 with error: Stream closed

EXPECTED RESULTS

Status: Successfully Installed
Ready: Yes

ACTUAL RESULTS

Status: Stream closed
Ready: No

[wqmeng]

The virtio drive which I added to iso.
https://gist.github.com/wqmeng/7d24bd5e4d7d963b9dad4a4179cfed69

[wqmeng]

The iso file size is 3.1G.

[root@nfs2 ~]# wget http://xxx.com/iso/virtio/en_windows_server_2008_r2_with_sp1_vl_build_x64_dvd_617403_virtio.iso
--2020-01-02 03:02:59-- http://xxx.com/iso/virtio/en_windows_server_2008_r2_with_sp1_vl_build_x64_dvd_617403_virtio.iso
Resolving xxx.com (xxx.com)... xxx.65.26
Connecting to xxx.com (xxx.com)|xxx.65.26|:80... connected.
HTTP request sent, awaiting response... 200 OK
Length: 3315433472 (3.1G) [application/octet-stream]
Saving to: ‘en_windows_server_2008_r2_with_sp1_vl_build_x64_dvd_617403_virtio.iso’

100%[========>] 3,315,433,472 99.7MB/s in 32s

2020-01-02 03:03:31 (100 MB/s) - ‘en_windows_server_2008_r2_with_sp1_vl_build_x64_dvd_617403_virtio.iso’ saved [3315433472/3315433472]

[root@nfs2 ~]# ls -lh
total 3.1G
-rw-r--r--. 1 root root 3.1G Jan 1 22:01 en_windows_server_2008_r2_with_sp1_vl_build_x64_dvd_617403_virtio.iso

[div8cn]

We have the same problem in 4.11.3

[yadvr]

Was this issue fixed recently @sureshanaparti ?

[DaanHoogland]

@div8cn @wqmeng , can you try this in 4.15?

[nxsbi]

I am running into this exact issue on 4.15 -

Stream Closed when trying to add template via internal URL. Template size is 22 GB. I am able to use wget to get the file on SSVM as well management server.
The download fails within 1-2 seconds when trying to register template.

INSIDE the SSVM log:

2021-02-21 04:45:16,799 INFO  [storage.template.HttpTemplateDownloader] (agentRequest-Handler-3:null) No credentials configured for host=192.168.100.101:8080
2021-02-21 04:45:16,824 INFO  [storage.template.HttpTemplateDownloader] (pool-1-thread-12:null) Starting download from http://192.168.100.101:8080/templates/win2012sql2014_template.vhd to /mnt/SecStorage/919be86c-d36a-3372-aa6b-f874eb9686a1/template/tmpl/2/236/dnld1015536663169530036tmp_ remoteSize=22859950592 , max size=64424509440
2021-02-21 04:45:17,294 INFO  [storage.template.DownloadManagerImpl] (pool-1-thread-12:null) Download Completion for jobId: 8b0861d8-0245-4d9e-a7c0-40c0e7367546, status=UNRECOVERABLE_ERROR
2021-02-21 04:45:17,296 INFO  [storage.template.DownloadManagerImpl] (pool-1-thread-12:null) local: /mnt/SecStorage/919be86c-d36a-3372-aa6b-f874eb9686a1/template/tmpl/2/236/dnld1015536663169530036tmp_, bytes=1179639, error=Stream closed, pct=0

In the Cloudstack management server log:

2021-02-20 22:45:15,551 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-391:ctx-6894d94b) (logid:07e7b886) Seq 11-681450918616499348: Executing request
2021-02-20 22:45:16,532 DEBUG [c.c.a.ApiServlet] (qtp769798433-3726:ctx-a4c4994b) (logid:bbba5f1c) ===START===  192.168.100.101 -- GET  url=http:%2F%2F192.168.100.101:8080%2Ftemplates%2Fwin2012sql2014_template.vhd&name=SQL+Server+2014+on+Win+2012+R2&displaytext=SQL+Server+2014+SP3+on+Win+2012+R2&zoneids=-1&hypervisor=XenServer&format=VHD&ostypeid=7849c78d-ae38-11e8-b45b-d6ba25f3c672&requireshvm=true&details[0].hypervisortoolsversion=true&command=registerTemplate&response=json
2021-02-20 22:45:16,532 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-391:ctx-6894d94b) (logid:b07c54d8) Seq 11-681450918616499348: Response Received:
2021-02-20 22:45:16,533 DEBUG [c.c.a.t.Request] (StatsCollector-5:ctx-25552059) (logid:b07c54d8) Seq 11-681450918616499348: Received:  { Ans: , MgmtId: 196482732657985, via: 11(virtsrvr7), Ver: v1, Flags: 10, { GetGPUStatsAnswer } }
2021-02-20 22:45:16,547 DEBUG [c.c.a.ApiServer] (qtp769798433-3726:ctx-a4c4994b ctx-53eab4f6) (logid:bbba5f1c) CIDRs from which account 'Acct[admin]' is allowed to perform API calls: 0.0.0.0/0,::/0
2021-02-20 22:45:16,627 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (qtp769798433-3726:ctx-a4c4994b ctx-53eab4f6) (logid:bbba5f1c) template 236 is not in store:1, type:Image
2021-02-20 22:45:16,642 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (qtp769798433-3726:ctx-a4c4994b ctx-53eab4f6) (logid:bbba5f1c) template 236 is already in store:1, type:Image
2021-02-20 22:45:16,650 DEBUG [o.a.c.s.i.BaseImageStoreDriverImpl] (qtp769798433-3726:ctx-a4c4994b ctx-53eab4f6) (logid:bbba5f1c) Downloading template to data store 1
2021-02-20 22:45:16,667 DEBUG [o.a.c.s.i.BaseImageStoreDriverImpl] (qtp769798433-3726:ctx-a4c4994b ctx-53eab4f6) (logid:bbba5f1c) Performing image store createTemplate async callback
2021-02-20 22:45:16,670 INFO  [o.a.c.s.i.BaseImageStoreDriverImpl] (qtp769798433-3726:ctx-a4c4994b ctx-53eab4f6) (logid:bbba5f1c) Updating store ref entry for template SQL Server 2014 on Win 2012 R2
2021-02-20 22:45:16,677 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (qtp769798433-3726:ctx-a4c4994b ctx-53eab4f6) (logid:bbba5f1c) getCommandHostDelegation: class org.apache.cloudstack.storage.command.DownloadCommand
2021-02-20 22:45:16,679 DEBUG [c.c.h.XenServerGuru] (qtp769798433-3726:ctx-a4c4994b ctx-53eab4f6) (logid:bbba5f1c) We are returning the default host to execute commands because the command is not of Copy type.
2021-02-20 22:45:16,679 DEBUG [o.a.c.s.RemoteHostEndPoint] (qtp769798433-3726:ctx-a4c4994b ctx-53eab4f6) (logid:bbba5f1c) Sending command org.apache.cloudstack.storage.command.DownloadCommand to host: 13
2021-02-20 22:45:16,683 DEBUG [c.c.a.t.Request] (qtp769798433-3726:ctx-a4c4994b ctx-53eab4f6) (logid:bbba5f1c) Seq 13-8825929369739329675: Sending  { Cmd , MgmtId: 196482732657985, via: 13(s-107-VM), Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DownloadCommand":{"hvm":"true","description":"SQL Server 2014 SP3 on Win 2012 R2","maxDownloadSizeInBytes":"(60.00 GB) 64424509440","id":"236","resourceType":"TEMPLATE","installPath":"template/tmpl/2/236","_store":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.168.100.23/mnt/vmdata01/prod/secondary","_role":"Image"}},"url":"http://192.168.100.101:8080/templates/win2012sql2014_template.vhd","format":"VHD","accountId":"2","name":"236-2-44539f37-7435-3c8d-9187-9519222d6d3b","secUrl":"nfs://192.168.100.23/mnt/vmdata01/prod/secondary","wait":"0"}}] }
2021-02-20 22:45:16,683 DEBUG [c.c.r.ResourceLimitManagerImpl] (qtp769798433-3726:ctx-a4c4994b ctx-53eab4f6) (logid:bbba5f1c) Updating resource Type = template count for Account = 2 Operation = increasing Amount = 1
2021-02-20 22:45:16,712 DEBUG [c.c.a.ApiServlet] (qtp769798433-3726:ctx-a4c4994b ctx-53eab4f6) (logid:bbba5f1c) ===END===  192.168.100.101 -- GET  url=http:%2F%2F192.168.100.101:8080%2Ftemplates%2Fwin2012sql2014_template.vhd&name=SQL+Server+2014+on+Win+2012+R2&displaytext=SQL+Server+2014+SP3+on+Win+2012+R2&zoneids=-1&hypervisor=XenServer&format=VHD&ostypeid=7849c78d-ae38-11e8-b45b-d6ba25f3c672&requireshvm=true&details[0].hypervisortoolsversion=true&command=registerTemplate&response=json
2021-02-20 22:45:17,275 DEBUG [c.c.a.ApiServlet] (qtp769798433-4814:ctx-9d30eacb) (logid:795892ae) ===START===  192.168.100.101 -- GET  listall=true&templatefilter=all&showunique=true&page=1&pagesize=20&command=listTemplates&response=json
2021-02-20 22:45:17,287 DEBUG [c.c.a.ApiServer] (qtp769798433-4814:ctx-9d30eacb ctx-a256010e) (logid:795892ae) CIDRs from which account 'Acct[admin]' is allowed to perform API calls: 0.0.0.0/0,::/0
2021-02-20 22:45:17,378 DEBUG [c.c.a.ApiServlet] (qtp769798433-4814:ctx-9d30eacb ctx-a256010e) (logid:795892ae) ===END===  192.168.100.101 -- GET  listall=true&templatefilter=all&showunique=true&page=1&pagesize=20&command=listTemplates&response=json
2021-02-20 22:45:19,844 DEBUG [c.c.a.t.Request] (AgentManager-Handler-14:null) (logid:) Seq 13-8825929369739329675: Processing:  { Ans: , MgmtId: 196482732657985, via: 13, Ver: v1, Flags: 10, [{"com.cloud.agent.api.storage.DownloadAnswer":{"jobId":"8b0861d8-0245-4d9e-a7c0-40c0e7367546","downloadPct":"0","errorString":"Stream closed","downloadStatus":"DOWNLOAD_ERROR","downloadPath":"/mnt/SecStorage/919be86c-d36a-3372-aa6b-f874eb9686a1/template/tmpl/2/236/dnld1015536663169530036tmp_","installPath":"template/tmpl/2/236","templateSize":"(0 bytes) 0","templatePhySicalSize":"(0 bytes) 0","result":"true","details":"Stream closed","wait":"0"}}] }
2021-02-20 22:45:19,845 DEBUG [o.a.c.s.i.BaseImageStoreDriverImpl] (RemoteHostEndPoint-4:ctx-a9402e56) (logid:1ff8d677) Performing image store createTemplate async callback
2021-02-20 22:45:19,851 INFO  [o.a.c.s.i.BaseImageStoreDriverImpl] (RemoteHostEndPoint-4:ctx-a9402e56) (logid:1ff8d677) Updating store ref entry for template SQL Server 2014 on Win 2012 R2
2021-02-20 22:45:19,868 WARN  [c.c.a.AlertManagerImpl] (RemoteHostEndPoint-4:ctx-a9402e56) (logid:1ff8d677) AlertType:: 28 | dataCenterId:: 1 | podId:: null | clusterId:: null | message:: Failed to register template: b25729b9-d0b3-4fe5-aee9-e0ec83d5191a with error: Stream closed
2021-02-20 22:45:19,955 ERROR [o.a.c.s.i.BaseImageStoreDriverImpl] (RemoteHostEndPoint-4:ctx-a9402e56) (logid:1ff8d677) Failed to register template: b25729b9-d0b3-4fe5-aee9-e0ec83d5191a with error: Stream closed

[DaanHoogland]

this would seem to be a configuration in your network, at first glance @nxsbi . can you check your network topology. In this case Cloudstack is just reporting what it encounters: stream closed.

[yadvr]

@wqmeng @nxsbi can you try this again with latest 4.15.0.0/4.14.1.0 and in a stable network?

[weizhouapache]

this seems to be same as #4127 which has been fixed by #4138

I will close this, please reopen the ticket if you still have same issue. @wqmeng @nxsbi