[
https://issues.apache.org/jira/browse/CLOUDSTACK-4112?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Min Chen reassigned CLOUDSTACK-4112:
------------------------------------
Assignee: Min Chen
> [Object_store_refactor] Attaching uploaded volume fails with DB Exception on:
> com.mysql.jdbc.JDBC4PreparedStatement@53b69b6d:
> -----------------------------------------------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-4112
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4112
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Storage Controller, VMware, Volumes
> Affects Versions: 4.2.0
> Environment: Latest build from ACS 4.2 branch.
> Storage: S3 for Secondary, NFS for secondarystaging, ISCSI for Primary
> Cluster: VMWare
> Reporter: Sanjeev N
> Assignee: Min Chen
> Priority: Critical
> Fix For: 4.2.0
>
> Attachments: cloud.dmp, management-server.rar
>
>
> [Object_store_refactor] Attaching uploaded volume fails with DB Exception on:
> com.mysql.jdbc.JDBC4PreparedStatement@53b69b6d: UPDATE volumes SET
> volumes.path=_binary'd093eb32a65a49e08e8237edac6772c9', volumes.pool_id=1,
> volumes.size=null WHERE volumes.id = 12
> Steps to Reproduce:
> =================
> 1.Bring up CS with VMWare cluster using S3 for Secondary, NFS for secondary
> staging and ISCSI for Primary storage.
> 2.Deploy guest vm using default cent os template
> 3.Upload volume using API:
> http://10.147.59.126:8096/client/api?command=uploadVolume&format=OVA&name=cent53-upload&url=http://10.147.28.7/templates/vmware/CentOS5.3-x86_64.ova&zoneid=a7c59acd-1b2f-4f06-b50b-bd79e113c692&account=admin&domainid=1
> 4.Attach volume to guest vm
> Result:
> ======
> Attaching uploaded volume to guest vm is failing with DB Exception.
> Observations:
> ==========
> During attach volume process, uploaded volume was successfully copied from S3
> to staging secondary storage. copyCmdAnswer result is true even for copying
> volume from staging secondary storage to primary storage.
> However attaching volume failed with DB Exception.
> Log snippet is as follows:
> 2013-08-06 08:06:48,905 DEBUG [cloud.async.AsyncJobManagerImpl]
> (catalina-exec-13:null) submit async job-27 = [
> 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ], details: AsyncJobVO {id:27, userId:
> 2, accountId: 2, sessionKey: null, instanceType: Volume, instanceId: 12, cmd:
> org.apache.cloudstack.api.command.user.volume.AttachVolumeCmd, cmdOriginator:
> null, cmdInfo:
> {"id":"3b18f8e5-e7e9-4658-9a85-a58275d1fbef","response":"json","sessionkey":"foQa9K4dPmYo8uEiAcolaTVR6yI\u003d","cmdEventType":"VOLUME.ATTACH","ctxUserId":"2","virtualMachineId":"e22af295-6429-4338-8a68-b6dba7753931","httpmethod":"GET","_":"1375790796785","ctxAccountId":"2","ctxStartEventId":"102"},
> 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-08-06 08:06:48,908 DEBUG [cloud.api.ApiServlet] (catalina-exec-13:null)
> ===END=== 10.146.0.20 -- GET
> command=attachVolume&id=3b18f8e5-e7e9-4658-9a85-a58275d1fbef&virtualMachineId=e22af295-6429-4338-8a68-b6dba7753931&response=json&sessionkey=foQa9K4dPmYo8uEiAcolaTVR6yI%3D&_=1375790796785
> 2013-08-06 08:06:48,912 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) Executing
> org.apache.cloudstack.api.command.user.volume.AttachVolumeCmd for job-27 = [
> 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]
> 2013-08-06 08:06:48,967 DEBUG [storage.allocator.LocalStoragePoolAllocator]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ])
> LocalStoragePoolAllocator trying to find storage pool to fit the vm
> 2013-08-06 08:06:48,969 DEBUG
> [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-28:job-27
> = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) ClusterScopeStoragePoolAllocator
> looking for storage pool
> 2013-08-06 08:06:48,970 DEBUG
> [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-28:job-27
> = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) Looking for pools in dc: 1 pod:1
> cluster:1
> 2013-08-06 08:06:48,976 DEBUG
> [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-28:job-27 = [
> 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) Checking if storage pool is suitable,
> name: null ,poolId: 1
> 2013-08-06 08:06:48,985 DEBUG [cloud.storage.StorageManagerImpl]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) Checking
> pool 1 for storage, totalSize: 93952409600, usedBytes: 4970250240, usedPct:
> 0.052901785714285714, disable threshold: 0.85
> 2013-08-06 08:06:48,999 DEBUG [cloud.storage.StorageManagerImpl]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) Checking
> pool: 1 for volume allocation [Vol[12|vm=null|DATADISK]], maxSize :
> 93952409600, totalAllocatedSize : 1769931776, askingSize : 459320832,
> allocated disable threshold: 0.85
> 2013-08-06 08:06:48,999 DEBUG
> [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-28:job-27
> = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) FirstFitStoragePoolAllocator
> returning 1 suitable storage pools
> 2013-08-06 08:06:49,033 DEBUG [storage.motion.AncientDataMotionStrategy]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) copyAsync
> inspecting src type VOLUME copyAsync inspecting dest type VOLUME
> 2013-08-06 08:06:49,043 DEBUG [storage.motion.AncientDataMotionStrategy]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ])
> needCacheStorage true, dest at null dest role
> Primaryvolumes/2/12/CentOS5.3-x86_64.ova src role Image
> 2013-08-06 08:06:49,068 DEBUG [storage.motion.AncientDataMotionStrategy]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) copyAsync
> inspecting src type VOLUME copyAsync inspecting dest type VOLUME
> 2013-08-06 08:06:49,112 DEBUG [agent.transport.Request]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) Seq
> 3-1317535777: Sending { Cmd , MgmtId: 6615759585382, via: 3, Ver: v1, Flags:
> 100011,
> [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"3b18f8e5-e7e9-4658-9a85-a58275d1fbef","volumeType":"DATADISK","dataStore":{"com.cloud.agent.api.to.S3TO":{"id":9,"uuid":"fc2025c3-0d27-4f54-a7e0-c39e4494420b","endPoint":"10.147.29.57:8080","bucketName":"imagestore","httpsFlag":false,"created":"Aug
> 6, 2013 7:50:34
> AM","enableRRS":false}},"name":"cent53-upload","size":459320832,"path":"volumes/2/12/CentOS5.3-x86_64.ova","volumeId":12,"accountId":2,"format":"OVA","id":12,"hypervisorType":"None"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"3b18f8e5-e7e9-4658-9a85-a58275d1fbef","volumeType":"DATADISK","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/sanjeev/sec_esx_os","_role":"ImageCache"}},"name":"cent53-upload","size":459320832,"path":"volumes/2/12","volumeId":12,"accountId":2,"format":"OVA","id":12,"hypervisorType":"None"}},"executeInSequence":false,"wait":10800}}]
> }
> 2013-08-06 08:07:16,725 DEBUG [agent.transport.Request]
> (AgentManager-Handler-8:null) Seq 3-1317535777: Processing: { Ans: , MgmtId:
> 6615759585382, via: 3, Ver: v1, Flags: 10,
> [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"name":"24998551-bab1-4b9c-864c-cdcc23b21a3c.ova","size":459320832,"path":"volumes/2/12/24998551-bab1-4b9c-864c-cdcc23b21a3c.ova","accountId":0,"id":0}},"result":true,"wait":0}}]
> }
> 2013-08-06 08:07:16,725 DEBUG [agent.transport.Request]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) Seq
> 3-1317535777: Received: { Ans: , MgmtId: 6615759585382, via: 3, Ver: v1,
> Flags: 10, { CopyCmdAnswer } }
> 2013-08-06 08:07:16,780 DEBUG [agent.transport.Request]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) Seq
> 3-1317535778: Sending { Cmd , MgmtId: 6615759585382, via: 3, Ver: v1, Flags:
> 100011,
> [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"3b18f8e5-e7e9-4658-9a85-a58275d1fbef","volumeType":"DATADISK","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/sanjeev/sec_esx_os","_role":"ImageCache"}},"name":"cent53-upload","size":459320832,"path":"volumes/2/12/24998551-bab1-4b9c-864c-cdcc23b21a3c.ova","volumeId":12,"accountId":2,"format":"OVA","id":12,"hypervisorType":"None"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"3b18f8e5-e7e9-4658-9a85-a58275d1fbef","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b845e7d4-562a-3b2d-8e59-b1df565f99e5","id":1,"poolType":"VMFS","host":"VMFS
> datastore:
> /sanjeev/openFiler","path":"/sanjeev/openFiler","port":0}},"name":"cent53-upload","size":459320832,"volumeId":12,"accountId":2,"format":"OVA","id":12,"hypervisorType":"None"}},"executeInSequence":false,"wait":10800}}]
> }
> 2013-08-06 08:09:24,002 DEBUG [agent.transport.Request]
> (AgentManager-Handler-14:null) Seq 3-1317535778: Processing: { Ans: ,
> MgmtId: 6615759585382, via: 3, Ver: v1, Flags: 10,
> [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"path":"d093eb32a65a49e08e8237edac6772c9","accountId":0,"id":0}},"result":true,"wait":0}}]
> }
> 2013-08-06 08:09:24,002 DEBUG [agent.transport.Request]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) Seq
> 3-1317535778: Received: { Ans: , MgmtId: 6615759585382, via: 3, Ver: v1,
> Flags: 10, { CopyCmdAnswer } }
> 2013-08-06 08:09:24,030 DEBUG [db.Transaction.Transaction]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) Rolling
> back the transaction: Time = 2 Name =
> -AsyncJobManagerImpl$1.run:494-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:896-Transaction.removeUpTo:839-Transaction.close:663-TransactionContextBuilder.interceptException:63-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:133-GenericDaoBase.update:774-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-GenericDaoBase.update:1262-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-VolumeObject.processEvent:476-VolumeServiceImpl.copyVolumeFromImageToPrimaryCallback:689-NativeMethodAccessorImpl.invoke0:-2
> 2013-08-06 08:09:24,033 DEBUG [cloud.storage.VolumeManagerImpl]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) copy
> volume failed: com.cloud.utils.exception.CloudRuntimeException: DB Exception
> on: com.mysql.jdbc.JDBC4PreparedStatement@53b69b6d: UPDATE volumes SET
> volumes.path=_binary'd093eb32a65a49e08e8237edac6772c9', volumes.pool_id=1,
> volumes.size=null WHERE volumes.id = 12
> 2013-08-06 08:09:24,042 ERROR [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ])
> Unexpected exception while executing
> org.apache.cloudstack.api.command.user.volume.AttachVolumeCmd
> com.cloud.utils.exception.CloudRuntimeException: copy volume failed:
> com.cloud.utils.exception.CloudRuntimeException: DB Exception on:
> com.mysql.jdbc.JDBC4PreparedStatement@53b69b6d: UPDATE volumes SET
> volumes.path=_binary'd093eb32a65a49e08e8237edac6772c9', volumes.pool_id=1,
> volumes.size=null WHERE volumes.id = 12
> at
> com.cloud.storage.VolumeManagerImpl.copyVolumeFromSecToPrimary(VolumeManagerImpl.java:634)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> com.cloud.storage.VolumeManagerImpl.copyVolume(VolumeManagerImpl.java:1501)
> at
> com.cloud.storage.VolumeManagerImpl.createVolumeOnPrimaryStorage(VolumeManagerImpl.java:1532)
> at
> com.cloud.storage.VolumeManagerImpl.attachVolumeToVM(VolumeManagerImpl.java:1829)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> org.apache.cloudstack.api.command.user.volume.AttachVolumeCmd.execute(AttachVolumeCmd.java:122)
> 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-06 08:09:24,046 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-28:job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ]) Complete
> async job-27 = [ 1a25a5ce-76b8-4dd4-be82-2723a91daff6 ], jobStatus: 2,
> resultCode: 530, result: Error Code: 530 Error text: copy volume failed:
> com.cloud.utils.exception.CloudRuntimeException: DB Exception on:
> com.mysql.jdbc.JDBC4PreparedStatement@53b69b6d: UPDATE volumes SET
> volumes.path=_binary'd093eb32a65a49e08e8237edac6772c9', volumes.pool_id=1,
> volumes.size=null WHERE volumes.id = 12
> In volumes table state remains in "Copying" state for this volume.
> Attaching management server log file and cloud DB.
--
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
