You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Bjoern Teipel (JIRA)" <ji...@apache.org> on 2013/10/25 10:22:30 UTC
[jira] [Closed] (CLOUDSTACK-4878) KVM snapshots are failing at
CentOS 6.4
[ https://issues.apache.org/jira/browse/CLOUDSTACK-4878?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Bjoern Teipel closed CLOUDSTACK-4878.
-------------------------------------
Resolution: Invalid
Found the issue. The JDBC error bothered me that much that I looked in my DB config and then I knew what happened. The wait_timeout is set to 30 seconds, so during the write of the qcow snapshot file to the secondary storage, the mysql session was terminated. After the copy was done, cloudstack tried to select/update tables on a non existing session anymore.
I removed now this parameter and wait_timeout is set to 8h, the standard value. So at least all backups should work within this period. Probably the db code should be changed a little bit to check for a connection before writing to the DB. Or better it should just close the connection and let the copy finish and then reopen a new connection. On large volumes the copy could take significant amount of time
> KVM snapshots are failing at CentOS 6.4
> ---------------------------------------
>
> Key: CLOUDSTACK-4878
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4878
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: KVM
> Affects Versions: 4.2.0, 4.2.1
> Environment: Centos 6.4 x64 recent patches
> primary local or NFS and seconday storage on NFS
> Reporter: Bjoern Teipel
> Priority: Critical
>
> 2013-10-15 21:45:59,415 DEBUG [agent.transport.Request] (AgentManager-Handler-8:null) Seq 1-621806172: Processing: { Ans: , MgmtId: 110493122496, via: 1, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/4/5/57ef69cd-1bc8-4e47-94c1-84834befaaad","id":0}},"result":true,"wait":0}}] }
> 2013-10-15 21:45:59,415 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-8:null) Seq 1-621806172: No more commands found
> 2013-10-15 21:45:59,415 DEBUG [agent.transport.Request] (Job-Executor-2:job-40 = [ 81b303ad-acb2-483f-9571-d09064d1d086 ]) Seq 1-621806172: Received: { Ans: , MgmtId: 110493122496, via: 1, Ver: v1, Flags: 110, { CopyCmdAnswer } }
> 2013-10-15 21:45:59,417 DEBUG [storage.snapshot.SnapshotServiceImpl] (Job-Executor-2:job-40 = [ 81b303ad-acb2-483f-9571-d09064d1d086 ]) Failed to update snapshot state
> com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@79fd21d8: 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 = 1 AND snapshot_store_ref.store_id = 1 AND snapshot_store_ref.store_role = 'Image' ORDER BY RAND() LIMIT 1
> at com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:414)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:349)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at com.cloud.utils.db.GenericDaoBase.findOneIncludingRemovedBy(GenericDaoBase.java:859)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at com.cloud.utils.db.GenericDaoBase.findOneBy(GenericDaoBase.java:870)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.storage.image.db.SnapshotDataStoreDaoImpl.findByStoreSnapshot(SnapshotDataStoreDaoImpl.java:178)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.storage.snapshot.SnapshotObject.processEvent(SnapshotObject.java:253)
> at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.copySnapshotAsyncCallback(SnapshotServiceImpl.java:315)
> 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.apache.cloudstack.framework.async.AsyncCallbackDispatcher.dispatch(AsyncCallbackDispatcher.java:142)
> at org.apache.cloudstack.framework.async.InplaceAsyncCallbackDriver.performCompletionCallback(InplaceAsyncCallbackDriver.java:26)
> at org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.complete(AsyncCallbackDispatcher.java:120)
> at org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:423)
> at org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:55)
> at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:265)
> at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:138)
> at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:264)
> at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1013)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1307)
> at com.cloud.storage.VolumeManagerImpl.takeSnapshot(VolumeManagerImpl.java:2719)
> at org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170)
> 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: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.CommunicationsException: Communications link failure
> The last packet successfully received from the server was 42,750 milliseconds ago. The last packet sent successfully to the server was 0 milliseconds ago.
> at sun.reflect.GeneratedConstructorAccessor174.newInstance(Unknown Source)
> 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.SQLError.createCommunicationsException(SQLError.java:1117)
> at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3567)
> at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3456)
> at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3997)
> 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.executeQuery(PreparedStatement.java:2318)
> at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
> at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
> at com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:408)
> ... 60 more
> Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
> ... 75 more
> 2013-10-15 21:45:59,419 DEBUG [storage.snapshot.SnapshotManagerImpl] (Job-Executor-2:job-40 = [ 81b303ad-acb2-483f-9571-d09064d1d086 ]) Failed to create snapshot
> com.cloud.utils.exception.CloudRuntimeException: com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@79fd21d8: 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 = 1 AND snapshot_store_ref.store_id = 1 AND snapshot_store_ref.store_role = 'Image' ORDER BY RAND() LIMIT 1
> at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:280)
> at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:138)
> at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:264)
> at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1013)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1307)
> at com.cloud.storage.VolumeManagerImpl.takeSnapshot(VolumeManagerImpl.java:2719)
> at org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170)
> 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:1146)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:679)
> 2013-10-15 21:45:59,420 WARN [db.Transaction.Transaction] (Job-Executor-2:job-40 = [ 81b303ad-acb2-483f-9571-d09064d1d086 ]) Unable to set auto commit:
> com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure
> The last packet successfully received from the server was 42,754 milliseconds ago. The last packet sent successfully to the server was 4 milliseconds ago.
> at sun.reflect.GeneratedConstructorAccessor174.newInstance(Unknown Source)
> 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.SQLError.createCommunicationsException(SQLError.java:1117)
> at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3829)
> at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2449)
> at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2629)
> at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2713)
> at com.mysql.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:5060)
> at org.apache.commons.dbcp.DelegatingConnection.setAutoCommit(DelegatingConnection.java:371)
> at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.setAutoCommit(PoolingDataSource.java:328)
> at com.cloud.utils.db.Transaction.start(Transaction.java:420)
> at com.cloud.resourcelimit.ResourceLimitManagerImpl.updateResourceCountForAccount(ResourceLimitManagerImpl.java:722)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at com.cloud.resourcelimit.ResourceLimitManagerImpl.decrementResourceCount(ResourceLimitManagerImpl.java:253)
> at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1034)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1307)
> at com.cloud.storage.VolumeManagerImpl.takeSnapshot(VolumeManagerImpl.java:2719)
> at org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170)
> 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:1146)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:679)
> Caused by: java.net.SocketException: Broken pipe
> at java.net.SocketOutputStream.socketWrite0(Native Method)
> ... 36 more
> 2013-10-15 21:45:59,422 ERROR [cloud.resourcelimit.ResourceLimitManagerImpl] (Job-Executor-2:job-40 = [ 81b303ad-acb2-483f-9571-d09064d1d086 ]) Failed to update resource count for account id=4
> 2013-10-15 21:45:59,422 DEBUG [db.Transaction.Transaction] (Job-Executor-2:job-40 = [ 81b303ad-acb2-483f-9571-d09064d1d086 ]) Rolling back the transaction: Time = 2 Name = -AsyncJobManagerImpl$1.run:494-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:898-Transaction.removeUpTo:841-Transaction.close:665-TransactionContextBuilder.interceptComplete:56-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:131-ResourceLimitManagerImpl.decrementResourceCount:253-SnapshotManagerImpl.takeSnapshot:1034-ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept:125-VolumeServiceImpl.takeSnapshot:1307-VolumeManagerImpl.takeSnapshot:2719-CreateSnapshotCmd.execute:170-ApiDispatcher.dispatch:158
> 2013-10-15 21:45:59,423 WARN [db.Transaction.Transaction] (Job-Executor-2:job-40 = [ 81b303ad-acb2-483f-9571-d09064d1d086 ]) Unable to rollback
> com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Communications link failure during rollback(). Transaction resolution unknown.
> at sun.reflect.GeneratedConstructorAccessor188.newInstance(Unknown Source)
> 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:1014)
> 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.ConnectionImpl.rollback(ConnectionImpl.java:4793)
> at org.apache.commons.dbcp.DelegatingConnection.rollback(DelegatingConnection.java:368)
> at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.rollback(PoolingDataSource.java:323)
> at com.cloud.utils.db.Transaction.rollbackTransaction(Transaction.java:860)
> at com.cloud.utils.db.Transaction.rollback(Transaction.java:898)
> at com.cloud.utils.db.Transaction.removeUpTo(Transaction.java:841)
> at com.cloud.utils.db.Transaction.close(Transaction.java:665)
> at com.cloud.utils.db.TransactionContextBuilder.interceptComplete(TransactionContextBuilder.java:56)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:131)
> at com.cloud.resourcelimit.ResourceLimitManagerImpl.decrementResourceCount(ResourceLimitManagerImpl.java:253)
> at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1034)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1307)
> at com.cloud.storage.VolumeManagerImpl.takeSnapshot(VolumeManagerImpl.java:2719)
> at org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170)
> 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:1146)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:679)
> 2013-10-15 21:45:59,424 WARN [apache.cloudstack.alerts] (Job-Executor-2:job-40 = [ 81b303ad-acb2-483f-9571-d09064d1d086 ]) alertType:: 22 // dataCenterId:: 0 // podId:: 0 // clusterId:: null // message:: Failed to decrement resource count of type secondary_storage for account id=4
> 2013-10-15 21:45:59,427 ERROR [cloud.alert.AlertManagerImpl] (Job-Executor-2:job-40 = [ 81b303ad-acb2-483f-9571-d09064d1d086 ]) Problem sending email alert
> com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@18608772: SELECT alert.id, alert.type, alert.cluster_id, alert.pod_id, alert.data_center_id, alert.subject, alert.sent_count, alert.created, alert.last_sent, alert.resolved, alert.uuid, alert.archived FROM alert WHERE alert.type = 22 AND alert.data_center_id = 0 AND alert.archived = 0 AND alert.pod_id = 0 ORDER BY alert.created DESC LIMIT 0, 1
> at com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:414)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:349)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at com.cloud.utils.db.GenericDaoBase.listIncludingRemovedBy(GenericDaoBase.java:901)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at com.cloud.utils.db.GenericDaoBase.listBy(GenericDaoBase.java:878)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at com.cloud.alert.dao.AlertDaoImpl.getLastAlert(AlertDaoImpl.java:66)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at com.cloud.alert.AlertManagerImpl$EmailAlert.sendAlert(AlertManagerImpl.java:833)
> at com.cloud.alert.AlertManagerImpl.sendAlert(AlertManagerImpl.java:261)
> at com.cloud.resourcelimit.ResourceLimitManagerImpl.decrementResourceCount(ResourceLimitManagerImpl.java:254)
> at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1034)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1307)
> at com.cloud.storage.VolumeManagerImpl.takeSnapshot(VolumeManagerImpl.java:2719)
> at org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170)
> 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: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.CommunicationsException: Communications link failure
> The last packet successfully received from the server was 42,760 milliseconds ago. The last packet sent successfully to the server was 10 milliseconds ago.
> at sun.reflect.GeneratedConstructorAccessor174.newInstance(Unknown Source)
> 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.SQLError.createCommunicationsException(SQLError.java:1117)
> at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3829)
> at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2449)
> 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.executeQuery(PreparedStatement.java:2318)
> at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
> at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
> at com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(GenericDaoBase.java:408)
> ... 49 more
> Caused by: java.net.SocketException: Broken pipe
> at java.net.SocketOutputStream.socketWrite0(Native Method)
> ... 62 more
> 2013-10-15 21:45:59,430 DEBUG [storage.volume.VolumeServiceImpl] (Job-Executor-2:job-40 = [ 81b303ad-acb2-483f-9571-d09064d1d086 ]) Take snapshot: 5 failed
> com.cloud.utils.exception.CloudRuntimeException: Failed to create snapshot
> at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1040)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSnapshot(VolumeServiceImpl.java:1307)
> at com.cloud.storage.VolumeManagerImpl.takeSnapshot(VolumeManagerImpl.java:2719)
> at org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170)
> 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:1146)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:679)
> Caused by: com.cloud.utils.exception.CloudRuntimeException: com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@79fd21d8: 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 = 1 AND snapshot_store_ref.store_id = 1 AND snapshot_store_ref.store_role = 'Image' ORDER BY RAND() LIMIT 1
> at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:280)
> at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:138)
> at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:264)
> at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1013)
> ... 16 more
> 2013-10-15 21:45:59,437 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-2:job-40 = [ 81b303ad-acb2-483f-9571-d09064d1d086 ]) Complete async job-40 = [ 81b303ad-acb2-483f-9571-d09064d1d086 ], jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: Failed to create snapshot due to an internal error creating snapshot for volume 5
> SQL Content :
> mysql> 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 = 1 AND snapshot_store_ref.store_id = 1 AND snapshot_store_ref.store_role = 'Image' ORDER BY RAND() LIMIT 1\G
> *************************** 1. row ***************************
> id: 2
> store_id: 1
> store_role: Image
> snapshot_id: 1
> created: 2013-10-16 04:45:16
> last_updated: NULL
> size: 0
> physical_size: 0
> parent_snapshot_id: 0
> job_id: NULL
> install_path: snapshots/4/5
> update_count: 1
> updated: 2013-10-16 04:45:16
> state: Creating
> ref_cnt: 0
> volume_id: 5
> mysql> SELECT alert.id, alert.type, alert.cluster_id, alert.pod_id, alert.data_center_id, alert.subject, alert.sent_count, alert.created, alert.last_sent, alert.resolved, alert.uuid, alert.archived FROM alert WHERE alert.type = 22 AND alert.data_center_id = 0 AND alert.archived = 0 AND alert.pod_id = 0 ORDER BY alert.created DESC LIMIT 0, 1\G
> Empty set (0.00 sec)
> Actually I can see a qcow2 snapshot file has been created. Not sure why command fails
> qemu-img info d1595fc0-8220-4d4f-99b9-d02759262bce
> image: d1595fc0-8220-4d4f-99b9-d02759262bce
> file format: qcow2
> virtual size: 2.0G (2097152000 bytes)
> disk size: 122M
> cluster_size: 65536
> backing file: /mnt/46ae9df0-3e29-3535-9acc-506dafa3f52c/d07390a2-edf9-4c6c-839c-2e03a4d3cd5c
--
This message was sent by Atlassian JIRA
(v6.1#6144)