[
https://issues.apache.org/jira/browse/CLOUDSTACK-2481?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Sanjeev N reopened CLOUDSTACK-2481:
-----------------------------------
Verified this on Today's build. I still see the issue with VMWare cluster.
Storage used is NFS for both primary(cluster level) and secondary .
Observations:
===========
2013-07-29 09:12:41,103 DEBUG [cloud.api.ApiServlet] (catalina-exec-17:null)
===START=== 10.146.0.20 -- GET
command=createTemplate&response=json&sessionkey=%2BFPenbp5rPeS7NG2g1sVBwdG7DM%3D&snapshotid=4186ec6b-81f0-495f-ab04-19e661947280&name=vm1-esx&displayText=vm1-esx&osTypeId=69dcda2a-f846-11e2-9888-06045a000066&isPublic=true&passwordEnabled=false&isdynamicallyscalable=false&_=1375103561437
2013-07-29 09:12:41,237 DEBUG [cloud.template.TemplateManagerImpl]
(catalina-exec-17:null) This template is getting created from other template,
setting source template Id to: 7
2013-07-29 09:12:41,294 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-17:null) submit async job-21 = [
4cc0ba40-5d27-4231-95af-e88b2eac80f4 ], details: AsyncJobVO {id:21, userId: 2,
accountId: 2, sessionKey: null, instanceType: Template, instanceId: 203, cmd:
org.apache.cloudstack.api.command.user.template.CreateTemplateCmd,
cmdOriginator: null, cmdInfo:
{"sessionkey":"+FPenbp5rPeS7NG2g1sVBwdG7DM\u003d","cmdEventType":"TEMPLATE.CREATE","ctxUserId":"2","httpmethod":"GET","osTypeId":"69dcda2a-f846-11e2-9888-06045a000066","isPublic":"true","isdynamicallyscalable":"false","response":"json","id":"203","displayText":"vm1-esx","snapshotid":"4186ec6b-81f0-495f-ab04-19e661947280","passwordEnabled":"false","name":"vm1-esx","_":"1375103561437","ctxAccountId":"2","ctxStartEventId":"78"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
processStatus: 0, resultCode: 0, result: null, initMsid: 6615759585382,
completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-07-29 09:12:41,298 DEBUG [cloud.api.ApiServlet] (catalina-exec-17:null)
===END=== 10.146.0.20 -- GET
command=createTemplate&response=json&sessionkey=%2BFPenbp5rPeS7NG2g1sVBwdG7DM%3D&snapshotid=4186ec6b-81f0-495f-ab04-19e661947280&name=vm1-esx&displayText=vm1-esx&osTypeId=69dcda2a-f846-11e2-9888-06045a000066&isPublic=true&passwordEnabled=false&isdynamicallyscalable=false&_=1375103561437
2013-07-29 09:12:41,301 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-21:job-21 = [ 4cc0ba40-5d27-4231-95af-e88b2eac80f4 ]) Executing
org.apache.cloudstack.api.command.user.template.CreateTemplateCmd for job-21 =
[ 4cc0ba40-5d27-4231-95af-e88b2eac80f4 ]
2013-07-29 09:12:41,351 DEBUG [storage.image.TemplateDataFactoryImpl]
(Job-Executor-21:job-21 = [ 4cc0ba40-5d27-4231-95af-e88b2eac80f4 ]) template
203 is already in store:1, type:Image
2013-07-29 09:12:41,365 DEBUG [storage.motion.AncientDataMotionStrategy]
(Job-Executor-21:job-21 = [ 4cc0ba40-5d27-4231-95af-e88b2eac80f4 ]) copyAsync
inspecting src type SNAPSHOT copyAsync inspecting dest type TEMPLATE
2013-07-29 09:12:41,426 DEBUG [agent.transport.Request] (Job-Executor-21:job-21
= [ 4cc0ba40-5d27-4231-95af-e88b2eac80f4 ]) Seq 3-105971776: Sending { Cmd ,
MgmtId: 6615759585382, via: 3, Ver: v1, Flags: 100011,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/4/9014dc0f-fada-4a35-adb5-50872299cdb7/9014dc0f-fada-4a35-adb5-50872299cdb7","volume":{"uuid":"5dbcc8b8-c649-4fc8-bb41-00ed572fec22","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"468ecd4b-14a6-3b7d-8991-c9dd7427b94a","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/sanjeev/pri_esx_os","port":2049}},"name":"ROOT-4","size":0,"path":"ROOT-4-4","volumeId":4,"vmName":"i-2-4-VM","accountId":2,"format":"OVA","id":4,"hypervisorType":"None"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/sanjeev/sec_esx_os","_role":"Image"}},"vmName":"i-2-4-VM","name":"vm1-esx_ROOT-4_20130729124015","hypervisorType":"None","id":2}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/203","uuid":"3b26874f-ade3-41e9-b726-9c9b03b065c3","id":203,"format":"RAW","accountId":2,"hvm":true,"displayText":"vm1-esx","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/sanjeev/sec_esx_os","_role":"Image"}},"name":"258462a2f-df47-397c-8017-95d575a55aee","hypervisorType":"None"}},"executeInSequence":false,"wait":10800}}]
}
2013-07-29 09:12:41,526 DEBUG [agent.transport.Request]
(AgentManager-Handler-7:null) Seq 3-105971776: Processing: { Ans: , MgmtId:
6615759585382, via: 3, Ver: v1, Flags: 10,
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"","wait":0}}]
}
2013-07-29 09:12:41,526 DEBUG [agent.transport.Request] (Job-Executor-21:job-21
= [ 4cc0ba40-5d27-4231-95af-e88b2eac80f4 ]) Seq 3-105971776: Received: { Ans:
, MgmtId: 6615759585382, via: 3, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2013-07-29 09:12:41,541 DEBUG [cloud.template.TemplateManagerImpl]
(Job-Executor-21:job-21 = [ 4cc0ba40-5d27-4231-95af-e88b2eac80f4 ]) Failed to
create template
2013-07-29 09:12:41,558 ERROR [cloud.async.AsyncJobManagerImpl]
(Job-Executor-21:job-21 = [ 4cc0ba40-5d27-4231-95af-e88b2eac80f4 ]) Unexpected
exception while executing
org.apache.cloudstack.api.command.user.template.CreateTemplateCmd
com.cloud.utils.exception.CloudRuntimeException: Failed to create template
at
com.cloud.template.TemplateManagerImpl.createPrivateTemplate(TemplateManagerImpl.java:1360)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
org.apache.cloudstack.api.command.user.template.CreateTemplateCmd.execute(CreateTemplateCmd.java:263)
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-07-29 09:12:41,567 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-21:job-21 = [ 4cc0ba40-5d27-4231-95af-e88b2eac80f4 ]) Complete
async job-21 = [ 4cc0ba40-5d27-4231-95af-e88b2eac80f4 ], jobStatus: 2,
resultCode: 530, result: Error Code: 530 Error text: Failed to create template
> Object_Store_Refactor - Templates - Not able to create a template from
> snapshot.
> --------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-2481
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-2481
> 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
> Assignee: edison su
> Priority: Critical
> Fix For: 4.2.0
>
> Attachments: cloud.dmp, management-server.rar, management-server.rar
>
>
> Steps to reproduce the problem:
> Deploy a VM.
> Take a snapshot of the root volume.
> Create a template from this snapshot.
> API fails with following error message:
> "DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@bb917d1: DELETE FROM
> vm_template WHERE vm_template.id= 203"
> Management server logs:
> 2013-05-14 09:32:33,964 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null)
> ===START=== 10.217.252.128 -- GET command=createTemplate&response=json
> &sessionkey=X%2FK09rgZ%2BYIUuGYkv7UGa0FoBEc%3D&snapshotid=d44ae73f-3cbd-49d3-8964-6c3325c24286&name=template1&displayText=template1&osTypeId=fce76ff
> 6-bc28-11e2-8a23-6a01c7e420f0&isPublic=true&passwordEnabled=false&_=1368552572710
> 2013-05-14 09:32:34,059 DEBUG [cloud.template.TemplateManagerImpl]
> (catalina-exec-3:null) This template is getting created from other template,
> sett
> ing source template Id to: 202
> 2013-05-14 09:32:34,118 DEBUG [cloud.async.AsyncJobManagerImpl]
> (catalina-exec-3:null) submit async job-18, details: AsyncJobVO {id:18,
> userId: 2, a
> ccountId: 2, sessionKey: null, instanceType: Template, instanceId: 203, cmd:
> org.apache.cloudstack.api.command.user.template.CreateTemplateCmd, cmdO
> riginator: null, cmdInfo:
> {"sessionkey":"X/K09rgZ+YIUuGYkv7UGa0FoBEc\u003d","ctxUserId":"2","httpmethod":"GET","osTypeId":"fce76ff6-bc28-11e2-8a23-6
> a01c7e420f0","isPublic":"true","response":"json","id":"203","displayText":"template1","snapshotid":"d44ae73f-3cbd-49d3-8964-6c3325c24286","passwordE
> nabled":"false","name":"template1","_":"1368552572710","ctxAccountId":"2","ctxStartEventId":"61"},
> 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 09:32:34,119 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-20:job-18) Executing
> org.apache.cloudstack.api.command.user.template.C
> reateTemplateCmd for job-18
> 2013-05-14 09:32:34,122 DEBUG [cloud.api.ApiServlet] (catalina-exec-3:null)
> ===END=== 10.217.252.128 -- GET command=createTemplate&response=json&s
> essionkey=X%2FK09rgZ%2BYIUuGYkv7UGa0FoBEc%3D&snapshotid=d44ae73f-3cbd-49d3-8964-6c3325c24286&name=template1&displayText=template1&osTypeId=fce76ff6-
> bc28-11e2-8a23-6a01c7e420f0&isPublic=true&passwordEnabled=false&_=1368552572710
> 2013-05-14 09:32:34,207 DEBUG [agent.transport.Request]
> (Job-Executor-20:job-18) Seq 3-178062289: Sending { Cmd , MgmtId:
> 206915885079359, via: 3,
> Ver: v1, Flags: 100111,
> [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":
> "snapshots/2/1/29d8dd25-c221-4bbc-bc8b-b89d37e362de","volume":{"uuid":"5d0bd6d7-4ebe-4fb6-98ad-5df52850e739","volumeType":"ROOT","dataStore":{"org.a
> pache.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-5","size":8589934592,"path":"86b8d3a8-44c9-4bb0-b4fb-1ba
> 98d3e4f75","volumeId":5,"vmName":"i-2-5-VM","accountId":2,"id":5},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.223.110.232/export/h
> ome/sangeetha/campo-systemp-1/secondary","_role":"Image"}},"vmName":"i-2-5-VM","name":"test-2_ROOT-5_20130514161859","hypervisorType":"XenServer","i
> d":1}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/2/203","uuid":"7f10ae7a-0e78-40ed-9b51-3a6a23c9dc66","id
> ":203,"format":"RAW","accountId":2,"hvm":true,"displayText":"template1","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.223.110.2
> 32/export/home/sangeetha/campo-systemp-1/secondary","_role":"Image"}},"name":"25860e266-0bd4-3eab-abe5-190cd2cafb8b"}},"wait":10800}}]
> }
> 2013-05-14 09:32:37,151 DEBUG [cloud.api.ApiServlet] (catalina-exec-18:null)
> ===START=== 10.217.252.128 -- GET command=queryAsyncJobResult&jobId=8
> 21ce4f1-c8a8-42ce-a095-70144886b536&response=json&sessionkey=X%2FK09rgZ%2BYIUuGYkv7UGa0FoBEc%3D&_=1368552575986
> 2013-05-14 09:32:37,203 DEBUG [cloud.api.ApiServlet] (catalina-exec-18:null)
> ===END=== 10.217.252.128 -- GET command=queryAsyncJobResult&jobId=821
> ce4f1-c8a8-42ce-a095-70144886b536&response=json&sessionkey=X%2FK09rgZ%2BYIUuGYkv7UGa0FoBEc%3D&_=1368552575986
> 2013-05-14 09:32:38,145 DEBUG [cloud.server.StatsCollector]
> (StatsCollector-1:null) VmStatsCollector is running...
> 2013-05-14 09:32:38,161 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-329:null) Seq 1-738331920: Executing request
> 2013-05-14 09:32:38,400 DEBUG [xen.resource.CitrixResourceBase]
> (DirectAgent-329:null) Vm cpu utilization 0.0010937499999999999
> 2013-05-14 09:32:38,400 DEBUG [xen.resource.CitrixResourceBase]
> (DirectAgent-329:null) Vm cpu utilization 0.00125
> 2013-05-14 09:32:38,400 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-329:null) Seq 1-738331920: Response Received:
> 2013-05-14 09:32:38,400 DEBUG [agent.transport.Request]
> (StatsCollector-1:null) Seq 1-738331920: Received: { Ans: , MgmtId:
> 206915885079359, via: 1
> , Ver: v1, Flags: 10, { GetVmStatsAnswer } }
> 2013-05-14 09:32:39,181 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-111:null) Ping from 1
> 2013-05-14 09:32:39,549 DEBUG [agent.transport.Request]
> (AgentManager-Handler-5:null) Seq 3-178062289: Processing: { Ans: , MgmtId:
> 206915885079359
> , via: 3, Ver: v1, Flags: 110,
> [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"java.io.FileNotFoundException:
> /mn
> t/SecStorage/6cbcf976-4416-3c80-8c9e-319590e1d160/template/tmpl/2/203/template.properties
> (No such file or directory)","wait":0}}] }
> 2013-05-14 09:32:39,549 DEBUG [agent.manager.AgentAttache]
> (AgentManager-Handler-5:null) Seq 3-178062289: No more commands found
> 2013-05-14 09:32:39,549 DEBUG [agent.transport.Request]
> (Job-Executor-20:job-18) Seq 3-178062289: Received: { Ans: , MgmtId:
> 206915885079359, via:
> 3, Ver: v1, Flags: 110, { CopyCmdAnswer } }
> 2013-05-14 09:32:39,609 DEBUG [cloud.template.TemplateManagerImpl]
> (Job-Executor-20:job-18) Failed to create
> templatejava.io.FileNotFoundException:
> /mnt/SecStorage/6cbcf976-4416-3c80-8c9e-319590e1d160/template/tmpl/2/203/template.properties
> (No such file or directory)
> 2013-05-14 09:32:39,615 DEBUG [db.Transaction.Transaction]
> (Job-Executor-20:job-18) Rolling back the transaction: Time = 4 Name =
> -AsyncJobManagerI
> mpl$1.run:401-Executors$RunnableAdapter.call:471-FutureTask$Sync.innerRun:334-FutureTask.run:166-ThreadPoolExecutor.runWorker:1110-ThreadPoolExecuto
> r$Worker.run:603-Thread.run:679; called by
> -Transaction.rollback:890-Transaction.removeUpTo:833-Transaction.close:657-TransactionContextBuilder.inte
> rceptException:63-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:133-TemplateManagerImpl.createPrivateTemplate:1424-ComponentIn
> stantiationPostProcessor$InterceptorDispatcher.intercept:125-CreateTemplateCmd.execute:258-ApiDispatcher.dispatch:155-AsyncJobManagerImpl$1.run:437-
> Executors$RunnableAdapter.call:471-FutureTask$Sync.innerRun:334
> 2013-05-14 09:32:39,636 ERROR [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-20:job-18) Unexpected exception while executing
> org.apache.cloudstack.
> api.command.user.template.CreateTemplateCmd
> com.cloud.utils.exception.CloudRuntimeException: DB Exception on:
> com.mysql.jdbc.JDBC4PreparedStatement@bb917d1: DELETE FROM vm_template WHERE
> vm_te
> mplate.id= 203
> at com.cloud.utils.db.GenericDaoBase.expunge(GenericDaoBase.java:1137)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:12
> 5)
> at
> com.cloud.template.TemplateManagerImpl.createPrivateTemplate(TemplateManagerImpl.java:1424)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:12
> 5)
> 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 constrain
> t 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 09:32:39,637 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-20:job-18) Complete async job-18, jobStatus: 2, resultCode:
> 530, resul
> t: Error Code: 530 Error text: DB Exception on:
> com.mysql.jdbc.JDBC4PreparedStatement@bb917d1: DELETE FROM vm_template WHERE
> vm_template.id= 203
--
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
