[ https://issues.apache.org/jira/browse/CLOUDSTACK-4226?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Abhinandan Prateek updated CLOUDSTACK-4226: ------------------------------------------- Assignee: Nitin Mehta > [Automation] copy template/iso is failing > ----------------------------------------- > > Key: CLOUDSTACK-4226 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4226 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the > default.) > Components: ISO, Template > Affects Versions: 4.2.0 > Reporter: Srikanteswararao Talluri > Assignee: Nitin Mehta > Priority: Blocker > Fix For: 4.2.0 > > > Copy template/iso is failing with HTTP Server returned 403 (expected 200 OK) > ===START=== 10.101.255.7 -- GET > command=copyTemplate&id=0e0a2038-6e7b-475f-b535-af5587df6c40&sourcezoneid=b2620b12-5480-4567-858b-fadaca64f71a&destzoneid=78abc627-2d24-4c36-ae55-7711c6456e17&response=json&sessionkey=h6oyyTiqF%2Fzy%2BEY8Z55vGXY16YE%3D&_=1376106139819 > 2013-08-09 20:30:26,342 DEBUG [cloud.async.AsyncJobManagerImpl] > (catalina-exec-11:null) submit async job-153 = [ > 5be875c8-6564-46b2-a073-e86e184b510b ], details: AsyncJobVO {id:153, userId: > 2, accountId: 2, sessionKey: null, instanceType: Template, instanceId: 208, > cmd: org.apache.cloudstack.api.command.user.template.CopyTemplateCmd, > cmdOriginator: null, cmdInfo: > {"response":"json","id":"0e0a2038-6e7b-475f-b535-af5587df6c40","sessionkey":"h6oyyTiqF/zy+EY8Z55vGXY16YE\u003d","destzoneid":"78abc627-2d24-4c36-ae55-7711c6456e17","cmdEventType":"TEMPLATE.COPY","ctxUserId":"2","httpmethod":"GET","_":"1376106139819","ctxAccountId":"2","sourcezoneid":"b2620b12-5480-4567-858b-fadaca64f71a","ctxStartEventId":"668"}, > cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, > processStatus: 0, resultCode: 0, result: null, initMsid: 112957957439171, > completeMsid: null, lastUpdated: null, lastPolled: null, created: null} > 2013-08-09 20:30:26,344 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null) > ===END=== 10.101.255.7 -- GET > command=copyTemplate&id=0e0a2038-6e7b-475f-b535-af5587df6c40&sourcezoneid=b2620b12-5480-4567-858b-fadaca64f71a&destzoneid=78abc627-2d24-4c36-ae55-7711c6456e17&response=json&sessionkey=h6oyyTiqF%2Fzy%2BEY8Z55vGXY16YE%3D&_=1376106139819 > 2013-08-09 20:30:26,345 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-139:job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ]) > Executing org.apache.cloudstack.api.command.user.template.CopyTemplateCmd for > job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ] > 2013-08-09 20:30:26,381 DEBUG [storage.image.TemplateDataFactoryImpl] > (Job-Executor-139:job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ]) > template 208 is already in store:1, type:Image > 2013-08-09 20:30:26,387 DEBUG [storage.image.TemplateDataFactoryImpl] > (Job-Executor-139:job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ]) > template 208 is not in store:2, type:Image > 2013-08-09 20:30:26,387 DEBUG [storage.image.TemplateServiceImpl] > (Job-Executor-139:job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ]) Setting > source template url to > https://10-223-251-16.realhostip.com/copy/SecStorage/b9c3c370-1cb2-3bc0-8000-fa52aed0c0b2/template/tmpl/2/208/33e1050e-318d-349f-9590-78d163f778ad.vhd > 2013-08-09 20:30:26,388 DEBUG [storage.image.TemplateServiceImpl] > (Job-Executor-139:job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ]) Mark > template_store_ref entry as Creating > 2013-08-09 20:30:26,413 DEBUG [storage.image.TemplateDataFactoryImpl] > (Job-Executor-139:job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ]) > template 208 is already in store:2, type:Image > 2013-08-09 20:30:26,484 DEBUG [storage.image.TemplateServiceImpl] > (Job-Executor-139:job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ]) Invoke > datastore driver createAsync to create template on destination store > 2013-08-09 20:30:26,491 DEBUG [storage.image.BaseImageStoreDriverImpl] > (Job-Executor-139:job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ]) > Downloading template to data store 2 > 2013-08-09 20:30:26,498 DEBUG [storage.image.BaseImageStoreDriverImpl] > (Job-Executor-139:job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ]) > Performing image store createTemplate async callback > 2013-08-09 20:30:26,621 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-3:null) SeqA 7-1448: Processing Seq 7-1448: { Cmd , > MgmtId: -1, via: 7, Ver: v1, Flags: 11, > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":3,"_loadInfo":"{\n > \"connections\": []\n}","wait":0}}] } > 2013-08-09 20:30:26,834 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-3:null) SeqA 7-1448: Sending Seq 7-1448: { Ans: , > MgmtId: 112957957439171, via: 7, Ver: v1, Flags: 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2013-08-09 20:30:26,908 DEBUG [cloudstack.storage.RemoteHostEndPoint] > (Job-Executor-139:job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ]) Sending > command org.apache.cloudstack.storage.command.DownloadCommand to host: 6 > 2013-08-09 20:30:26,911 DEBUG [agent.transport.Request] > (Job-Executor-139:job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ]) Seq > 6-1121976430: Sending { Cmd , MgmtId: 112957957439171, via: 6, Ver: v1, > Flags: 100011, > [{"org.apache.cloudstack.storage.command.DownloadCommand":{"hvm":true,"description":"t","checksum":"215e5d9941dffbc8790f5668fe3f19bf","maxDownloadSizeInBytes":53687091200,"id":208,"resourceType":"TEMPLATE","installPath":"template/tmpl/2/208","_store":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.223.110.232:/export/home/automation/CS-Nightly-MS1/secondary","_role":"Image"}},"url":"https://10-223-251-16.realhostip.com/copy/SecStorage/b9c3c370-1cb2-3bc0-8000-fa52aed0c0b2/template/tmpl/2/208/33e1050e-318d-349f-9590-78d163f778ad.vhd","format":"VHD","accountId":2,"name":"208-2-c9122749-9789-3927-9f53-dc9b9795d96e","secUrl":"nfs://10.223.110.232:/export/home/automation/CS-Nightly-MS1/secondary","wait":0}}] > } > 2013-08-09 20:30:27,082 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-2:null) SeqA 9-500: Processing Seq 9-500: { Cmd , > MgmtId: -1, via: 9, Ver: v1, Flags: 11, > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":29,"_loadInfo":"{\n > \"connections\": []\n}","wait":0}}] } > 2013-08-09 20:30:27,163 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-2:null) SeqA 9-500: Sending Seq 9-500: { Ans: , > MgmtId: 112957957439171, via: 9, Ver: v1, Flags: 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2013-08-09 20:30:29,597 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null) > ===START=== 10.101.255.7 -- GET > command=queryAsyncJobResult&jobId=5be875c8-6564-46b2-a073-e86e184b510b&response=json&sessionkey=h6oyyTiqF%2Fzy%2BEY8Z55vGXY16YE%3D&_=1376106143276 > 2013-08-09 20:30:29,616 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null) > ===END=== 10.101.255.7 -- GET > command=queryAsyncJobResult&jobId=5be875c8-6564-46b2-a073-e86e184b510b&response=json&sessionkey=h6oyyTiqF%2Fzy%2BEY8Z55vGXY16YE%3D&_=1376106143276 > 2013-08-09 20:30:29,651 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-4:null) Ping from 6 > 2013-08-09 20:30:29,677 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-6:null) Ping from 7 > 2013-08-09 20:30:29,978 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager > Timer:null) Resetting hosts suitable for reconnect > 2013-08-09 20:30:29,980 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager > Timer:null) Completed resetting hosts suitable for reconnect > 2013-08-09 20:30:29,980 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager > Timer:null) Acquiring hosts for clusters already owned by this management > server > 2013-08-09 20:30:29,982 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager > Timer:null) Completed acquiring hosts for clusters already owned by this > management server > 2013-08-09 20:30:29,982 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager > Timer:null) Acquiring hosts for clusters not owned by any management server > 2013-08-09 20:30:29,982 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager > Timer:null) Completed acquiring hosts for clusters not owned by any > management server > 2013-08-09 20:30:30,067 DEBUG [agent.transport.Request] > (AgentManager-Handler-8:null) Seq 6-1121976430: Processing: { Ans: , MgmtId: > 112957957439171, via: 6, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.storage.DownloadAnswer":{"jobId":"10a10e95-42ed-45f2-b64e-4bd2411a4de1","downloadPct":0,"errorString":" > HTTP Server returned 403 (expected 200 OK) > ","downloadStatus":"DOWNLOAD_ERROR","downloadPath":"/mnt/SecStorage/a556003b-728c-3284-afa6-af7cafdaa7be/template/tmpl/2/208/dnld654651999571594567tmp_","installPath":"template/tmpl/2/208","templateSize":0,"templatePhySicalSize":0,"checkSum":"215e5d9941dffbc8790f5668fe3f19bf","result":true,"details":" > HTTP Server returned 403 (expected 200 OK) ","wait":0}}] } > 2013-08-09 20:30:31,622 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-11:null) SeqA 7-1450: Processing Seq 7-1450: { Cmd , > MgmtId: -1, via: 7, Ver: v1, Flags: 11, > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":3,"_loadInfo":"{\n > \"connections\": []\n}","wait":0}}] } > 2013-08-09 20:30:31,662 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-11:null) SeqA 7-1450: Sending Seq 7-1450: { Ans: , > MgmtId: 112957957439171, via: 7, Ver: v1, Flags: 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2013-08-09 20:30:32,598 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null) > ===START=== 10.101.255.7 -- GET > command=queryAsyncJobResult&jobId=5be875c8-6564-46b2-a073-e86e184b510b&response=json&sessionkey=h6oyyTiqF%2Fzy%2BEY8Z55vGXY16YE%3D&_=1376106146276 > 2013-08-09 20:30:32,622 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null) > ===END=== 10.101.255.7 -- GET > command=queryAsyncJobResult&jobId=5be875c8-6564-46b2-a073-e86e184b510b&response=json&sessionkey=h6oyyTiqF%2Fzy%2BEY8Z55vGXY16YE%3D&_=1376106146276 > 2013-08-09 20:30:35,597 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) > ===START=== 10.101.255.7 -- GET > command=queryAsyncJobResult&jobId=5be875c8-6564-46b2-a073-e86e184b510b&response=json&sessionkey=h6oyyTiqF%2Fzy%2BEY8Z55vGXY16YE%3D&_=1376106149277 > 2013-08-09 20:30:35,635 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) > ===END=== 10.101.255.7 -- GET > command=queryAsyncJobResult&jobId=5be875c8-6564-46b2-a073-e86e184b510b&response=json&sessionkey=h6oyyTiqF%2Fzy%2BEY8Z55vGXY16YE%3D&_=1376106149277 > 2013-08-09 20:30:36,583 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-9:null) SeqA 7-1451: Processing Seq 7-1451: { Cmd , > MgmtId: -1, via: 7, Ver: v1, Flags: 11, > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":3,"_loadInfo":"{\n > \"connections\": []\n}","wait":0}}] } > 2013-08-09 20:30:36,605 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-9:null) SeqA 7-1451: Sending Seq 7-1451: { Ans: , > MgmtId: 112957957439171, via: 7, Ver: v1, Flags: 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2013-08-09 20:30:37,045 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-5:null) SeqA 9-501: Processing Seq 9-501: { Cmd , > MgmtId: -1, via: 9, Ver: v1, Flags: 11, > [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":29,"_loadInfo":"{\n > \"connections\": []\n}","wait":0}}] } > 2013-08-09 20:30:37,081 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-5:null) SeqA 9-501: Sending Seq 9-501: { Ans: , > MgmtId: 112957957439171, via: 9, Ver: v1, Flags: 100010, > [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2013-08-09 20:30:38,597 DEBUG [cloud.api.ApiServlet] (catalina-exec-15:null) > ===START=== 10.101.255.7 -- GET > command=queryAsyncJobResult&jobId=5be875c8-6564-46b2-a073-e86e184b510b&response=json&sessionkey=h6oyyTiqF%2Fzy%2BEY8Z55vGXY16YE%3D&_=1376106152278 > 2013-08-09 20:30:38,699 DEBUG [cloud.api.ApiServlet] (catalina-exec-15:null) > ===END=== 10.101.255.7 -- GET > command=queryAsyncJobResult&jobId=5be875c8-6564-46b2-a073-e86e184b510b&response=json&sessionkey=h6oyyTiqF%2Fzy%2BEY8Z55vGXY16YE%3D&_=1376106152278 > 2013-08-09 20:30:39,776 DEBUG [storage.secondary.SecondaryStorageManagerImpl] > (secstorage-1:null) Zone 1 is ready to launch secondary storage VM > 2013-08-09 20:30:39,791 DEBUG [storage.secondary.SecondaryStorageManagerImpl] > (secstorage-1:null) Zone 2 is ready to launch secondary storage VM > 2013-08-09 20:30:40,068 DEBUG [storage.image.BaseImageStoreDriverImpl] > (RemoteHostEndPoint-1:null) Performing image store createTemplate async > callback > 2013-08-09 20:30:40,520 DEBUG [storage.image.TemplateServiceImpl] > (RemoteHostEndPoint-1:null) Performing copy template cross zone callback > after completion > 2013-08-09 20:30:40,694 DEBUG [cloud.template.TemplateManagerImpl] > (Job-Executor-139:job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ]) copy > template failed for image store > nfs://10.223.110.232:/export/home/automation/CS-Nightly-MS1/secondary: HTTP > Server returned 403 (expected 200 OK) > 2013-08-09 20:30:40,720 ERROR [cloud.async.AsyncJobManagerImpl] > (Job-Executor-139:job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ]) > Unexpected exception while executing > org.apache.cloudstack.api.command.user.template.CopyTemplateCmd > com.cloud.utils.exception.CloudRuntimeException: Failed to copy template > at > com.cloud.template.TemplateManagerImpl.copyTemplate(TemplateManagerImpl.java:740) > at > com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) > at > org.apache.cloudstack.api.command.user.template.CopyTemplateCmd.execute(CopyTemplateCmd.java:124) > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158) > at > com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531) > at > java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) > at java.util.concurrent.FutureTask.run(FutureTask.java:166) > at > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) > at > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) > at java.lang.Thread.run(Thread.java:679) > 2013-08-09 20:30:40,723 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-139:job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ]) > Complete async job-153 = [ 5be875c8-6564-46b2-a073-e86e184b510b ], jobStatus: > 2, resultCode: 530, result: Error Code: 530 Error text: Failed to copy > template -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators For more information on JIRA, see: http://www.atlassian.com/software/jira