Sangeetha Hariharan created CLOUDSTACK-2637: -----------------------------------------------
Summary: Object_Store_Refactor - DB Exception encountered when trying to upload volume. Key: CLOUDSTACK-2637 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-2637 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 Priority: Critical Fix For: 4.2.0 Object_Store_Refactor - DB Exception encountered when trying to upload volume. Steps to reproduce the problem: Deploy a Vm. Attach a data disk to it. Write some changes to the data disk. Take a snapshot of the datadisk. Download this volume. Now Upload this volume using uploadVolume command. This operation fails with following error message: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@47c83c76: INSERT INTO volume_store_ref (volume_store_ref.store_id, volume_store_ref.volume_id, volume_store_ref.zone_id, volume_store_ref.created, volume_store_ref.last_updated, volume_store_ref.download_pct, volume_store_ref.size, volume_store_ref.physical_size, volume_store_ref.download_state, volume_store_ref.checksum, volume_store_ref.local_path, volume_store_ref.error_str, volume_store_ref.job_id, volume_store_ref.install_path, volume_store_ref.url, volume_store_ref.format, volume_store_ref.destroyed, volume_store_ref.update_count, volume_store_ref.updated, volume_store_ref.state) VALUES (1, 10, 0, '2013-05-22 23:26:12', null, 0, 0, 0, null, null, null, null, null, _binary'volumes/2/10', null, null, 0, 0, null, 'Allocated') 013-05-22 16:26:12,464 INFO [cloud.api.ApiServer] (catalina-exec-6:null) (userId=2 accountId=2 sessionId=D91C4E4C17F0583A30B61BA0525D7FF8) 10.216.51.144 -- GET command=uploadVolume&response=json&sessionkey=YVb5KPqcM3%2B%2BRpKwK3nTB2j6PTg%3D&name=volfromtest&zoneId=9c88115b-ff6e-47af-9033-e592da1f395c&format=VHD&url=http%3A%2F%2F10.223.110.232%2Ftemplates%2Ftest%2F64163ecc-060a-4a80-a396-54e57a2bae27.vhd&_=1369268599951 200 { "uploadvolumeresponse" : {"jobid":"0227985e-52ea-4605-87b3-c06e2df8bef7"} } 2013-05-22 16:26:15,524 INFO [cloud.api.ApiServer] (catalina-exec-5:null) (userId=2 accountId=2 sessionId=D91C4E4C17F0583A30B61BA0525D7FF8) 10.216.51.144 -- GET command=queryAsyncJobResult&jobId=0227985e-52ea-4605-87b3-c06e2df8bef7&response=json&sessionkey=YVb5KPqcM3%2B%2BRpKwK3nTB2j6PTg%3D&_=1369268603245 200 { "queryasyncjobresultresponse" : {"accountid":"89db33ec-c193-11e2-8a23-6a01c7e420f0","userid":"89dc6e24-c193-11e2-8a23-6a01c7e420f0","cmd":"org.apache.cloudstack.api.command.user.volume.UploadVolumeCmd","jobstatus":2,"jobprocstatus":0,"jobresultcode":530,"jobresulttype":"object","jobresult":{"errorcode":530,"errortext":"DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@47c83c76: INSERT INTO volume_store_ref (volume_store_ref.store_id, volume_store_ref.volume_id, volume_store_ref.zone_id, volume_store_ref.created, volume_store_ref.last_updated, volume_store_ref.download_pct, volume_store_ref.size, volume_store_ref.physical_size, volume_store_ref.download_state, volume_store_ref.checksum, volume_store_ref.local_path, volume_store_ref.error_str, volume_store_ref.job_id, volume_store_ref.install_path, volume_store_ref.url, volume_store_ref.format, volume_store_ref.destroyed, volume_store_ref.update_count, volume_store_ref.updated, volume_store_ref.state) VALUES (1, 10, 0, '2013-05-22 23:26:12', null, 0, 0, 0, null, null, null, null, null, _binary'volumes/2/10', null, null, 0, 0, null, 'Allocated')"},"created":"2013-05-22T16:26:12-0700","jobid":"0227985e-52ea-4605-87b3-c06e2df8bef7"} } Management server logs : 2013-05-22 16:26:12,362 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null) ===START=== 10.216.51.144 -- GET command=uploadVolume&response=json&sessionkey=YVb5KPqcM3%2B%2BRpKwK3nTB2j6PTg%3D&name=volfromtest&zoneId=9c88115b-ff6e-47af-9033-e592da1f395c&format=VHD&url=http%3A%2F%2F10.223.110.232%2Ftemplates%2Ftest%2F64163ecc-060a-4a80-a396-54e57a2bae27.vhd&_=1369268599951 2013-05-22 16:26:12,460 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-6:null) submit async job-50, details: AsyncJobVO {id:50, userId: 2, accountId: 2, sessionKey: null, instanceType: None, instanceId: null, cmd: org.apache.cloudstack.api.command.user.volume.UploadVolumeCmd, cmdOriginator: null, cmdInfo: {"response":"json","sessionkey":"YVb5KPqcM3++RpKwK3nTB2j6PTg\u003d","ctxUserId":"2","name":"volfromtest","httpmethod":"GET","_":"1369268599951","ctxAccountId":"2","format":"VHD","ctxStartEventId":"149","url":"http://10.223.110.232/templates/test/64163ecc-060a-4a80-a396-54e57a2bae27.vhd","zoneId":"9c88115b-ff6e-47af-9033-e592da1f395c"}, 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-22 16:26:12,462 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-27:job-50) Executing org.apache.cloudstack.api.command.user.volume.UploadVolumeCmd for job-50 2013-05-22 16:26:12,464 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null) ===END=== 10.216.51.144 -- GET command=uploadVolume&response=json&sessionkey=YVb5KPqcM3%2B%2BRpKwK3nTB2j6PTg%3D&name=volfromtest&zoneId=9c88115b-ff6e-47af-9033-e592da1f395c&format=VHD&url=http%3A%2F%2F10.223.110.232%2Ftemplates%2Ftest%2F64163ecc-060a-4a80-a396-54e57a2bae27.vhd&_=1369268599951 2013-05-22 16:26:12,508 DEBUG [db.Transaction.Transaction] (Job-Executor-27:job-50) 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-ObjectInDataStoreManagerImpl.create:160-ImageStoreImpl.create:142-VolumeServiceImpl.registerVolume:822-VolumeManagerImpl.uploadVolume:397-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-VolumeManagerImpl.uploadVolume:183-UploadVolumeCmd.execute:121 2013-05-22 16:26:12,519 ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-27:job-50) Unexpected exception while executing org.apache.cloudstack.api.command.user.volume.UploadVolumeCmd com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@47c83c76: INSERT INTO volume_store_ref (volume_store_ref.store_id, volume_store_ref.volume_id, volume_store_ref.zone_id, volume_store_ref.created, volume_store_ref.last_updated, volume_store_ref.download_pct, volume_store_ref.size, volume_store_ref.physical_size, volume_store_ref.download_state, volume_store_ref.checksum, volume_store_ref.local_path, volume_store_ref.error_str, volume_store_ref.job_id, volume_store_ref.install_path, volume_store_ref.url, volume_store_ref.format, volume_store_ref.destroyed, volume_store_ref.update_count, volume_store_ref.updated, volume_store_ref.state) VALUES (1, 10, 0, '2013-05-22 23:26:12', null, 0, 0, 0, null, null, null, null, null, _binary'volumes/2/10', null, null, 0, 0, null, 'Allocated') at com.cloud.utils.db.GenericDaoBase.persist(GenericDaoBase.java:1342) at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) at org.apache.cloudstack.storage.datastore.ObjectInDataStoreManagerImpl.create(ObjectInDataStoreManagerImpl.java:160) at org.apache.cloudstack.storage.image.store.ImageStoreImpl.create(ImageStoreImpl.java:142) at org.apache.cloudstack.storage.volume.VolumeServiceImpl.registerVolume(VolumeServiceImpl.java:822) at com.cloud.storage.VolumeManagerImpl.uploadVolume(VolumeManagerImpl.java:397) at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) at com.cloud.storage.VolumeManagerImpl.uploadVolume(VolumeManagerImpl.java:183) at org.apache.cloudstack.api.command.user.volume.UploadVolumeCmd.execute(UploadVolumeCmd.java:121) 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: Column 'format' cannot be null 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.persist(GenericDaoBase.java:1305) ... 25 more 2013-05-22 16:26:12,520 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-27:job-50) Complete async job-50, jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@47c83c76: INSERT INTO volume_store_ref (volume_store_ref.store_id, volume_store_ref.volume_id, volume_store_ref.zone_id, volume_store_ref.created, volume_store_ref.last_updated, volume_store_ref.download_pct, volume_store_ref.size, volume_store_ref.physical_size, volume_store_ref.download_state, volume_store_ref.checksum, volume_store_ref.local_path, volume_store_ref.error_str, volume_store_ref.job_id, volume_store_ref.install_path, volume_store_ref.url, volume_store_ref.format, volume_store_ref.destroyed, volume_store_ref.update_count, volume_store_ref.updated, volume_store_ref.state) VALUES (1, 10, 0, '2013-05-22 23:26:12', null, 0, 0, 0, null, null, null, null, null, _binary'volumes/2/10', null, null, 0, 0, null, 'Allocated') 2013-05-22 16:26:15,506 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===START=== 10.216.51.144 -- GET command=queryAsyncJobResult&jobId=0227985e-52ea-4605-87b3-c06e2df8bef7&response=json&sessionkey=YVb5KPqcM3%2B%2BRpKwK3nTB2j6PTg%3D&_=1369268603245 2013-05-22 16:26:15,520 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-5:null) Async job-50 completed -- 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