Intermittent Communications Link Failure

[Former Member]

Hi,

I'm getting Communications Link Failure when Jenkins triggers an integration test on an AWS Ubuntu machine where it has a local mysql DB setup. Most of the time it completes successfully, however, intermittently, it fails with the Communications link failure message. So far, I've found two different stack trace patterns with the same Communications link failure (hybris version: 5.1.0.2, mysql version: 5.5.49)

First pattern is com.mysql.jdbc.exceptions.jdbc4.CommunicationsException caused by java.io.EOFException

  [yunitint] 2016-05-11 19:30:34,063 ERROR      [ConnectionImpl] error resetting isolation level
  [yunitint] com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.
  [yunitint]     at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
  [yunitint]     at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
  [yunitint]     at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
  [yunitint]     at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
  [yunitint]     at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
  [yunitint]     at com.mysql.jdbc.Util.getInstance(Util.java:386)
  [yunitint]     at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1014)
  [yunitint]     at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:988)
  [yunitint]     at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:974)
  [yunitint]     at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:919)
  [yunitint]     at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1290)
  [yunitint]     at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1282)
  [yunitint]     at com.mysql.jdbc.ConnectionImpl.setTransactionIsolation(ConnectionImpl.java:5527)
  [yunitint]     at de.hybris.platform.jdbcwrapper.ConnectionImpl.doSetTransactionIsolation(ConnectionImpl.java:692)
  [yunitint]     at de.hybris.platform.jdbcwrapper.ConnectionImpl.restoreTxIsolationLevel(ConnectionImpl.java:197)
  [yunitint]     at de.hybris.platform.jdbcwrapper.ConnectionImpl.unsetTxBound(ConnectionImpl.java:171)
  [yunitint]     at de.hybris.platform.tx.Transaction.unsetTxBoundConnection(Transaction.java:852)
  [yunitint]     at de.hybris.platform.tx.Transaction.clearTxBoundConnectionAndNotify(Transaction.java:829)
  [yunitint]     at de.hybris.platform.tx.Transaction.clearTxBoundConnectionAndNotifyRollback(Transaction.java:819)
  [yunitint]     at de.hybris.platform.tx.Transaction.rollbackOuter(Transaction.java:1046)
  [yunitint]     at de.hybris.platform.tx.Transaction.rollback(Transaction.java:990)
  [yunitint]     at de.hybris.platform.spring.HybrisTransactionManager.doRollback(HybrisTransactionManager.java:80)
  [yunitint]     at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:845)
  [yunitint]     at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:822)
  [yunitint]     at org.springframework.transaction.support.TransactionTemplate.rollbackOnException(TransactionTemplate.java:161)
  [yunitint]     at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:134)
  [yunitint]     at de.hybris.platform.processengine.process.ProcessengineTaskRunner.runProcessTaskInTransaction(ProcessengineTaskRunner.java:159)
  [yunitint]     at de.hybris.platform.processengine.process.ProcessengineTaskRunner.doRun(ProcessengineTaskRunner.java:126)
  [yunitint]     at de.hybris.platform.processengine.process.ProcessengineTaskRunner.run(ProcessengineTaskRunner.java:97)
  [yunitint]     at de.hybris.platform.processengine.process.ProcessengineTaskRunner.run(ProcessengineTaskRunner.java:1)
  [yunitint]     at de.hybris.platform.processengine.task.impl.ProcessengineTaskExecutionStrategy.run(ProcessengineTaskExecutionStrategy.java:33)
  [yunitint]     at de.hybris.platform.task.impl.DefaultTaskService.processTask(DefaultTaskService.java:1127)
  [yunitint]     at de.hybris.platform.task.impl.DefaultTaskService.process(DefaultTaskService.java:1026)
  [yunitint]     at de.hybris.platform.task.impl.DefaultTaskService.processInTenant(DefaultTaskService.java:986)
  [yunitint]     at de.hybris.platform.task.impl.DefaultTaskService$3.run(DefaultTaskService.java:891)
  [yunitint]     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
  [yunitint]     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
  [yunitint]     at java.lang.Thread.run(Thread.java:745)
  [yunitint] Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure
  [yunitint] 
  [yunitint] The last packet successfully received from the server was 2 milliseconds ago.  The last packet sent successfully to the server was 0 milliseconds ago.
  [yunitint]     at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
  [yunitint]     at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
  [yunitint]     at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
  [yunitint]     at java.lang.reflect.Constructor.newInstance(Constructor.java:526)
  [yunitint]     at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
  [yunitint]     at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1117)
  [yunitint]     at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3603)
  [yunitint]     at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3492)
  [yunitint]     at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4043)
  [yunitint]     at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2503)
  [yunitint]     at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2664)
  [yunitint]     at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2788)
  [yunitint]     at com.mysql.jdbc.ConnectionImpl.rollbackNoChecks(ConnectionImpl.java:5115)
  [yunitint]     at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:5001)
  [yunitint]     at de.hybris.platform.jdbcwrapper.ConnectionImpl.rollback(ConnectionImpl.java:508)
  [yunitint]     at de.hybris.platform.tx.Transaction.rollbackConnection(Transaction.java:1060)
  [yunitint]     at de.hybris.platform.tx.Transaction.rollbackConnection(Transaction.java:1053)
  [yunitint]     at de.hybris.platform.tx.Transaction.rollbackOuter(Transaction.java:1038)
  [yunitint]     ... 18 more
  [yunitint] Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
  [yunitint]     at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3052)
  [yunitint]     at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3503)
  [yunitint]     ... 29 more

The other pattern is de.hybris.platform.jalo.JaloSystemException caused by de.hybris.platform.persistence.hjmp.HJMPFinderException

      [java] 2016-05-11 19:30:33,491 ERROR      [AbstractAntPerformable] Error occurred while perfort task
      [java] de.hybris.platform.servicelayer.exceptions.ModelSavingException: [de.hybris.platform.product.impl.UniqueCatalogItemInterceptor@2f9e200e]: unexpected preparer error: Communications link failure
      [java] 
      [java] The last packet successfully received from the server was 0 milliseconds ago.  The last packet sent successfully to the server was 0 milliseconds ago.
      [java]     at de.hybris.platform.servicelayer.internal.model.impl.ModelWrapper.prepare(ModelWrapper.java:107)
      [java]     at de.hybris.platform.servicelayer.internal.model.extractor.impl.DefaultInterceptorsExecutor.execute(DefaultInterceptorsExecutor.java:80)
      [java]     at de.hybris.platform.servicelayer.internal.model.extractor.impl.DefaultModelExtractor.process(DefaultModelExtractor.java:56)
      [java]     at de.hybris.platform.servicelayer.internal.model.impl.DefaultModelService.saveAllInternal(DefaultModelService.java:1131)
      [java]     at de.hybris.platform.servicelayer.internal.model.impl.DefaultModelService.saveAll(DefaultModelService.java:1115)
      [java]     at de.hybris.platform.servicelayer.internal.model.impl.DefaultModelService.save(DefaultModelService.java:770)
      [java]     at de.hybris.platform.servicelayer.event.impl.AbstractEventListener.onApplicationEvent(AbstractEventListener.java:67)
      [java]     at de.hybris.platform.servicelayer.event.impl.AbstractEventListener.onApplicationEvent(AbstractEventListener.java:1)
      [java]     at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:97)
      [java]     at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:327)
      [java]     at de.hybris.platform.spring.ctx.CloseAwareApplicationContext.publishEvent(CloseAwareApplicationContext.java:97)
      [java]     at de.hybris.platform.servicelayer.event.impl.SpringEventSender.sendEvent(SpringEventSender.java:36)
      [java]     at de.hybris.platform.servicelayer.event.impl.PlatformClusterEventSender.sendEvent(PlatformClusterEventSender.java:63)
      [java]     at de.hybris.platform.servicelayer.event.impl.DefaultEventService.publishEvent(DefaultEventService.java:78)
      [java]     at de.hybris.platform.servicelayer.internal.jalo.ServicelayerManager.notifyInitializationEnd(ServicelayerManager.java:254)
      [java]     at de.hybris.ant.taskdefs.AbstractAntPerformable.doPerform(AbstractAntPerformable.java:154)
      [java]     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      [java]     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
      [java]     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      [java]     at java.lang.reflect.Method.invoke(Method.java:606)
      [java]     at bsh.Reflect.invokeMethod(Unknown Source)
      [java]     at bsh.Reflect.invokeObjectMethod(Unknown Source)
      [java]     at bsh.Name.invokeMethod(Unknown Source)
      [java]     at bsh.BSHMethodInvocation.eval(Unknown Source)
      [java]     at bsh.BSHPrimaryExpression.eval(Unknown Source)
      [java]     at bsh.BSHPrimaryExpression.eval(Unknown Source)
      [java]     at bsh.Interpreter.eval(Unknown Source)
      [java]     at bsh.Interpreter.eval(Unknown Source)
      [java]     at bsh.Interpreter.eval(Unknown Source)
      [java]     at de.hybris.platform.util.ClientExecuter.execute(ClientExecuter.java:38)
      [java]     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      [java]     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
      [java]     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      [java]     at java.lang.reflect.Method.invoke(Method.java:606)
      [java]     at de.hybris.bootstrap.loader.Loader.execute(Loader.java:139)
      [java]     at de.hybris.bootstrap.loader.Loader.main(Loader.java:112)
      [java] Caused by: de.hybris.platform.jalo.JaloSystemException: Communications link failure
      [java] 
      [java] The last packet successfully received from the server was 0 milliseconds ago.  The last packet sent successfully to the server was 0 milliseconds ago.[HY--1]
      [java]     at de.hybris.platform.persistence.type.TypeManagerEJB.findByCodeExact(TypeManagerEJB.java:284)
      [java]     at de.hybris.platform.persistence.type.TypeManagerEJB.getComposedType(TypeManagerEJB.java:459)
      [java]     at de.hybris.platform.jalo.type.TypeManager.getComposedType(TypeManager.java:387)
      [java]     at de.hybris.platform.servicelayer.type.daos.impl.DefaultTypeDao.findComposedTypeByCode(DefaultTypeDao.java:70)
      [java]     at de.hybris.platform.servicelayer.type.impl.DefaultTypeService.getComposedTypeForCode(DefaultTypeService.java:111)
      [java]     at de.hybris.platform.catalog.impl.DefaultCatalogTypeService.isCatalogVersionAwareType(DefaultCatalogTypeService.java:233)
      [java]     at de.hybris.platform.product.impl.UniqueCatalogItemInterceptor.onPrepare(UniqueCatalogItemInterceptor.java:128)
      [java]     at de.hybris.platform.servicelayer.internal.model.impl.ModelWrapper.prepare(ModelWrapper.java:98)
      [java]     ... 42 more
      [java] Caused by: de.hybris.platform.persistence.hjmp.HJMPFinderException: Communications link failure
      [java] 
      [java] The last packet successfully received from the server was 0 milliseconds ago.  The last packet sent successfully to the server was 0 milliseconds ago.
      [java]     at de.hybris.platform.persistence.type.ComposedType_HJMPWrapper.ejbFindByCodeExact(ComposedType_HJMPWrapper.java:1248)
      [java]     at sun.reflect.GeneratedMethodAccessor26.invoke(Unknown Source)
      [java]     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      [java]     at java.lang.reflect.Method.invoke(Method.java:606)
      [java]     at de.hybris.platform.util.Utilities.callMethod(Utilities.java:1071)
      [java]     at de.hybris.platform.util.Utilities.callMethod(Utilities.java:1061)
      [java]     at de.hybris.platform.persistence.framework.HomeInvocationHandler.invoke(HomeInvocationHandler.java:93)
      [java]     at com.sun.proxy.$Proxy0.findByCodeExact(Unknown Source)
      [java]     at de.hybris.platform.persistence.type.TypeManagerEJB.findByCodeExact(TypeManagerEJB.java:271)
      [java]     ... 49 more
      [java] shutting down hybris registry..

We're using hybris 5.1.0.2 and the default hybris OOTB db.pool settings as shown below

 db.pool.maxActive=90
 db.pool.maxIdle=90
 
 db.pool.minIdle=2
 db.pool.timeBetweenEvictionRunsMillis=10000
 db.pool.minEvictableIdleTimeMillis=300000
 db.pool.numTestsPerEvictionRun=100
 db.pool.testWhileIdle=true
 db.pool.testOnBorrow=false
 db.pool.testOnReturn=false
 db.pool.whenExhaustedAction=1
 db.pool.maxWait=10000
 
 db.pool.dumpThreadsOnBorrowError=false

And mysql version and timeout related settings are:

 mysql-client-core-5.5 (5.5.49-0ubuntu0.14.04.1)
 mysql-client-5.5 (5.5.49-0ubuntu0.14.04.1)
 mysql-server-core-5.5 (5.5.49-0ubuntu0.14.04.1)
 mysql-server-5.5 (5.5.49-0ubuntu0.14.04.1)

 connect_timeout    10
 delayed_insert_timeout    300
 innodb_flush_log_at_timeout    1
 innodb_lock_wait_timeout    50
 innodb_rollback_on_timeout    OFF
 interactive_timeout    28800
 lock_wait_timeout    31536000
 net_read_timeout    30
 net_write_timeout    60
 rpl_stop_slave_timeout    31536000
 slave_net_timeout    3600
 wait_timeout    28800

We've increased mysql innodb_buffer_pool_size from 134,217,728 to 1,073,741,824 and table_cache from 64 to 128, but it didn't help.

Anyone has any suggestions on how to fix this issue?

Thanks, Yong

[Former Member]

Hi, i'm facing the same, did you manage to fix it please ?