cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Nicolas Bouige <n.bou...@dimsi.fr>
Subject DB Communication Link Failure
Date Wed, 13 Jun 2018 14:04:17 GMT
Hello All,

Tonight du to a network issue our management cloudstack server and MariaDb server have been
shutdowned and restarted this morning.

Unfortunately, we  get some issues of < connectivity > between the mgmt server and db
server.
Both service (cloudstack-management/mysqld) are up and running without any errors.
Db server are available from mgmt server (telnet OK, mysql -h dbserver...ok, firewall policies
are good from both sides)

However, when we want to login to the GUI cloudstack an execption is raised in mgmt-server.log
:

2018-06-13 15:28:41,019 DEBUG [c.c.u.d.T.Transaction] (qtp1796488937-13:ctx-88e441c4) (logid:f9e9b399)
Rolling back the transaction: Time = 97 Name =  qtp1796488937-13; called by -TransactionLegacy.rollback:889-TransactionLegacy.removeUpTo:832-TransactionLegacy.close:656-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:174-ExposeInvocationInterceptor.invoke:92-ReflectiveMethodInvocation.proceed:185-JdkDynamicAopProxy.invoke:212-$Proxy121.persist:-1-ActionEventUtils.persistActionEvent:186-ActionEventUtils.onActionEvent:98-AccountManagerImpl.logoutUser:2096
2018-06-13 15:28:41,020 WARN  [c.c.u.d.T.Transaction] (qtp1796488937-13:ctx-88e441c4) (logid:f9e9b399)
Unable to rollback
com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: Communications link
failure during rollback(). Transaction resolution unknown.
        at sun.reflect.GeneratedConstructorAccessor98.newInstance(Unknown Source)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        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:1015)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:989)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:975)
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:920)
        at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:5067)
        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.TransactionLegacy.rollbackTransaction(TransactionLegacy.java:851)
        at com.cloud.utils.db.TransactionLegacy.rollback(TransactionLegacy.java:889)
        at com.cloud.utils.db.TransactionLegacy.removeUpTo(TransactionLegacy.java:832)
        at com.cloud.utils.db.TransactionLegacy.close(TransactionLegacy.java:656)
        at com.cloud.utils.db.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:36)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
        at com.sun.proxy.$Proxy121.persist(Unknown Source)
        at com.cloud.event.ActionEventUtils.persistActionEvent(ActionEventUtils.java:186)
        at com.cloud.event.ActionEventUtils.onActionEvent(ActionEventUtils.java:98)
        at com.cloud.user.AccountManagerImpl.logoutUser(AccountManagerImpl.java:2096)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
        at com.sun.proxy.$Proxy40.logoutUser(Unknown Source)
        at com.cloud.api.ApiServer.logoutUser(ApiServer.java:1104)
        at com.cloud.api.ApiServlet.processRequestInContext(ApiServlet.java:234)
        at com.cloud.api.ApiServlet$1.run(ApiServlet.java:130)
        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.ApiServlet.processRequest(ApiServlet.java:127)
        at com.cloud.api.ApiServlet.doGet(ApiServlet.java:89)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:686)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:791)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:852)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:190)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
        at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:527)
        at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:126)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at org.eclipse.jetty.server.Server.handle(Server.java:530)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:347)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:256)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
        at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:247)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:140)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:382)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
        at java.lang.Thread.run(Thread.java:748)
2018-06-13 15:28:41,024 ERROR [c.c.a.ApiServlet] (qtp1796488937-13:ctx-88e441c4) (logid:f9e9b399)
unknown exception writing api response
com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@168d9c37:
INSERT INTO event (event.type, event.state, event.description, event.created, event.user_id,
event.account_id, event.domain_id, event.level, event.start_id, event.parameters, event.uuid,
event.archived, event.display) VALUES (_binary'USER.LOGOUT', 'Completed', _binary'user has
logged out', '2018-06-13 13:28:40', 2, 2, 1, _binary'INFO', 0, null, _binary'd9009f21-6550-4a18-a6e9-9213bbb8eabb',
0, 1)
        at com.cloud.utils.db.GenericDaoBase.persist(GenericDaoBase.java:1436)
        at sun.reflect.GeneratedMethodAccessor118.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at com.cloud.utils.db.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:34)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:174)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
        at com.sun.proxy.$Proxy121.persist(Unknown Source)
        at com.cloud.event.ActionEventUtils.persistActionEvent(ActionEventUtils.java:186)
        at com.cloud.event.ActionEventUtils.onActionEvent(ActionEventUtils.java:98)
        at com.cloud.user.AccountManagerImpl.logoutUser(AccountManagerImpl.java:2096)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:338)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:197)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
        at com.sun.proxy.$Proxy40.logoutUser(Unknown Source)
        at com.cloud.api.ApiServer.logoutUser(ApiServer.java:1104)
        at com.cloud.api.ApiServlet.processRequestInContext(ApiServlet.java:234)
        at com.cloud.api.ApiServlet$1.run(ApiServlet.java:130)
        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.ApiServlet.processRequest(ApiServlet.java:127)
        at com.cloud.api.ApiServlet.doGet(ApiServlet.java:89)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:686)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:791)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:852)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:190)
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
        at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:527)
        at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:126)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
        at org.eclipse.jetty.server.Server.handle(Server.java:530)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:347)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:256)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
        at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:247)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:140)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:382)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
        at java.lang.Thread.run(Thread.java:748)
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 94 milliseconds ago.  The last packet
sent successfully to the server was 93 milliseconds ago.
        at sun.reflect.GeneratedConstructorAccessor96.newInstance(Unknown Source)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        ... 82 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.
        at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3119)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3570)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3559)
        ... 78 more


We were able to connect to the GUI during 30 min with same kind of errors each time we tried
to start an instance or VR...and it's now impossible to connect to the GUI.

Seems to be a problem with the rollback transaction but i dont know how to deal with it except
 wait they finish their jobs

Here log from mysqld.log :

he manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
180613 14:24:19 mysqld_safe Number of processes running now: 0
180613 14:24:19 mysqld_safe mysqld restarted
2018-06-13 14:24:19 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please
use --explici
2018-06-13 14:24:19 0 [Note] /usr/sbin/mysqld (mysqld 5.6.39) starting as process 15999 ...
2018-06-13 14:24:19 15999 [Warning] Buffered warning: Changed limits: max_open_files: 1024
(requested 500

2018-06-13 14:24:19 15999 [Warning] Buffered warning: Changed limits: table_open_cache: 431
(requested 20

2018-06-13 14:24:19 15999 [Note] Plugin 'FEDERATED' is disabled.
2018-06-13 14:24:19 15999 [Note] InnoDB: Using atomics to ref count buffer pool pages
2018-06-13 14:24:19 15999 [Note] InnoDB: The InnoDB memory heap is disabled
2018-06-13 14:24:19 15999 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-06-13 14:24:19 15999 [Note] InnoDB: Memory barrier is not used
2018-06-13 14:24:19 15999 [Note] InnoDB: Compressed tables use zlib 1.2.3
2018-06-13 14:24:19 15999 [Note] InnoDB: Using Linux native AIO
2018-06-13 14:24:19 15999 [Note] InnoDB: Using CPU crc32 instructions
2018-06-13 14:24:19 15999 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2018-06-13 14:24:19 15999 [Note] InnoDB: Completed initialization of buffer pool
2018-06-13 14:24:19 15999 [Note] InnoDB: Highest supported file format is Barracuda.
2018-06-13 14:24:19 15999 [Note] InnoDB: Log scan progressed past the checkpoint lsn 7513843395
2018-06-13 14:24:19 15999 [Note] InnoDB: Database was not shutdown normally!
2018-06-13 14:24:19 15999 [Note] InnoDB: Starting crash recovery.
2018-06-13 14:24:19 15999 [Note] InnoDB: Reading tablespace information from the .ibd files...
2018-06-13 14:24:19 15999 [Note] InnoDB: Restoring possible half-written data pages
2018-06-13 14:24:19 15999 [Note] InnoDB: from the doublewrite buffer...
InnoDB: Doing recovery: scanned up to log sequence number 7513851738
2018-06-13 14:24:19 15999 [Note] InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25
26 27 28 29 30 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
2018-06-13 14:24:20 15999 [Note] InnoDB: 128 rollback segment(s) are active.
2018-06-13 14:24:20 15999 [Note] InnoDB: Waiting for purge to start
2018-06-13 14:24:20 15999 [Note] InnoDB: 5.6.39 started; log sequence number 7513851738
2018-06-13 14:24:20 15999 [Note] Server hostname (bind-address): '172.8.22.170'; port: 3306
2018-06-13 14:24:20 15999 [Note]   - '172.8.22.170' resolves to '172.8.22.170';
2018-06-13 14:24:20 15999 [Note] Server socket created on IP: '172.8.22.170'.
2018-06-13 14:24:20 15999 [Note] Event Scheduler: Loaded 0 events
2018-06-13 14:24:20 15999 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.39'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server
(GPL)
^C
[root@FRPRCSSQB1 /]# tail -f /var/log/mysqld.log
InnoDB: Apply batch completed
2018-06-13 15:28:42 17230 [Note] InnoDB: 128 rollback segment(s) are active.
2018-06-13 15:28:42 17230 [Note] InnoDB: Waiting for purge to start
2018-06-13 15:28:42 17230 [Note] InnoDB: 5.6.39 started; log sequence number 7517034692
2018-06-13 15:28:42 17230 [Note] Server hostname (bind-address): '172.8.22.170'; port: 3306
2018-06-13 15:28:42 17230 [Note]   - '172.8.22.170' resolves to '172.8.22.170';
2018-06-13 15:28:42 17230 [Note] Server socket created on IP: '172.8.22.170'.
2018-06-13 15:28:42 17230 [Note] Event Scheduler: Loaded 0 events
2018-06-13 15:28:42 17230 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.6.39'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server
(GPL)

Thanks upfront for any technical help or better understanding of what is going on ;)

Best regards,
[SignatureBouige]


Mime
  • Unnamed multipart/related (inline, None, 0 bytes)
View raw message