cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Sanjeev N (JIRA)" <j...@apache.org>
Subject [jira] [Created] (CLOUDSTACK-4112) [Object_store_refactor] Attaching uploaded volume fails with DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@53b69b6d:
Date Tue, 06 Aug 2013 12:26:48 GMT
Sanjeev N created CLOUDSTACK-4112:
-------------------------------------

             Summary: [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
            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

Mime
View raw message