You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Sangeetha Hariharan (JIRA)" <ji...@apache.org> on 2013/07/12 21:21:47 UTC

[jira] [Closed] (CLOUDSTACK-2498) Object_Store_Refactor - Templates - Not able to create a template from root volume.

     [ https://issues.apache.org/jira/browse/CLOUDSTACK-2498?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Sangeetha Hariharan closed CLOUDSTACK-2498.
-------------------------------------------


Tested with latest build from 4.2 using Xenserver host and NSF as secondary store.

We are able to create template from root volume successfully. 
                
> Object_Store_Refactor - Templates - Not able to create a template from  root volume.
> ------------------------------------------------------------------------------------
>
>                 Key: CLOUDSTACK-2498
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-2498
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>          Components: Management Server
>    Affects Versions: 4.2.0
>         Environment: Build from object_store
>            Reporter: Sangeetha Hariharan
>             Fix For: 4.2.0
>
>
> Object_Store_Refactor - Templates - Not able to create a template from  root volume.
> Steps to reproduce the problem:
> 1. Deploy a Vm.
> 2. Stop the Vm.
> 3.Create template from the ROOT volume of the vm
> Template creation fails.
> Management server logs:
> 2013-05-14 16:58:59,710 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===START===  10.217.252.128 -- GET  command=createTemplate&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&volumeId=edbc637b-d4cc-46a6-b332-8278469258fc&name=TemplatefromVolume&displayText=TemplatefromVolume&osTypeId=fce76ff6-bc28-11e2-8a23-6a01c7e420f0&isPublic=true&passwordEnabled=false&isfeatured=true&_=1368579358661
> 2013-05-14 16:58:59,779 DEBUG [cloud.template.TemplateManagerImpl] (catalina-exec-1:null) This template is getting created from other template, setting source template Id to: 5
> 2013-05-14 16:58:59,827 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-1:null) submit async job-42, details: AsyncJobVO {id:42, userId: 2, accountId: 2, sessionKey: null, instanceType: Template, instanceId: 207, cmd: org.apache.cloudstack.api.command.user.template.CreateTemplateCmd, cmdOriginator: null, cmdInfo: {"sessionkey":"qgY9GFmKNylox/ssl8BEOS8nFvs\u003d","volumeId":"edbc637b-d4cc-46a6-b332-8278469258fc","ctxUserId":"2","httpmethod":"GET","osTypeId":"fce76ff6-bc28-11e2-8a23-6a01c7e420f0","isPublic":"true","isfeatured":"true","response":"json","id":"207","displayText":"TemplatefromVolume","passwordEnabled":"false","name":"TemplatefromVolume","_":"1368579358661","ctxAccountId":"2","ctxStartEventId":"174"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 206915885079359, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2013-05-14 16:58:59,828 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-9:job-42) Executing org.apache.cloudstack.api.command.user.template.CreateTemplateCmd for job-42
> 2013-05-14 16:58:59,830 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===END===  10.217.252.128 -- GET  command=createTemplate&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&volumeId=edbc637b-d4cc-46a6-b332-8278469258fc&name=TemplatefromVolume&displayText=TemplatefromVolume&osTypeId=fce76ff6-bc28-11e2-8a23-6a01c7e420f0&isPublic=true&passwordEnabled=false&isfeatured=true&_=1368579358661
> 2013-05-14 16:58:59,899 DEBUG [agent.transport.Request] (Job-Executor-9:job-42) Seq 1-900399343: Sending  { Cmd , MgmtId: 206915885079359, via: 1, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"edbc637b-d4cc-46a6-b332-8278469258fc","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"e97b5727-d157-3dc1-b32c-065b99806623","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/sangeetha/campo-systemp-1/primary","port":2049}},"name":"ROOT-9","size":21474836480,"path":"49643ed0-d428-4ba3-bb84-a0e0f742dc39","volumeId":11,"vmName":"i-2-9-VM","accountId":2,"id":11}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/207","uuid":"83950a32-7938-4d9a-86d7-649d3eb1f0e0","id":207,"format":"RAW","accountId":2,"hvm":true,"displayText":"TemplatefromVolume","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.223.110.232/export/home/sangeetha/campo-systemp-1/secondary","_role":"Image"}},"name":"244c28c5a-52b9-39a5-a945-3db48a5cb644"}},"wait":10800}}] }
> 2013-05-14 16:58:59,900 DEBUG [agent.transport.Request] (Job-Executor-9:job-42) Seq 1-900399343: Executing:  { Cmd , MgmtId: 206915885079359, via: 1, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"edbc637b-d4cc-46a6-b332-8278469258fc","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"e97b5727-d157-3dc1-b32c-065b99806623","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/sangeetha/campo-systemp-1/primary","port":2049}},"name":"ROOT-9","size":21474836480,"path":"49643ed0-d428-4ba3-bb84-a0e0f742dc39","volumeId":11,"vmName":"i-2-9-VM","accountId":2,"id":11}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/207","uuid":"83950a32-7938-4d9a-86d7-649d3eb1f0e0","id":207,"format":"RAW","accountId":2,"hvm":true,"displayText":"TemplatefromVolume","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.223.110.232/export/home/sangeetha/campo-systemp-1/secondary","_role":"Image"}},"name":"244c28c5a-52b9-39a5-a945-3db48a5cb644"}},"wait":10800}}] }
> 2013-05-14 16:58:59,900 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-316:null) Seq 1-900399343: Executing request
> 2013-05-14 16:58:59,927 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) StorageCollector is running...
> 2013-05-14 16:59:01,001 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 5-1883045927: Received:  { Ans: , MgmtId: 206915885079359, via: 5, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2013-05-14 16:59:01,008 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-21:null) Seq 1-900399344: Executing request
> 2013-05-14 16:59:01,370 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-316:null) Creating a not shared SR for nfs://10.223.110.232/export/home/sangeetha/campo-systemp-1/secondary/template/tmpl/2/207
> 2013-05-14 16:59:01,481 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-21:null) Seq 1-900399344: Response Received:
> 2013-05-14 16:59:01,481 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-900399344: Received:  { Ans: , MgmtId: 206915885079359, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2013-05-14 16:59:02,051 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-316:null) Checking 33fef15a-475f-3a2f-a4f1-bf81ea5afd8a or SR 070bc979-8fd1-5772-cb01-7901abcaff69 on XS[c5a85f60-1e15-40f5-9e7f-436bac0c8b63-10.223.56.194]
> 2013-05-14 16:59:02,066 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-316:null) Host 10.223.56.194 OpaqueRef:6863588d-0107-fb13-0bbd-9188709eec8e: Created a SR; UUID is 070bc979-8fd1-5772-cb01-7901abcaff69 device config is {serverpath=/export/home/sangeetha/campo-systemp-1/secondary/template/tmpl/2/207, server=10.223.110.232}
> 2013-05-14 16:59:02,864 DEBUG [cloud.api.ApiServlet] (catalina-exec-23:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579361900
> 2013-05-14 16:59:02,890 DEBUG [cloud.api.ApiServlet] (catalina-exec-23:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579361900
> 2013-05-14 16:59:05,859 DEBUG [cloud.api.ApiServlet] (catalina-exec-20:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579364901
> 2013-05-14 16:59:06,000 DEBUG [cloud.api.ApiServlet] (catalina-exec-20:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579364901
> 2013-05-14 16:59:08,888 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579367905
> 2013-05-14 16:59:09,095 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-230:null) Seq 1-900399109: Response Received:
> 2013-05-14 16:59:09,096 DEBUG [agent.transport.Request] (DirectAgent-230:null) Seq 1-900399109: Processing:  { Ans: , MgmtId: 206915885079359, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}] }
> 2013-05-14 16:59:11,899 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579370933
> 2013-05-14 16:59:11,929 DEBUG [cloud.api.ApiServlet] (catalina-exec-7:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579370933
> 2013-05-14 16:59:14,886 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579373921
> 2013-05-14 16:59:14,912 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579373921
> 2013-05-14 16:59:17,871 DEBUG [cloud.api.ApiServlet] (catalina-exec-9:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579376905
> 2013-05-14 16:59:17,897 DEBUG [cloud.api.ApiServlet] (catalina-exec-9:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579376905
> 2013-05-14 16:59:20,899 DEBUG [cloud.api.ApiServlet] (catalina-exec-16:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579379905
> 2013-05-14 16:59:20,931 DEBUG [cloud.api.ApiServlet] (catalina-exec-16:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579379905
> 2013-05-14 16:59:23,867 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579382907
> 2013-05-14 16:59:23,896 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579382907
> 2013-05-14 16:59:26,871 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579385907
> 2013-05-14 16:59:26,904 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579385907
> 2013-05-14 16:59:27,917 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
> 2013-05-14 16:59:28,036 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
> 2013-05-14 16:59:29,622 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 1 routers to update status.
> 2013-05-14 16:59:29,623 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2013-05-14 16:59:29,649 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 1 routers to update status.
> 2013-05-14 16:59:29,651 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2013-05-14 16:59:29,877 DEBUG [cloud.api.ApiServlet] (catalina-exec-21:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579388910
> 2013-05-14 16:59:29,904 DEBUG [cloud.api.ApiServlet] (catalina-exec-21:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579388910
> 2013-05-14 16:59:30,466 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) HostStatsCollector is running...
> 2013-05-14 16:59:30,477 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-340:null) Seq 1-900399345: Executing request
> 2013-05-14 16:59:30,822 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-340:null) Seq 1-900399345: Response Received:
> 2013-05-14 16:59:30,823 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-900399345: Received:  { Ans: , MgmtId: 206915885079359, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2013-05-14 16:59:31,011 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) VmStatsCollector is running...
> 2013-05-14 16:59:31,022 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-24:null) Seq 1-900399346: Executing request
> 2013-05-14 16:59:31,303 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-24:null) Vm cpu utilization 0.0010937499999999999
> 2013-05-14 16:59:31,303 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-24:null) Seq 1-900399346: Response Received:
> 2013-05-14 16:59:31,304 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-900399346: Received:  { Ans: , MgmtId: 206915885079359, via: 1, Ver: v1, Flags: 10, { GetVmStatsAnswer } }
> 2013-05-14 16:59:31,396 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-6:null) Ping from 5
> 2013-05-14 16:59:32,897 DEBUG [cloud.api.ApiServlet] (catalina-exec-15:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579391934
> 2013-05-14 16:59:32,928 DEBUG [cloud.api.ApiServlet] (catalina-exec-15:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-966
> 9-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579391934
> 2013-05-14 16:59:35,672 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-7:null) Ping from 4
> 2013-05-14 16:59:35,900 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579394933
> 2013-05-14 16:59:35,930 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579394933
> 2013-05-14 16:59:38,873 DEBUG [cloud.api.ApiServlet] (catalina-exec-14:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579397910
> 2013-05-14 16:59:38,905 DEBUG [cloud.api.ApiServlet] (catalina-exec-14:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579397910
> 2013-05-14 16:59:41,914 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579400953
> 2013-05-14 16:59:41,946 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579400953
> 2013-05-14 16:59:44,901 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579403942
> 2013-05-14 16:59:44,920 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579403942
> 2013-05-14 16:59:47,916 DEBUG [cloud.api.ApiServlet] (catalina-exec-12:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579406955
> 2013-05-14 16:59:48,004 DEBUG [cloud.api.ApiServlet] (catalina-exec-12:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579406955
> 2013-05-14 16:59:50,910 DEBUG [cloud.api.ApiServlet] (catalina-exec-4:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579409947
> 2013-05-14 16:59:50,938 DEBUG [cloud.api.ApiServlet] (catalina-exec-4:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579409947
> 2013-05-14 16:59:53,944 DEBUG [cloud.api.ApiServlet] (catalina-exec-19:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579412946
> 2013-05-14 16:59:53,971 DEBUG [cloud.api.ApiServlet] (catalina-exec-19:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579412946
> 2013-05-14 16:59:56,909 DEBUG [cloud.api.ApiServlet] (catalina-exec-13:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579415949
> 2013-05-14 16:59:56,938 DEBUG [cloud.api.ApiServlet] (catalina-exec-13:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579415949
> 2013-05-14 16:59:57,917 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
> 2013-05-14 16:59:58,036 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
> 2013-05-14 16:59:59,622 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 1 routers to update status.
> 2013-05-14 16:59:59,623 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2013-05-14 16:59:59,649 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 1 routers to update status.
> 2013-05-14 16:59:59,651 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
> 2013-05-14 16:59:59,912 DEBUG [cloud.api.ApiServlet] (catalina-exec-17:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579418948
> 2013-05-14 16:59:59,944 DEBUG [cloud.api.ApiServlet] (catalina-exec-17:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579418948
> 2013-05-14 17:00:01,482 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) StorageCollector is running...
> 2013-05-14 17:00:02,339 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 5-1883045928: Received:  { Ans: , MgmtId: 206915885079359, via: 5, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2013-05-14 17:00:02,346 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-343:null) Seq 1-900399347: Executing request
> 2013-05-14 17:00:02,915 DEBUG [cloud.api.ApiServlet] (catalina-exec-18:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579421949
> 2013-05-14 17:00:02,945 DEBUG [cloud.api.ApiServlet] (catalina-exec-18:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579421949
> 2013-05-14 17:00:03,608 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-343:null) Seq 1-900399347: Response Received:
> 2013-05-14 17:00:03,609 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-900399347: Received:  { Ans: , MgmtId: 206915885079359, via: 1, Ver: v1, Flags: 1
> 0, { GetStorageStatsAnswer } }
> 2013-05-14 17:00:05,981 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579424949
> 2013-05-14 17:00:06,010 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579424949
> 2013-05-14 17:00:07,475 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-163:null) Ping from 1
> 2013-05-14 17:00:08,860 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-217:null) Seq 1-900399109: Executing request
> 2013-05-14 17:00:08,912 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579427952
> 2013-05-14 17:00:08,935 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579427952
> 2013-05-14 17:00:09,115 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-217:null) Seq 1-900399109: Response Received:
> 2013-05-14 17:00:09,116 DEBUG [agent.transport.Request] (DirectAgent-217:null) Seq 1-900399109: Processing:  { Ans: , MgmtId: 206915885079359, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ClusterSyncAnswer":{"_clusterId":1,"_newStates":{},"_isExecuted":false,"result":true,"wait":0}}] }
> 2013-05-14 17:00:11,907 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579430949
> 2013-05-14 17:00:11,936 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579430949
> 2013-05-14 17:00:14,910 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579433951
> 2013-05-14 17:00:14,937 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579433951
> 2013-05-14 17:00:17,947 DEBUG [cloud.api.ApiServlet] (catalina-exec-23:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579437018
> 2013-05-14 17:00:17,978 DEBUG [cloud.api.ApiServlet] (catalina-exec-23:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579437018
> 2013-05-14 17:00:20,942 DEBUG [cloud.api.ApiServlet] (catalina-exec-20:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579439992
> 2013-05-14 17:00:20,970 DEBUG [cloud.api.ApiServlet] (catalina-exec-20:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579439992
> 2013-05-14 17:00:23,948 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null) ===START===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579443017
> 2013-05-14 17:00:23,977 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null) ===END===  10.217.252.128 -- GET  command=queryAsyncJobResult&jobId=8f36cb34-1920-4ba3-9669-9d09cbe27ce7&response=json&sessionkey=qgY9GFmKNylox%2Fssl8BEOS8nFvs%3D&_=1368579443017
> 2013-05-14 17:00:26,298 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-316:null) Successfully created template.properties file on secondary storage for 99d89e76-d94a-4cde-ae61-4509af3c0fcf.vhd
> 2013-05-14 17:00:26,298 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-316:null) Host 10.223.56.194 OpaqueRef:6863588d-0107-fb13-0bbd-9188709eec8e: Removing SR
> 2013-05-14 17:00:26,329 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-316:null) Host 10.223.56.194 OpaqueRef:ea6dfb0a-08c6-47ae-76fe-3dabd8080e22: Unplugging pbd
> 2013-05-14 17:00:26,841 DEBUG [xen.resource.CitrixResourceBase] (DirectAgent-316:null) Host 10.223.56.194 OpaqueRef:6863588d-0107-fb13-0bbd-9188709eec8e: Forgetting
> 2013-05-14 17:00:26,867 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-316:null) Seq 1-900399343: Response Received:
> 2013-05-14 17:00:26,868 DEBUG [agent.transport.Request] (DirectAgent-316:null) Seq 1-900399343: Processing:  { Ans: , MgmtId: 206915885079359, via: 1, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/207/99d89e76-d94a-4cde-ae61-4509af3c0fcf.vhd","id":0,"format":"VHD","accountId":0,"hvm":false}},"result":true,"wait":0}}] }
> 2013-05-14 17:00:26,868 DEBUG [agent.manager.AgentAttache] (DirectAgent-316:null) Seq 1-900399343: No more commands found
> 2013-05-14 17:00:26,868 DEBUG [agent.transport.Request] (Job-Executor-9:job-42) Seq 1-900399343: Received:  { Ans: , MgmtId: 206915885079359, via: 1, Ver: v1, Flags: 110, { CopyCmdAnswer } }
> 2013-05-14 17:00:26,869 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-9:job-42) Failed to create templatejava.lang.NullPointerException
> 2013-05-14 17:00:26,873 DEBUG [db.Transaction.Transaction] (Job-Executor-9:job-42) Rolling back the transaction: Time = 1 Name =  -AsyncJobManagerImpl$1.run:401-Executors$RunnableAdapter.call:471-FutureTask$Sync.innerRun:334-FutureTask.run:166-ThreadPoolExecutor.runWorker:1110-ThreadPoolExecutor$Worker.run:603-Thread.run:679; called by -Transaction.rollback:890-Transaction.removeUpTo:833-Transaction.close:657-TransactionContextBuilder.interceptException:63-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:133-TemplateManagerImpl.createPrivateTemplate:1424-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-CreateTemplateCmd.execute:258-ApiDispatcher.dispatch:155-AsyncJobManagerImpl$1.run:437-Executors$RunnableAdapter.call:471-FutureTask$Sync.innerRun:334
> 2013-05-14 17:00:26,899 ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-9:job-42) Unexpected exception while executing org.apache.cloudstack.api.command.user.tem
> plate.CreateTemplateCmd
> com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@13b8f5c6: DELETE FROM vm_template WHERE vm_template.id= 207
>         at com.cloud.utils.db.GenericDaoBase.expunge(GenericDaoBase.java:1137)
>         at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
>         at com.cloud.template.TemplateManagerImpl.createPrivateTemplate(TemplateManagerImpl.java:1424)
>         at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
>         at org.apache.cloudstack.api.command.user.template.CreateTemplateCmd.execute(CreateTemplateCmd.java:258)
>         at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:155)
>         at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:437)
>         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)
> Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Cannot delete or update a parent row: a foreign key constraint fails (`cloud`.`template_store_ref`, CONSTRAINT `fk_template_store_ref__template_id` FOREIGN KEY (`template_id`) REFERENCES `vm_template` (`id`))
>         at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
>         at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
>         at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
>         at java.lang.reflect.Constructor.newInstance(Constructor.java:532)
>         at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
>         at com.mysql.jdbc.Util.getInstance(Util.java:386)
>         at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1040)
>         at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4074)
>         at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4006)
>         at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2468)
>         at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2629)
>         at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2719)
>         at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2155)
>         at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2450)
>         at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2371)
>         at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2355)
>         at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105)
>         at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:105)
>         at com.cloud.utils.db.GenericDaoBase.expunge(GenericDaoBase.java:1128)
>         ... 20 more
> 2013-05-14 17:00:26,901 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-9:job-42) Complete async job-42, jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@13b8f5c6: DELETE FROM vm_template WHERE vm_template.id= 207

--
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