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.
>
