[
https://issues.apache.org/jira/browse/CLOUDSTACK-5558?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13853064#comment-13853064
]
Min Chen commented on CLOUDSTACK-5558:
--------------------------------------
Can you show the DB result for snapshot_store_ref before deletion including
ref_cnt column? The error complained that ref_cnt for the child snapshot on
snapshot_store_ref is too big (18446744073709551615), normally it cannot be
incremented like that at all. Not sure what exactly operations you have done
causing this. Also, did you run this with the build containing my fix for
CLOUDSTACK-5541? I think with that fix, this problem should go away, since
backupSnapshot will remove that db entry with store_role as ImageCache after
backing up to secondary.
> Delete Snapshot throws an exception with S3 store
> -------------------------------------------------
>
> Key: CLOUDSTACK-5558
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5558
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Snapshot
> Affects Versions: 4.3.0
> Environment: Xenserver host
> 4.3 MS
> Reporter: Pavan Kumar Bandarupally
> Assignee: Min Chen
> Fix For: 4.3.0
>
>
> A snapshot of the root volume is taken and is backed up to S3 Image Store.
> Another snapshot of the same root volume is taken at a later point of time
> and this will be an incremental snapshot having a child relationship to the
> earlier one.
> Now delete the first snapshot (parent) and the operation completes
> successfully. The actual snapshot will not be deleted from the storage as it
> has children remaining. The same will be reflected in the traces.
> Now delete the child snapshot and it will succesfully be deleted from UI and
> Storage but an exception is thrown in the traces.
> DB snapshot_store_ref table before deletion of snapshot:
> --------------------------------------------------------------------------
> mysql> select snapshot_id, store_id, store_role, state, install_path from
> snapshot_store_ref;
> +-------------+----------+------------+-----------+--------------------------------------------------------+
> | snapshot_id | store_id | store_role | state | install_path
> |
> +-------------+----------+------------+-----------+--------------------------------------------------------+
> | 2 | 2 | Image | Ready |
> snapshots/2/3/d57dc76a-fa1d-474c-9da6-463d69932917.vhd |
> | 2 | 1 | ImageCache | Ready | snapshots/2/3
> |
> | 2 | 1 | ImageCache | Allocated |
> snapshots/2/3/d57dc76a-fa1d-474c-9da6-463d69932917.vhd |
> | 3 | 1 | Primary | Ready |
> 9ff92074-7876-40c7-baf4-6b354907220a |
> | 3 | 2 | Image | Ready |
> snapshots/2/3/d57dc76a-fa1d-474c-9da6-463d69932917.vhd |
> +-------------+----------+------------+-----------+--------------------------------------------------------+
> 5 rows in set (0.00 sec)
> DB snapshot_store_ref table after deletion of snapshot:
> --------------------------------------------------------------------------
> mysql> select snapshot_id, store_id, store_role, state, install_path from
> snapshot_store_ref;
> +-------------+----------+------------+-----------+--------------------------------------------------------+
> | snapshot_id | store_id | store_role | state | install_path
> |
> +-------------+----------+------------+-----------+--------------------------------------------------------+
> | 2 | 2 | Image | Destroyed |
> snapshots/2/3/d57dc76a-fa1d-474c-9da6-463d69932917.vhd |
> | 2 | 1 | ImageCache | Ready | snapshots/2/3
> |
> | 2 | 1 | ImageCache | Allocated |
> snapshots/2/3/d57dc76a-fa1d-474c-9da6-463d69932917.vhd |
> | 3 | 1 | Primary | Destroyed |
> 9ff92074-7876-40c7-baf4-6b354907220a |
> | 3 | 2 | Image | Destroyed |
> snapshots/2/3/d57dc76a-fa1d-474c-9da6-463d69932917.vhd |
> +-------------+----------+------------+-----------+--------------------------------------------------------+
> 5 rows in set (0.00 sec)
> Job Trace:
> ---------------------
> 2013-12-19 17:34:36,793 DEBUG [c.c.a.ApiServlet]
> (catalina-exec-14:ctx-a5653e88) ===START=== 10.146.0.11 -- GET
> command=deleteSnapshot&id=2bf17c10-57e7-4a49-a3a9-d5dae78e9b06&response=json&sessionkey=zZJPWieCtGbQWU4g65spOrFYwCA%3D&_=1387435473150
> 2013-12-19 17:34:36,850 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (catalina-exec-14:ctx-a5653e88 ctx-3d52ff98) submit async job-36, details:
> AsyncJobVO {id:36, userId: 2, accountId: 2, instanceType: Snapshot,
> instanceId: 3, cmd:
> org.apache.cloudstack.api.command.user.snapshot.DeleteSnapshotCmd, cmdInfo:
> {"response":"json","id":"2bf17c10-57e7-4a49-a3a9-d5dae78e9b06","sessionkey":"zZJPWieCtGbQWU4g65spOrFYwCA\u003d","cmdEventType":"SNAPSHOT.DELETE","ctxUserId":"2","httpmethod":"GET","_":"1387435473150","ctxAccountId":"2","ctxStartEventId":"103"},
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
> null, initMsid: 6915098673184, completeMsid: null, lastUpdated: null,
> lastPolled: null, created: null}
> 2013-12-19 17:34:36,853 DEBUG [c.c.a.ApiServlet]
> (catalina-exec-14:ctx-a5653e88 ctx-3d52ff98) ===END=== 10.146.0.11 -- GET
> command=deleteSnapshot&id=2bf17c10-57e7-4a49-a3a9-d5dae78e9b06&response=json&sessionkey=zZJPWieCtGbQWU4g65spOrFYwCA%3D&_=1387435473150
> 2013-12-19 17:34:36,855 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (Job-Executor-11:ctx-20e35c49) Add job-36 into job monitoring
> 2013-12-19 17:34:36,855 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Job-Executor-11:ctx-20e35c49) Executing AsyncJobVO {id:36, userId: 2,
> accountId: 2, instanceType: Snapshot, instanceId: 3, cmd:
> org.apache.cloudstack.api.command.user.snapshot.DeleteSnapshotCmd, cmdInfo:
> {"response":"json","id":"2bf17c10-57e7-4a49-a3a9-d5dae78e9b06","sessionkey":"zZJPWieCtGbQWU4g65spOrFYwCA\u003d","cmdEventType":"SNAPSHOT.DELETE","ctxUserId":"2","httpmethod":"GET","_":"1387435473150","ctxAccountId":"2","ctxStartEventId":"103"},
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
> null, initMsid: 6915098673184, completeMsid: null, lastUpdated: null,
> lastPolled: null, created: null}
> 2013-12-19 17:34:36,901 DEBUG [o.a.c.s.s.XenserverSnapshotStrategy]
> (Job-Executor-11:ctx-20e35c49 ctx-3d52ff98) delete snapshot chain for
> snapshot: 3
> 2013-12-19 17:34:36,904 DEBUG [o.a.c.s.s.XenserverSnapshotStrategy]
> (Job-Executor-11:ctx-20e35c49 ctx-3d52ff98) Snapshot: 3 doesn't have
> children, so it's ok to delete it and its parents
> 2013-12-19 17:34:36,927 DEBUG [o.a.c.s.s.XenserverSnapshotStrategy]
> (Job-Executor-11:ctx-20e35c49 ctx-3d52ff98) for empty delta snapshot, only
> mark it as destroyed in db
> 2013-12-19 17:34:36,945 DEBUG [o.a.c.s.s.XenserverSnapshotStrategy]
> (Job-Executor-11:ctx-20e35c49 ctx-3d52ff98) Snapshot: 2 doesn't have
> children, so it's ok to delete it and its parents
> 2013-12-19 17:34:37,045 DEBUG [c.c.a.t.Request] (Job-Executor-11:ctx-20e35c49
> ctx-3d52ff98) Seq 3-599064621: Sending { Cmd , MgmtId: 6915098673184, via:
> 3(s-2-VM), Ver: v1, Flags: 100011,
> [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/3/d57dc76a-fa1d-474c-9da6-463d69932917.vhd","volume":{"uuid":"dba16dff-69c9-4047-9445-a3e03b797a2b","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"cc393eb0-2b30-3bd7-a5cc-ab3f9d7a228a","id":1,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/pavan/primaryXSS3New","port":2049,"url":"NetworkFilesystem://10.147.28.7//export/home/pavan/primaryXSS3New/?ROLE=Primary&STOREUUID=cc393eb0-2b30-3bd7-a5cc-ab3f9d7a228a"}},"name":"ROOT-3","size":21474836480,"path":"8519a4c7-b660-4bb0-a275-86f23141f654","volumeId":3,"vmName":"i-2-3-VM","accountId":2,"format":"VHD","id":3,"deviceId":0,"hypervisorType":"XenServer"},"dataStore":{"com.cloud.agent.api.to.S3TO":{"id":2,"uuid":"06f333f1-e100-465b-be12-5c4bad1ffc2a","endPoint":"10.147.29.56:8080","bucketName":"pavanxsbucketnew","httpsFlag":false,"created":"Dec
> 18, 2013 9:50:13
> PM","enableRRS":false,"maxSingleUploadSizeInBytes":5368709120}},"vmName":"i-2-3-VM","name":"CosBeforeMig_ROOT-3_20131218173917","hypervisorType":"XenServer","id":2,"quiescevm":false}},"wait":0}}]
> }
> 2013-12-19 17:34:37,308 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-14:null) SeqA 2-9723: Processing Seq 2-9723: { Cmd ,
> MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":1,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
> 2013-12-19 17:34:37,316 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-14:null) SeqA 2-9723: Sending Seq 2-9723: { Ans: ,
> MgmtId: 6915098673184, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2013-12-19 17:34:37,411 DEBUG [c.c.a.t.Request] (AgentManager-Handler-1:null)
> Seq 3-599064621: Processing: { Ans: , MgmtId: 6915098673184, via: 3, Ver:
> v1, Flags: 10,
> [{"com.cloud.agent.api.Answer":{"result":true,"details":"Deleted snapshot %s
> from bucket pavanxsbucketnew.","wait":0}}] }
> 2013-12-19 17:34:37,412 DEBUG [c.c.a.t.Request] (Job-Executor-11:ctx-20e35c49
> ctx-3d52ff98) Seq 3-599064621: Received: { Ans: , MgmtId: 6915098673184,
> via: 3, Ver: v1, Flags: 10, { Answer } }
> 2013-12-19 17:34:38,738 DEBUG [o.a.c.s.s.XenserverSnapshotStrategy]
> (Job-Executor-11:ctx-20e35c49 ctx-3d52ff98) delete snapshot failed:
> com.cloud.utils.exception.CloudRuntimeException: DB Exception on:
> com.mysql.jdbc.JDBC4PreparedStatement@74248339: SELECT snapshot_store_ref.id,
> snapshot_store_ref.store_id, snapshot_store_ref.store_role,
> snapshot_store_ref.snapshot_id, snapshot_store_ref.created,
> snapshot_store_ref.last_updated, snapshot_store_ref.size,
> snapshot_store_ref.physical_size, snapshot_store_ref.parent_snapshot_id,
> snapshot_store_ref.job_id, snapshot_store_ref.install_path,
> snapshot_store_ref.update_count, snapshot_store_ref.updated,
> snapshot_store_ref.state, snapshot_store_ref.ref_cnt,
> snapshot_store_ref.volume_id FROM snapshot_store_ref WHERE
> snapshot_store_ref.snapshot_id = 2 AND snapshot_store_ref.store_role =
> 'ImageCache'
> at
> com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:421)
> at
> com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:356)
> at com.cloud.utils.db.GenericDaoBase.search(GenericDaoBase.java:340)
> at com.cloud.utils.db.GenericDaoBase.search(GenericDaoBase.java:1243)
> at
> org.apache.cloudstack.storage.image.db.SnapshotDataStoreDaoImpl.listOnCache(SnapshotDataStoreDaoImpl.java:296)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:616)
> at
> org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
> at
> com.cloud.utils.db.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:33)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
> at
> org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
> at
> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> at $Proxy156.listOnCache(Unknown Source)
> at
> org.apache.cloudstack.storage.snapshot.SnapshotDataFactoryImpl.listSnapshotOnCache(SnapshotDataFactoryImpl.java:84)
> at
> org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.deleteSnapshotChain(XenserverSnapshotStrategy.java:172)
> at
> org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.deleteSnapshot(XenserverSnapshotStrategy.java:229)
> at
> com.cloud.storage.snapshot.SnapshotManagerImpl.deleteSnapshot(SnapshotManagerImpl.java:428)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:616)
> at
> org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
> at
> com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
> at
> org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
> at
> org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
> at
> org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> at $Proxy161.deleteSnapshot(Unknown Source)
> at
> org.apache.cloudstack.api.command.user.snapshot.DeleteSnapshotCmd.execute(DeleteSnapshotCmd.java:97)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
> at
> com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
> at
> com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at
> com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
> at
> org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:521)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
> at
> org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at
> org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
> 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.MySQLDataException:
> '18446744073709551615' in column '15' is outside valid range for the datatype
> BIGINT.
> 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:1026)
> at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:988)
> at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:974)
> at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:919)
> at
> com.mysql.jdbc.ResultSetImpl.throwRangeException(ResultSetImpl.java:7870)
> at
> com.mysql.jdbc.ResultSetImpl.parseLongAsDouble(ResultSetImpl.java:7095)
> at com.mysql.jdbc.ResultSetImpl.getLong(ResultSetImpl.java:2981)
> at com.mysql.jdbc.ResultSetImpl.getLong(ResultSetImpl.java:2946)
> at
> org.apache.commons.dbcp.DelegatingResultSet.getLong(DelegatingResultSet.java:228)
> at
> org.apache.commons.dbcp.DelegatingResultSet.getLong(DelegatingResultSet.java:228)
> at com.cloud.utils.db.GenericDaoBase.setField(GenericDaoBase.java:541)
> at
> com.cloud.utils.db.GenericDaoBase.setField(GenericDaoBase.java:1702)
> at
> com.cloud.utils.db.GenericDaoBase.toEntityBean(GenericDaoBase.java:1582)
> at
> com.cloud.utils.db.GenericDaoBase.toEntityBean(GenericDaoBase.java:1543)
> at
> com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:417)
> ... 54 more
> 2013-12-19 17:34:38,807 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Job-Executor-11:ctx-20e35c49 ctx-3d52ff98) Complete async job-36, jobStatus:
> SUCCEEDED, resultCode: 0, result:
> org.apache.cloudstack.api.response.SuccessResponse/null/{"success":true}
> 2013-12-19 17:34:38,828 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Job-Executor-11:ctx-20e35c49) Done executing
> org.apache.cloudstack.api.command.user.snapshot.DeleteSnapshotCmd for job-36
> 2013-12-19 17:34:38,837 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (Job-Executor-11:ctx-20e35c49) Remove job-36 from job monitoring
--
This message was sent by Atlassian JIRA
(v6.1.4#6159)
