3

I have a normal spring boot 1.2.x web app with an embedded Tomcat 7.x container and connected to an RDS instance (running MySQL 5.6). If the application is idle for a period of time (8 hours?) and then it receives a request it throws the following exception

** BEGIN NESTED EXCEPTION ** 

com.mysql.jdbc.exceptions.jdbc4.CommunicationsException
MESSAGE: The last packet successfully received from the server was39320 seconds ago.The last packet sent successfully to the server was 39320 seconds ago, whi
ch  is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your ap
plication, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this proble
m.

STACKTRACE:

com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was39320 seconds ago.The last packet sent succe
ssfully to the server was 39320 seconds ago, which  is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or t
esting connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection pr
operty '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:406)
... trimmed more of the stacktrace ... 
Caused by: java.net.SocketException: Broken pipe
 at java.net.SocketOutputStream.socketWrite0(Native Method)
 at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
 at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
 at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
 at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
 at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3227)
 ... 119 more


** END NESTED EXCEPTION **

In my application.yml (where configurations for datasource, hibernate, etc. can be set) I have the following (this is part of what I get when I call the management API /env

   "applicationConfig: [classpath:/application.yml]#rds-profile":{  
      "spring.profiles":"rds-profile",
      "spring.datasource.driverClassName":"com.mysql.jdbc.Driver",
      "spring.datasource.url":"jdbc:mysql://rds-host:3306/mydb?user=mysqlusername&password=****",
      "spring.datasource.schema":"classpath:/schema.sql",
      "spring.datasource.username":"mysqlusername",
      "spring.datasource.password":"******",
      "spring.datasource.testOnBorrow":true,
      "spring.datasource.validationQuery":"SELECT 1",
      "spring.datasource.continueOnError":true,
      "spring.datasource.timeBetweenEvictionRunsMillis":5000,
      "spring.datasource.minEvictableIdleTimeMillis":5000,
      "spring.datasource.max-active":500,
      "spring.jpa.database-platform":"org.hibernate.dialect.MySQL5InnoDBDialect",
      "spring.jpa.database":"MYSQL",
      "spring.jpa.show-sql":false,
      "spring.jpa.generate-ddl":false,
      "spring.jpa.hibernate.ddl-auto":"none",
      "spring.jpa.hibernate.dialect":"org.hibernate.dialect.MySQL5InnoDBDialect"
   },

Curiously, when I call the management API "/configprops" I get this (I don't know if this is the root of the problem?

  "spring.datasource.CONFIGURATION_PROPERTIES":{  
      "prefix":"spring.datasource",
      "properties":{  
         "platform":"all",
         "data":null,
         "driverClassName":"com.mysql.jdbc.Driver",
         "password":"******",
         "url":"jdbc:mysql://rds-host:3306/mydb?user=mysqlusername&password=****",
         "schema":"classpath:/schema.sql",
         "username":"mysqlusername",
         "jndiName":null,
         "xa":{  
            "dataSourceClassName":null,
            "properties":{  

            }
         },
         "continueOnError":true,
         "sqlScriptEncoding":null,
         "separator":";",
         "initialize":true
      }
   },

The question is: given the above configurations and details, why is it that I am still getting the "wait_timeout" exception? I would expect the connections to be tested when borrowed and I would expect the JDBC connection pool to create valid connections if none are available... so why is my application running out of valid connections after (8 hours?) or inactivity?

Thank you.

Jens Schauder
  • 77,657
  • 34
  • 181
  • 348
pastafarian
  • 1,010
  • 3
  • 16
  • 30
  • The connection will be tested when borrowed from a pool. Have you ascertained that the connections are really getting pooled (the stacktrace does not validate that). I have not used Spring Boot in production so I don't know how to find out if connection pooling is really on. Just to be certain, you may want to add a connection pool explicitly to the configuration and test it locally with debug logging to ensure that the app does take out connections from a pool. – manish Jul 13 '15 at 06:32
  • Thank you. I am assuming the tomcat connection pool is used because I include spring-boot-starter-data-jpa starter pom in my pom file. http://docs.spring.io/spring-boot/docs/current/reference/html/boot-features-sql.html#boot-features-connect-to-production-database – pastafarian Jul 14 '15 at 15:02
  • The limited stacktrace you have posted does not contain reference to a connection pool so it is unclear if one is being used. May be check the full stacktrace just to be sure. – manish Jul 14 '15 at 15:05
  • @manish: I have uploaded the full logs here: http://wikisend.com/download/162858/31389391.txt Thank you. – pastafarian Jul 16 '15 at 07:07
  • Your logs suggest that the Tomcat connection pool is indeed in use. However, it seems that the pool is still handing you bad connections. I have seen this with BoneCP, Tomcat and C3P0. HikariCP also [documents this in detail](https://github.com/brettwooldridge/HikariCP/wiki/Bad-Behavior:-Handling-Database-Down). In fact, HikariCP gives Tomcat the worst rating of all pools. Your best option would be to switch to HikariCP, repeat the connection unavailable test locally, ensure that HikariCP is working correctly and then use a long timeout before deploying the solution to production. – manish Jul 16 '15 at 07:45
  • By the way, what RDS instance type are you using? Not `t1.micro` I presume. – manish Jul 16 '15 at 07:46
  • @manish: Thank you. Strangely the Spring Boot documentation says: "We prefer the Tomcat pooling..." Also Tomcat claims much improvement in version 7. In any case I appreciate your suggestion. I think initially I will increase the wait_timeout and interactive_wait_timeout on the RDS server hoping it will fix the issue and have no adverse effect. My instance is t2.small. – pastafarian Jul 16 '15 at 16:02
  • See if you can set the minimum pool size to zero. That way, the pool would drain itself overnight and will be forced to start with a new connection in the morning, reducing the possibility of a connection error due to a connection pooled overnight. – manish Jul 16 '15 at 16:14

2 Answers2

1

If you are using auto-configuration to define RDS connection from the property file like this:

cloud.aws.rds.testdb.password=testdbpwd
cloud.aws.rds.testdb.username=testdbuser
cloud.aws.rds.testdb.databaseName=testdb

spring boot datasource auto-configuration will not work even you put these(or tomcat datasource conf) to your configuration file:

spring.datasource.driver-class-name=com.mysql.cj.jdbc.Driver
spring.datasource.test-on-borrow: true
spring.datasource.validation-query: SELECT 1 FROM DUAL
spring.datasource.log-validation-errors: true

I think this is the reason why you cannot validate your connections in the pool, before using them.

You need to override postProcessAfterInitialization method to set pool properties of the TomcatJdbcDataSourceFactory bean like this:

@Component
public class PoolConfiguration implements BeanPostProcessor {

@Override
public Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {
    if (bean instanceof TomcatJdbcDataSourceFactory) {
        TomcatJdbcDataSourceFactory tomcatJdbcDataSourceFactory = (TomcatJdbcDataSourceFactory) bean;
        tomcatJdbcDataSourceFactory.setTestOnBorrow(true);
        tomcatJdbcDataSourceFactory.setTestWhileIdle(true);
        tomcatJdbcDataSourceFactory.setValidationQuery("SELECT 1");
    }
    return bean;
}
}

I could not find any other solution for this.By the way this might be a bug of spring-cloud-aws-autoconfigure packet.

Good Luck!

gokhansari
  • 2,379
  • 1
  • 27
  • 33
0

Try using this as well

spring.datasource.test-while-idle=true
spring.datasource.validation-interval=5000
jst
  • 1,697
  • 1
  • 12
  • 13