You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Sanjeev N (JIRA)" <ji...@apache.org> on 2013/07/17 08:12:50 UTC
[jira] [Reopened] (CLOUDSTACK-2584) [Object_Store_Refactor] Failed
to create template from stopped guest vm's root disk
[ https://issues.apache.org/jira/browse/CLOUDSTACK-2584?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Sanjeev N reopened CLOUDSTACK-2584:
-----------------------------------
Observed this issue again in the latest build from ACS4.2 branch with the following combinations:
Secondary: S3
Primary : Local Storage
Cluster: KVM
Following is the snippet from the management server log file:
2013-07-17 01:55:15,700 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===START=== 10.101.255.91 -- GET command=createTemplate&response=json&sessionkey=hv2IwcUdfj2BRf%2FYRDbh4n6KwWU%3D&volumeId=11fe57d4-54d8-46e1-b93b-5e49c9826184&name=cent_vm&displayText=cent_vm&osTypeId=ba38e2b4-edf8-11e2-9c55-06045a000066&isPublic=true&passwordEnabled=false&isfeatured=true&_=1374040515719
2013-07-17 01:55:15,855 DEBUG [cloud.template.TemplateManagerImpl] (catalina-exec-5:null) This template is getting created from other template, setting source template Id to: 203
2013-07-17 01:55:15,919 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-5:null) submit async job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ], details: AsyncJobVO {id:39, userId: 2, accountId: 2, sessionKey: null, instanceType: Template, instanceId: 204, cmd: org.apache.cloudstack.api.command.user.template.CreateTemplateCmd, cmdOriginator: null, cmdInfo: {"sessionkey":"hv2IwcUdfj2BRf/YRDbh4n6KwWU\u003d","cmdEventType":"TEMPLATE.CREATE","volumeId":"11fe57d4-54d8-46e1-b93b-5e49c9826184","ctxUserId":"2","httpmethod":"GET","osTypeId":"ba38e2b4-edf8-11e2-9c55-06045a000066","isPublic":"true","isfeatured":"true","response":"json","id":"204","displayText":"cent_vm","passwordEnabled":"false","name":"cent_vm","_":"1374040515719","ctxAccountId":"2","ctxStartEventId":"136"}, 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-17 01:55:15,922 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===END=== 10.101.255.91 -- GET command=createTemplate&response=json&sessionkey=hv2IwcUdfj2BRf%2FYRDbh4n6KwWU%3D&volumeId=11fe57d4-54d8-46e1-b93b-5e49c9826184&name=cent_vm&displayText=cent_vm&osTypeId=ba38e2b4-edf8-11e2-9c55-06045a000066&isPublic=true&passwordEnabled=false&isfeatured=true&_=1374040515719
2013-07-17 01:55:15,929 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-39:job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ]) Executing org.apache.cloudstack.api.command.user.template.CreateTemplateCmd for job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ]
2013-07-17 01:55:15,994 DEBUG [storage.motion.AncientDataMotionStrategy] (Job-Executor-39:job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ]) copyAsync inspecting src type VOLUME copyAsync inspecting dest type TEMPLATE
2013-07-17 01:55:16,008 DEBUG [storage.motion.AncientDataMotionStrategy] (Job-Executor-39:job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ]) needCacheStorage true, dest at template/tmpl/2/204/2425d37ef-3961-3194-996a-913b4e9df00b dest role Image2c4ce55a-5f8a-423b-8c60-a92d77dbf185 src role Primary
2013-07-17 01:55:16,030 DEBUG [storage.motion.AncientDataMotionStrategy] (Job-Executor-39:job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ]) copyAsync inspecting src type VOLUME copyAsync inspecting dest type VOLUME
2013-07-17 01:55:16,054 DEBUG [agent.transport.Request] (Job-Executor-39:job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ]) Seq 1-662441576: Sending { Cmd , MgmtId: 6615759585382, via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"11fe57d4-54d8-46e1-b93b-5e49c9826184","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"03497158-90a8-426c-a02f-8345e4ba9ff8","id":1,"poolType":"Filesystem","host":"10.147.40.14","path":"/var/lib/libvirt/images","port":0}},"name":"ROOT-21","size":139264,"path":"2c4ce55a-5f8a-423b-8c60-a92d77dbf185","volumeId":23,"vmName":"i-2-21-VM","accountId":2,"format":"QCOW2","id":23}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"11fe57d4-54d8-46e1-b93b-5e49c9826184","volumeType":"ROOT","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/sanjeev/sec_kvm_os","_role":"ImageCache"}},"name":"ROOT-21","size":139264,"path":"volumes/2/23","volumeId":23,"vmName":"i-2-21-VM","accountId":2,"format":"QCOW2","id":23}},"executeInSequence":false,"wait":10800}}] }
2013-07-17 01:55:16,143 DEBUG [agent.transport.Request] (AgentManager-Handler-15:null) Seq 1-662441576: Processing: { Ans: , MgmtId: 6615759585382, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.UnsupportedAnswer":{"result":false,"details":"Unsupported command issued:org.apache.cloudstack.storage.command.CopyCommand. Are you sure you got the right type of server?","wait":0}}] }
2013-07-17 01:55:16,143 DEBUG [agent.transport.Request] (Job-Executor-39:job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ]) Seq 1-662441576: Received: { Ans: , MgmtId: 6615759585382, via: 1, Ver: v1, Flags: 10, { UnsupportedAnswer } }
2013-07-17 01:55:16,143 WARN [agent.manager.AgentManagerImpl] (Job-Executor-39:job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ]) Unsupported Command: Unsupported command issued:org.apache.cloudstack.storage.command.CopyCommand. Are you sure you got the right type of server?
2013-07-17 01:55:16,163 DEBUG [storage.motion.AncientDataMotionStrategy] (Job-Executor-39:job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ]) copy object failed: java.lang.NullPointerException
2013-07-17 01:55:16,163 DEBUG [storage.motion.AncientDataMotionStrategy] (Job-Executor-39:job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ]) copy failed
com.cloud.utils.exception.CloudRuntimeException: java.lang.NullPointerException
at org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyObject(AncientDataMotionStrategy.java:207)
at org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:354)
at org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:55)
at org.apache.cloudstack.storage.image.TemplateServiceImpl.copyAsync(TemplateServiceImpl.java:549)
at org.apache.cloudstack.storage.image.TemplateServiceImpl.createTemplateFromVolumeAsync(TemplateServiceImpl.java:562)
at com.cloud.template.TemplateManagerImpl.createPrivateTemplate(TemplateManagerImpl.java:1361)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at org.apache.cloudstack.api.command.user.template.CreateTemplateCmd.execute(CreateTemplateCmd.java:256)
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-17 01:55:16,177 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-39:job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ]) Failed to create templatecom.cloud.utils.exception.CloudRuntimeException: java.lang.NullPointerException
2013-07-17 01:55:16,227 ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-39:job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ]) Unexpected exception while executing org.apache.cloudstack.api.command.user.template.CreateTemplateCmd
com.cloud.utils.exception.CloudRuntimeException: Failed to create templatecom.cloud.utils.exception.CloudRuntimeException: java.lang.NullPointerException
at com.cloud.template.TemplateManagerImpl.createPrivateTemplate(TemplateManagerImpl.java:1372)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at org.apache.cloudstack.api.command.user.template.CreateTemplateCmd.execute(CreateTemplateCmd.java:256)
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-17 01:55:16,230 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-39:job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ]) Complete async job-39 = [ c7188e7a-dea7-47c4-9a7c-1c1579a3f493 ], jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: Failed to create templatecom.cloud.utils.exception.CloudRuntimeException: java.lang.NullPointerException
> [Object_Store_Refactor] Failed to create template from stopped guest vm's root disk
> -----------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-2584
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-2584
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: Template
> Affects Versions: 4.2.0
> Environment: Build from object_store branch
> Reporter: Sanjeev N
> Assignee: edison su
> Priority: Critical
> Fix For: 4.2.0
>
> Attachments: management-server.rar
>
>
> [Object_Store_Refactor] Failed to create template from stopped guest vm's root disk
> Steps to reproduce:
> ================
> 1.Bring up CS in advanced zone with S3 as the secondary storage provider
> 2.Deploy guest vm with default cent os template downloaded after system vms are up
> 3.Stop the guest vm and try to take template from the root volume of the guest vm deployed above
> Observations:
> ============
> Observed following exception while taking template:
> 2013-05-20 12:33:23,481 DEBUG [cloud.api.ApiServlet] (catalina-exec-15:null) ===START=== 10.146.0.15 -- GET command=createTemplate&response=json&sessionkey=R6B02dSeoRFzL6CVp2PX3UbfsGg%3D&volumeId=135a3df1-20e1-4b4b-a433-86976ddc9218&name=root3&displayText=root3&osTypeId=6d6b2f3e-c0bf-11e2-8198-06ab4600005f&isPublic=true&passwordEnabled=false&isfeatured=true&_=1369047892340
> 2013-05-20 12:33:23,711 DEBUG [cloud.template.TemplateManagerImpl] (catalina-exec-15:null) This template is getting created from other template, setting source template Id to: 5
> 2013-05-20 12:33:23,763 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-15:null) submit async job-19, details: AsyncJobVO {id:19, userId: 2, accountId: 2, sessionKey: null, instanceType: Template, instanceId: 205, cmd: org.apache.cloudstack.api.command.user.template.CreateTemplateCmd, cmdOriginator: null, cmdInfo: {"sessionkey":"R6B02dSeoRFzL6CVp2PX3UbfsGg\u003d","volumeId":"135a3df1-20e1-4b4b-a433-86976ddc9218","ctxUserId":"2","httpmethod":"GET","osTypeId":"6d6b2f3e-c0bf-11e2-8198-06ab4600005f","isPublic":"true","isfeatured":"true","response":"json","id":"205","displayText":"root3","passwordEnabled":"false","name":"root3","_":"1369047892340","ctxAccountId":"2","ctxStartEventId":"75"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 7332683579487, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2013-05-20 12:33:23,766 DEBUG [cloud.api.ApiServlet] (catalina-exec-15:null) ===END=== 10.146.0.15 -- GET command=createTemplate&response=json&sessionkey=R6B02dSeoRFzL6CVp2PX3UbfsGg%3D&volumeId=135a3df1-20e1-4b4b-a433-86976ddc9218&name=root3&displayText=root3&osTypeId=6d6b2f3e-c0bf-11e2-8198-06ab4600005f&isPublic=true&passwordEnabled=false&isfeatured=true&_=1369047892340
> 2013-05-20 12:33:23,774 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-6:job-19) Executing org.apache.cloudstack.api.command.user.template.CreateTemplateCmd for job-19
> 2013-05-20 12:33:23,853 DEBUG [cloud.template.TemplateManagerImpl] (Job-Executor-6:job-19) Failed to create templatecom.cloud.utils.exception.CloudRuntimeException: Can't find cache storage in zone: null
> 2013-05-20 12:33:23,857 DEBUG [db.Transaction.Transaction] (Job-Executor-6:job-19) Rolling back the transaction: Time = 3 Name = -AsyncJobManagerImpl$1.run:401-Executors$RunnableAdapter.call:471-FutureTask$Sync.innerRun:334-FutureTask.run:166-ThreadPoolExecutor.runWorker:1146-ThreadPoolExecutor$Worker.run:615-Thread.run:679; called by -Transaction.rollback:890-Transaction.removeUpTo:833-Transaction.close:657-TransactionContextBuilder.interceptException:63-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:133-TemplateManagerImpl.createPrivateTemplate:1433-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-CreateTemplateCmd.execute:258-ApiDispatcher.dispatch:155-AsyncJobManagerImpl$1.run:437-Executors$RunnableAdapter.call:471-FutureTask$Sync.innerRun:334
> 2013-05-20 12:33:23,867 ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-6:job-19) Unexpected exception while executing org.apache.cloudstack.api.command.user.template.CreateTemplateCmd
> com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@6265c4a7: DELETE FROM vm_template WHERE vm_template.id= 205
> 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:1433)
> 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:1146)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> 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-20 12:33:23,870 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-6:job-19) Complete async job-19, jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@6265c4a7: DELETE FROM vm_template WHERE vm_template.id= 205
> 2.Even though the template creation failed, I could see template state as Allocated in vm_template and template_store_ref tables:
> mysql> select * from vm_template where id=205\G;
> *************************** 1. row ***************************
> id: 205
> unique_name: 25a63a226-e490-3bc7-885e-fb9c83464397
> name: root3
> uuid: 088f76b9-1765-4eac-bdc6-8d51716cf9d5
> public: 1
> featured: 1
> type: USER
> hvm: 1
> bits: 64
> url: NULL
> format: RAW
> created: 2013-05-20 16:33:23
> removed: NULL
> account_id: 2
> checksum: NULL
> display_text: root3
> enable_password: 0
> enable_sshkey: 0
> guest_os_id: 142
> bootable: 1
> prepopulate: 0
> cross_zones: 0
> extractable: 1
> hypervisor_type: XenServer
> source_template_id: 5
> template_tag: NULL
> sort_key: 0
> size: NULL
> state: Allocated
> update_count: 2
> updated: 2013-05-20 16:33:23
> 1 row in set (0.00 sec)
> ERROR:
> No query specified
> mysql> select * from template_store_ref where template_id=205\G;
> *************************** 1. row ***************************
> id: 12
> store_id: 1
> template_id: 205
> created: 2013-05-20 16:33:23
> last_updated: NULL
> job_id: NULL
> download_pct: 0
> size: 0
> store_role: Image
> physical_size: 0
> download_state: NULL
> error_str: NULL
> local_path: NULL
> install_path: template/tmpl/2/205
> url: NULL
> state: Allocated
> destroyed: 0
> is_copy: 0
> update_count: 2
> updated: 2013-05-20 16:33:23
> 1 row in set (0.00 sec)
> ERROR:
> No query specified
>
--
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