If you go to the Global Settings tab in the GUI and search for “wait”, there
are several possible timeouts that may apply.
The backup.snapshot.wait Global Setting seems like the one that probably
applies here (per what Pierre-Luc was noting).
On 2/8/18, 4:15 PM, "Pierre-Luc Dion" <pdion...@apache.org> wrote:
I think there is a timout global settings you could change so the copy task
will take longer before it timeout and fail in cloudstack. This will not
improve your performance but might reduce failure.
On updating the database content, it could work, but only if the vhd
successfully copy, and mappings remain valid.
I hope this can help...
Le 6 févr. 2018 13 h 28, "anillakieni" <anilkumar459.lakin...@gmail.com> a
écrit :
Dear All,
Is somebody available here to assist me on fixing my issue.
Thanks,
Anil.
On Tue, Feb 6, 2018 at 9:00 PM, anillakieni <anilkumar459.lakin...@gmail.com
> wrote:
> Hi All,
>
> I'm facing issue when copying larger size volumes. i.e., Secondary
> Storage to Primary Storage (I mean attaching DATA volume to VM), after
> certain time around 37670 seconds.
>
> Version of:
> - CloudStack is 4.5.0
> - XenServer 6.5.0
> - MySQL 5.1.73
>
>
> The error and log is provided below, Could someone please assist me here
> which steps i have to take to fix this issue. Also, can we have a chance
to
> update the failed status to success through database tables because i have
> to upload the whole disk again to secondary storage and then later attach
> it to VM, which is consuming more time. My environment has very slow
> network transfers (I have only 1 Gig switch). Please let me know if we can
> tweak the DB to update the status of the disk or do we have any settings
to
> be changed to accept more time (wait time) for updating the status.
> "
>
> 2018-02-06 03:20:42,385 DEBUG [c.c.a.t.Request] (Work-Job-Executor-31:ctx-
c1c78a5a
> job-106186/job-106187 ctx-ea1ef3e6) (logid:c59b2359) Seq
> 38-367887794560851961: Received: { Ans: , MgmtId: 47019105324719, via:
38,
> Ver: v1, Flags: 110, { CopyCmdAnswer } }
> 2018-02-06 03:20:42,389 DEBUG [o.a.c.s.v.VolumeObject]
> (Work-Job-Executor-31:ctx-c1c78a5a job-106186/job-106187 ctx-ea1ef3e6)
> (logid:c59b2359) *Failed to update state*
> *com.cloud.utils.exception.CloudRuntimeException: DB Exception on:
> com.mysql.jdbc.JDBC4PreparedStatement@54bd3a25: SELECT volume_store_ref.id
> <http://volume_store_ref.id>, 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.download_url, volume_store_ref.download_url_created,
> volume_store_ref.destroyed, volume_store_ref.update_count,
> volume_store_ref.updated, volume_store_ref.state, volume_store_ref.ref_cnt
> FROM volume_store_ref WHERE volume_store_ref.store_id = 1 AND
> volume_store_ref.volume_id = 1178 AND volume_store_ref.destroyed = 0
> ORDER BY RAND() LIMIT 1*
> at com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(
> GenericDaoBase.java:425)
> at com.cloud.utils.db.GenericDaoBase.searchIncludingRemoved(
> GenericDaoBase.java:361)
> at com.cloud.utils.db.GenericDaoBase.findOneIncludingRemovedBy(
> GenericDaoBase.java:889)
> at com.cloud.utils.db.GenericDaoBase.findOneBy(
> GenericDaoBase.java:900)
> at org.apache.cloudstack.storage.image.db.VolumeDataStoreDaoImpl.
> findByStoreVolume(VolumeDataStoreDaoImpl.java:209)
> at sun.reflect.GeneratedMethodAccessor306.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(
> DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> 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:34)
> 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 com.sun.proxy.$Proxy173.findByStoreVolume(Unknown Source)
> at org.apache.cloudstack.storage.datastore.
> ObjectInDataStoreManagerImpl.findObject(ObjectInDataStoreManagerImpl.
> java:353)
> at org.apache.cloudstack.storage.datastore.
> ObjectInDataStoreManagerImpl.findObject(ObjectInDataStoreManagerImpl.
> java:338)
> at org.apache.cloudstack.storage.datastore.
> ObjectInDataStoreManagerImpl.update(ObjectInDataStoreManagerImpl.java:289)
> at org.apache.cloudstack.storage.volume.VolumeObject.
> processEvent(VolumeObject.java:294)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.
> copyVolumeFromImageToPrimaryCallback(VolumeServiceImpl.java:901)
> 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:606)
> at org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.
> dispatch(AsyncCallbackDispatcher.java:148)
> at org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.
> dispatch(AsyncCallbackDispatcher.java:148)
> at org.apache.cloudstack.framework.async.
> InplaceAsyncCallbackDriver.performCompletionCallback(
> InplaceAsyncCallbackDriver.java:25)
> at org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.
> complete(AsyncCallbackDispatcher.java:126)
> at org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.
> copyAsync(AncientDataMotionStrategy.java:463)
> at org.apache.cloudstack.storage.motion.DataMotionServiceImpl.
> copyAsync(DataMotionServiceImpl.java:68)
> at org.apache.cloudstack.storage.motion.DataMotionServiceImpl.
> copyAsync(DataMotionServiceImpl.java:73)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.
> copyVolumeFromImageToPrimary(VolumeServiceImpl.java:870)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.
> copyVolume(VolumeServiceImpl.java:968)
> at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.
> copyVolumeFromSecToPrimary(VolumeOrchestrator.java:430)
> at org.apache.cloudstack.engine.orchestration.
> VolumeOrchestrator.copyVolume(VolumeOrchestrator.java:764)
> at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.
> createVolumeOnPrimaryStorage(VolumeOrchestrator.java:784)
> at com.cloud.storage.VolumeApiServiceImpl.
> orchestrateAttachVolumeToVM(VolumeApiServiceImpl.java:1211)
> at com.cloud.storage.VolumeApiServiceImpl.
> orchestrateAttachVolumeToVM(VolumeApiServiceImpl.java:2732)
> 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:606)
> at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(
> VmWorkJobHandlerProxy.java:107)
> at com.cloud.storage.VolumeApiServiceImpl.handleVmWorkJob(
> VolumeApiServiceImpl.java:2771)
> 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:606)
> 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 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 com.sun.proxy.$Proxy186.handleVmWorkJob(Unknown Source)
> at com.cloud.vm.VmWorkJobDispatcher.runJob(
> VmWorkJobDispatcher.java:103)
> at org.apache.cloudstack.framework.jobs.impl.
> AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:547)
> 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 org.apache.cloudstack.framework.jobs.impl.
> AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:498)
> at java.util.concurrent.Executors$RunnableAdapter.
> call(Executors.java:471)
> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(
> ThreadPoolExecutor.java:1145)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(
> ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:744)
> *Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The
> last packet successfully received from the server was 37,706,960
> milliseconds ago. The last packet sent successfully to the server was
> 37,706,961 milliseconds ago. is longer than the server configured value of
> 'wait_timeout'. You should consider either expiring and/or testing
> connection validity before use in your application, increasing the server
> configured values for client timeouts, or using the Connector/J connection
> property 'autoReconnect=true' to avoid this problem.*
> 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:526)
> at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
> at com.mysql.jdbc.SQLError.createCommunicationsException(
> SQLError.java:1116)
> at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3352)
> at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1971)
> at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2151)
> at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2625)
> at com.mysql.jdbc.PreparedStatement.executeInternal(
> PreparedStatement.java:2119)
> at com.mysql.jdbc.PreparedStatement.executeQuery(
> PreparedStatement.java:2283)
> 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:419)
> ... 68 more
> Caused by: java.net.SocketException: Broken pipe
> ... 82 more
> 2018-02-06 03:20:42,390 DEBUG [c.c.a.m.AgentAttache]
> (DirectAgent-212:ctx-418e3b03) (logid:c59b2359) Seq 38-367887794560855816:
> Sending now. is current sequence.
> 2018-02-06 03:20:42,391 DEBUG [o.a.c.e.o.VolumeOrchestrator]
> (Work-Job-Executor-31:ctx-c1c78a5a job-106186/job-106187 ctx-ea1ef3e6)
> (logid:c59b2359) copy volume failed: com.cloud.utils.exception.
CloudRuntimeException:
> Failed to update state:com.cloud.utils.exception.CloudRuntimeException:
> DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@54bd3a25: SELECT
> volume_store_ref.id, 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.download_url, volume_store_ref.download_url_created,
> volume_store_ref.destroyed, volume_store_ref.update_count,
> volume_store_ref.updated, volume_store_ref.state, volume_store_ref.ref_cnt
> FROM volume_store_ref WHERE volume_store_ref.store_id = 1 AND
> volume_store_ref.volume_id = 1178 AND volume_store_ref.destroyed = 0
> ORDER BY RAND() LIMIT 1
> 2018-02-06 03:20:42,391 ERROR [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-31:ctx-c1c78a5a job-106186/job-106187 ctx-ea1ef3e6)
> (logid:c59b2359) Invocation exception, caused by:
com.cloud.utils.exception.CloudRuntimeException:
> copy volume failed: com.cloud.utils.exception.CloudRuntimeException:
> Failed to update state:com.cloud.utils.exception.CloudRuntimeException:
> DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@54bd3a25: SELECT
> volume_store_ref.id, 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.download_url, volume_store_ref.download_url_created,
> volume_store_ref.destroyed, volume_store_ref.update_count,
> volume_store_ref.updated, volume_store_ref.state, volume_store_ref.ref_cnt
> FROM volume_store_ref WHERE volume_store_ref.store_id = 1 AND
> volume_store_ref.volume_id = 1178 AND volume_store_ref.destroyed = 0
> ORDER BY RAND() LIMIT 1
> 2018-02-06 03:20:42,392 INFO [c.c.v.VmWorkJobHandlerProxy]
> (Work-Job-Executor-31:ctx-c1c78a5a job-106186/job-106187 ctx-ea1ef3e6)
> (logid:c59b2359) Rethrow exception com.cloud.utils.exception.
CloudRuntimeException:
> copy volume failed: com.cloud.utils.exception.CloudRuntimeException:
> Failed to update state:com.cloud.utils.exception.CloudRuntimeException:
> DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@54bd3a25: SELECT
> volume_store_ref.id, 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.download_url, volume_store_ref.download_url_created,
> volume_store_ref.destroyed, volume_store_ref.update_count,
> volume_store_ref.updated, volume_store_ref.state, volume_store_ref.ref_cnt
> FROM volume_store_ref WHERE volume_store_ref.store_id = 1 AND
> volume_store_ref.volume_id = 1178 AND volume_store_ref.destroyed = 0
> ORDER BY RAND() LIMIT 1
> 2018-02-06 03:20:42,392 DEBUG [c.c.v.VmWorkJobDispatcher]
> (Work-Job-Executor-31:ctx-c1c78a5a job-106186/job-106187)
> (logid:c59b2359) Done with run of VM work job: com.cloud.vm.
VmWorkAttachVolume
> for VM 877, job origin: 106186
>
> "
>
>
> If you require more info please let me know to provide it. Looking forward
> for the help. Much appreciation.
>
>
> Thanks,
> Anil.
>
