1

Having background jobs in a wildfly web application where NamedParameterJdbcTemplate is used to retrieve a list of records, I've a database connection leak preventing the jobs to work after a while, CannotGetJdbcConnectionException.

After monitoring a part of the sql requests, here is what i found. For this simple piece of code :

String sqlselectreq = 
    "SELECT * " + 
    "FROM systemedpdfdb.documents " +
    "WHERE state=-3 AND closing_date IS null";

NamedParameterJdbcTemplate namedParameterJdbcTemplate = new  
    NamedParameterJdbcTemplate(this.getDataSource());

Map<String, Object> namedParameters = new HashMap<String, Object>();
// namedParameters.put("param_name_here", param_value_here);
List<Map<String, Object>> queryres =  
    namedParameterJdbcTemplate.queryForList(sqlselectreq, namedParameters);

if (!(queryres == null || queryres.isEmpty())) {
    for (Map<String, Object> queryrec : queryres) {
       ....
    }
} else {
    return new Result(this, Result.CodeCategory.NOERROR, 
        Result.Type.TEXT, "NOTHING TO DO".getBytes(), ident);

}

I have the following traces where we can see a useless last getConnection without close.

2017-05-11 15:37:00,031 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [DataSource] getConnection()
2017-05-11 15:37:00,281 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [Connection] prepareStatement(SELECT * FROM systemedpdfdb.documents WHERE state=-3 and closing_date is null)
2017-05-11 15:37:00,297 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [PreparedStatement] executeQuery()
2017-05-11 15:37:00,312 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [ResultSet] next()
2017-05-11 15:37:00,312 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [ResultSet] close()
2017-05-11 15:37:00,312 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [PreparedStatement] isClosed()
2017-05-11 15:37:00,328 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [PreparedStatement] close()
2017-05-11 15:37:00,328 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [Connection] isClosed()
2017-05-11 15:37:00,328 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [Connection] close()
2017-05-11 15:37:00,328 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [DataSource] getConnection()
2017-05-11 15:37:00,328 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [Connection] getMetaData()

Is it normal ? Or do I misuse Spring Jdbc Template ?

Thanks in advance

David L.

malaguna
  • 4,183
  • 1
  • 17
  • 33
David L
  • 175
  • 1
  • 14
  • Add some logging to after the `queryForList` call, just so we know for sure that the extra `getConnection` was made from in there. – jingx May 11 '17 at 15:26

2 Answers2

1

Thanks for your help .... the last useless not closed connection was caused by a buggy logging system as the following jboss logs let it guess...

2017-05-11 18:12:00,024 INFO  [eu.systemed.commands.workflow.CloseCancelledDocumentCommand] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) before execution of the query:SELECT * FROM systemedpdfdb.documents WHERE state=-3 and closing_date is null
2017-05-11 18:12:00,039 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [DataSource] getConnection()
2017-05-11 18:12:00,273 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [Connection] prepareStatement(SELECT * FROM systemedpdfdb.documents WHERE state=-3 and closing_date is null)
2017-05-11 18:12:00,289 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [PreparedStatement] executeQuery()
2017-05-11 18:12:00,305 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [ResultSet] next()
2017-05-11 18:12:00,305 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [ResultSet] close()
2017-05-11 18:12:00,305 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [PreparedStatement] isClosed()
2017-05-11 18:12:00,320 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [PreparedStatement] close()
2017-05-11 18:12:00,320 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [Connection] isClosed()
2017-05-11 18:12:00,320 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [Connection] close()
2017-05-11 18:12:00,320 INFO  [eu.systemed.commands.workflow.CloseCancelledDocumentCommand] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) after execution of the query:SELECT * FROM systemedpdfdb.documents WHERE state=-3 and closing_date is null
2017-05-11 18:12:00,320 INFO  [eu.systemed.commands.workflow.CloseCancelledDocumentCommand] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) empty result for the query:SELECT * FROM systemedpdfdb.documents WHERE state=-3 and closing_date is null
2017-05-11 18:12:00,320 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [DataSource] getConnection()
2017-05-11 18:12:00,320 DEBUG [jboss.jdbc.spy] (org.springframework.scheduling.quartz.SchedulerFactoryBean#0_Worker-1) java:jboss/datasources/SystemedPdfdataSource4jobs [Connection] getMetaData() 
David L
  • 175
  • 1
  • 14
0

The actual database connection is wrapped by your DataSource implementation. What DataSource implementation are you using?

In a web application you should (always?) use a DataSource that provides a pool of established connections (aka a connection pool). There are several excellent database connection pool implementation available. For example, DBCP, c3p0, and Heroku.

Also, if you're using Spring, simply inject your data source into your JdbcTemplate bean, and then inject the JdbcTemplate into your DAO class rather than creating a new NamedParameterJdbcTemplate instance on the fly.

Michael Peacock
  • 2,011
  • 1
  • 11
  • 14