Tomcat 8 Connection has been abandoned

alexnktn picture alexnktn · Aug 11, 2017 · Viewed 7.9k times · Source

First time posting question. Thanks all!

The issue I have is been around for a while and we couldn't find a solution for that. In short, application build using Java 8, Spring, Hibernate, PostgreSQL, JSF (PrimeFaces here), Webflow. The problem related to Connection being closed, but it seems that application still uses it, so next time some logic borrows the same connection it just "stumbles" on it, and throws exception:

 Caused by: org.hibernate.exception.GenericJDBCException: could not prepare statement
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:47)

Caused by: java.sql.SQLException: Connection has already been closed.
    at org.apache.tomcat.jdbc.pool.ProxyConnection.invoke(ProxyConnection.java:117)
    at org.apache.tomcat.jdbc.pool.JdbcInterceptor.invoke(JdbcInterceptor.java:108)

Application could work for couple days without problems, until something happens, where it gets Connection abandoned warning from tomcat. From there is just won't work fine, and many process would get that closed connection and will fail measurably, because connection is already closed:

 WARNING [Tomcat JDBC Pool Cleaner[1989780873:1502425160484]] org.apache.tomcat.jdbc.pool.ConnectionPool.abandon Connection has been abandoned PooledConnection[org.postgresql.jdbc.PgConnection@234be71f]:java.lang.Exception
    at org.apache.tomcat.jdbc.pool.ConnectionPool.getThreadDump(ConnectionPool.java:1093)

Our team spend hours and hours on that issue, searching in the web, and consulting fellow developers, and in the beginning it was all come down to trying to tweak Tomcat server.xml, but without any success. It could run fine for another days, and then fail with same problem, where server will become inconsistent, so the only thing to do is restart it. The interceptors we added didn't help, and only there as part of trying to solve problem.

Only later we could reliably replicate the issue, and the issue was pretty interesting on its own. So, Tomcat would throw Abandoned Connection (close it) when any Exception thrown within transaction, custom or regular Java, such as if there is NoResultException or some MyCustomException based on assertion is thrown; 60 seconds later (removeAbandonedTimeout) Tomcat will display Warning Message and connection will be closed. But the problem that logic still refers to it, and more connections closed down the line, more things breaks while performing business logic.

There are two dataSources configured in server.xml (one for business logic, another for Jobs) as follows:

<Resource auth="Container" driverClassName="org.postgresql.Driver"
factory="org.apache.tomcat.jdbc.pool.DataSourceFactory" 
initialSize="5"
jdbcInterceptors=
"org.apache.tomcat.jdbc.pool.interceptor.ConnectionState; 
org.apache.tomcat.jdbc.pool.interceptor.StatementFinalizer; 
org.apache.tomcat.jdbc.pool.interceptor.SlowQueryReportJmx (threshold=10000)"
logAbandoned="true" 
maxActive="30" 
minEvictableIdleTimeMillis="30000"
minIdle="5" 
name="jdbc/my-app-db"
password=""
removeAbandoned="true" 
removeAbandonedTimeout="60" 
testOnBorrow="true"
testOnReturn="false" 
testWhileIdle="true"
timeBetweenEvictionRunsMillis="5000" 
type="javax.sql.DataSource"
url="jdbc:postgresql://mydb.rds.amazonaws.com:5432/mydb_db" 
username=""
validationInterval="30000" 
validationQuery="SELECT 1" />

<Resource auth="Container" 
driverClassName="org.postgresql.Driver"
factory="org.apache.tomcat.jdbc.pool.DataSourceFactory" 
initialSize="5"
jdbcInterceptors=
"org.apache.tomcat.jdbc.pool.interceptor.ConnectionState; 
org.apache.tomcat.jdbc.pool.interceptor.StatementFinalizer; 
org.apache.tomcat.jdbc.pool.interceptor.SlowQueryReportJmx (threshold=10000)"
logAbandoned="true" 
maxActive="30" 
minEvictableIdleTimeMillis="30000"
minIdle="5" 
name="jdbc/my-app-db-for-jobs" 
password=""
removeAbandoned="true" 
removeAbandonedTimeout="60" 
testOnBorrow="true"
testOnReturn="false" 
testWhileIdle="true"
timeBetweenEvictionRunsMillis="5000" 
type="javax.sql.DataSource"
url="jdbc:postgresql://mydb.rds.amazonaws.com:5432/myapp_db" 
username=""
validationInterval="30000" 
validationQuery="SELECT 1" />

And xml configuration:

 <bean id="entityManagerFactory"
    class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean">
    <property name="persistenceUnitName" value="acme"></property>
    <property name="jpaVendorAdapter">
        <bean class="org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter">
            <property name="showSql" value="true" />
            <property name="databasePlatform" value="org.hibernate.dialect.PostgreSQLDialect" />
        </bean>
    </property>
</bean>
<bean id="transactionManager" class="org.springframework.orm.jpa.JpaTransactionManager">
    <property name="dataSource" ref="dataSource"></property>
    <property name="entityManagerFactory" ref="entityManagerFactory"></property>
</bean>

and POM.xml with some dependencies:

    <dependency>
        <groupId>org.hibernate</groupId>
        <artifactId>hibernate-validator</artifactId>
        <version>5.2.4.Final</version>
    </dependency>

    <dependency>
        <groupId>org.springframework.webflow</groupId>
        <artifactId>spring-faces</artifactId>
        <version>2.4.2.RELEASE</version>
    </dependency>

    <dependency>
        <groupId>org.springframework.webflow</groupId>
        <artifactId>spring-webflow</artifactId>
        <version>2.4.2.RELEASE</version>
    </dependency>
    <dependency>
        <groupId>org.springframework</groupId>
        <artifactId>spring-context-support</artifactId>
        <version>4.1.6.RELEASE</version>
    </dependency>

    <dependency>
        <groupId>org.springframework</groupId>
        <artifactId>spring-web</artifactId>
    </dependency>
    <dependency>
        <groupId>org.hibernate</groupId>
        <artifactId>hibernate-entitymanager</artifactId>
    </dependency>
    <dependency>
        <groupId>org.postgresql</groupId>
        <artifactId>postgresql</artifactId>
        <version>42.1.1</version>
    </dependency>

And here is the piece of the code that could fail, but really anything that has a transaction, or anything that query DB could stumble upon closed Pool Conection:

 PromoCode promoCodeEntity = null;
    try {
        JpaTransactionManager transactionManager = (JpaTransactionManager) ApplicationContextProvider
                .getApplicationContext().getBean("transactionManager");
        TransactionDefinition def = new DefaultTransactionDefinition();
        TransactionStatus status = transactionManager.getTransaction(def);

        String jpql = "select p from PromoCode p where p.code = :code";
        Query query = em.createQuery(jpql).setParameter("code", promoCode);
        promoCodeEntity = (PromoCode) query.getSingleResult();

        if (promoCodeEntity.getQuantyOfUses() >= promoCodeEntity.getTotalOfUses()) {
            MyCustomException myCustomException = new MyCustomException("This promo code is not valid: [" + promoCode + "]");
            MyCustomException.setCode("PROMO_CODE");
            throw myCustomException;
        }

        if (!promoCodeEntity.getActive() || promoCodeEntity.getFinish()) {
            MyCustomException myCustomException = new MyCustomException("This promo code is not valid: [" + promoCode + "]");
            myCustomException.setCode("PROMO_CODE");
            throw myCustomException;
        }

        if (!(promoCodeEntity.getStartDateValid().before(new Date())
                && promoCodeEntity.getEndDateValid().after(new Date()))) {
            MyCustomException myCustomException = new MyCustomException("This promo code is expired: [" + promoCode + "]");
            myCustomException.setCode("PROMO_CODE");
            throw myCustomException;
        }
        promoCodeEntity.setQuantyOfUses(promoCodeEntity.getQuantyOfUses() + 1);
        transactionManager.commit(status);
    } catch (NoResultException e) {
        MyCustomException myCustomException = new MyCustomException("Promo code not found: [" + promoCode + "]");
        myCustomException.setCode("PROMO_CODE");
        throw myCustomException;
    }

Has anyone encounter such problem, or where should I look further? We made some drivers updates (such as postgres jdbc), also currently evaluating c3p0 Pool, to see if this is Tomcat Pool bugs related. But really will be nice to understand what's wrong.

Answer

Anshul Sharma picture Anshul Sharma · Aug 11, 2017

you nee to use connectionTimeout into your dataSources property. right now you are using default timeout, after timeout it forces to session to close. so you can try to add below code into dataSources property :

        connectionTimeout="300000"