java - Database connections not closed after idle-timeout in wildfly Datasource

Question

I have an application running under wildfly 8.1 The database connections used in the applications are taken from a Datasource defined in standalone.xml file.

Problem: I don't know why but the Connection from the Pool never goes Idle and are released. Eventually the Pool gets filled will all active Connection and application starts throwing javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:/bo/datasource

At the same time when I look at the database, most of the Connections are shown to be idle. (Configuration and result output below)

I have been at this for a week now and have not been able to figure out root cause of this problem. I have also checked all places where a connection is created and have made sure that they are closed afterwards.

What are the other possible places I should be looking into? Or is this a bug (or known issues with Wildfly datasource)?

Wildfly datasource definition:

    <subsystem xmlns="urn:jboss:domain:datasources:2.0">
        <datasources>
            <datasource jndi-name="java:/db/pool" pool-name="DBSource" enabled="true">
                <connection-url>jdbc:postgresql://<IP>:5432/DB</connection-url>
                <driver>postgres</driver>
                <new-connection-sql>select 1</new-connection-sql>
                <pool>
                    <min-pool-size>5</min-pool-size>
                    <max-pool-size>100</max-pool-size>
                </pool>
                <security>
                    <user-name>user</user-name>
                    <password>password</password>
                </security>
                <validation>
                    <check-valid-connection-sql>select 1</check-valid-connection-sql>
                    <background-validation>true</background-validation>
                    <background-validation-millis>60000</background-validation-millis>
                </validation>
                <timeout>
                    <idle-timeout-minutes>30</idle-timeout-minutes>
                </timeout>
                <statement>
                    <track-statements>true</track-statements>
                </statement>
            </datasource>
            <drivers>
                <driver name="h2" module="com.h2database.h2">
                    <xa-datasource-class>org.h2.jdbcx.JdbcDataSource</xa-datasource-class>
                </driver>
                <driver name="postgres" module="org.postgres">
                    <driver-class>org.postgresql.Driver</driver-class>
                </driver>
            </drivers>
        </datasources>
    </subsystem>

Wildfly datasource pool information:

Command:

/subsystem=datasources/data-source=DBSource/statistics=pool:read-resource(recursive=false,proxies=false,include-runtime=true,include-defaults=true) 

Response:

{
    "outcome" => "success",
    "result" => {
        "ActiveCount" => "98",
        "AvailableCount" => "55",
        "AverageBlockingTime" => "1",
        "AverageCreationTime" => "125",
        "AverageGetTime" => "27",
        "BlockingFailureCount" => "0",
        "CreatedCount" => "98",
        "DestroyedCount" => "0",
        "IdleCount" => "3",
        "InUseCount" => "95",
        "MaxCreationTime" => "1382",
        "MaxGetTime" => "1382",
        "MaxUsedCount" => "97",
        "MaxWaitCount" => "0",
        "MaxWaitTime" => "1",
        "TimedOut" => "0",
        "TotalBlockingTime" => "71",
        "TotalCreationTime" => "12340",
        "TotalGetTime" => "12696",
        "WaitCount" => "0"
    },
    "response-headers" => {"process-state" => "reload-required"}
}

PostgreSQL Query Status:

Command:

SELECT datname, pid, usename, waiting, state, (now()-query_start) AS since, (now() - state_change) AS since2, (now() - backend_start) as since3, (now() - xact_start) as since4, query FROM pg_stat_activity ORDER BY datname, state, usename, waiting, query, since, pid; 

Response:

    datname    | pid  |  usename   | waiting |        state        |      since      |      since2      |     since3      |     since4      |                                                                                                                                   
---------------+------+------------+---------+---------------------+-----------------+------------------+-----------------+-----------------+-----------------------------------------------------------------------------------------------------------------------------------
 BOIEDUDBV13R1 | 4871 | blueoptima | f       | active              | 00:00:00.176188 | 00:00:00.176179  | 01:37:21.045722 | 00:02:17.212346 | Query-1
 BOIEDUDBV13R1 | 4568 | blueoptima | f       | active              | 00:18:33.035399 | 00:18:33.035395  | 04:25:11.916388 | 00:18:33.473355 | Query-2
 BOIEDUDBV13R1 | 4564 | blueoptima | f       | active              | 00:10:10.599237 | 00:10:10.599232  | 04:25:11.943752 | 00:10:10.915048 | Query-3 
 BOIEDUDBV13R1 | 4498 | blueoptima | f       | active              | 00:03:25.861284 | 00:03:25.86128   | 05:09:51.735583 | 00:03:25.861823 | Query-4 
 BOIEDUDBV13R1 | 4535 | blueoptima | f       | active              | 00:01:16.612227 | 00:01:16.612222  | 04:34:01.668772 | 00:01:16.614149 | Query-5
 BOIEDUDBV13R1 | 4534 | blueoptima | f       | idle                | 00:00:04.72429  | 00:00:04.683504  | 04:35:21.78966  |                 | COMMIT
 BOIEDUDBV13R1 | 4519 | blueoptima | f       | idle                | 00:00:12.950041 | 00:00:12.913566  | 04:50:53.698877 |                 | COMMIT
 BOIEDUDBV13R1 | 4438 | blueoptima | f       | idle                | 00:00:25.82585  | 00:00:25.81036   | 05:34:41.528853 |                 | COMMIT
 BOIEDUDBV13R1 | 4425 | blueoptima | f       | idle                | 00:09:12.999537 | 00:09:12.9731    | 05:41:51.806148 |                 | COMMIT
 BOIEDUDBV13R1 | 4488 | blueoptima | f       | idle                | 00:56:04.709316 | 00:56:04.686439  | 05:14:45.445165 |                 | COMMIT
 BOIEDUDBV13R1 | 4501 | blueoptima | f       | idle                | 00:57:00.615919 | 00:57:00.61589   | 05:06:51.861328 |                 | COMMIT
 BOIEDUDBV13R1 | 4466 | blueoptima | f       | idle                | 04:11:54.8669   | 04:11:54.516947  | 05:25:03.079741 |                 | COMMIT
 BOIEDUDBV13R1 | 4419 | blueoptima | f       | idle                | 04:51:03.786294 | 04:51:03.749462  | 05:41:51.814577 |                 | COMMIT
 BOIEDUDBV13R1 | 4340 | blueoptima | f       | idle                | 04:52:19.772533 | 04:52:19.720537  | 06:31:51.758733 |                 | COMMIT
 BOIEDUDBV13R1 | 4502 | blueoptima | f       | idle                | 04:54:49.892553 | 04:54:49.85151   | 05:06:51.439101 |                 | COMMIT
 BOIEDUDBV13R1 | 4406 | blueoptima | f       | idle                | 05:09:20.675009 | 05:09:20.655038  | 06:00:50.160594 |                 | COMMIT
 BOIEDUDBV13R1 | 4489 | blueoptima | f       | idle                | 05:09:54.785706 | 05:09:54.751723  | 05:14:45.358108 |                 | COMMIT
 BOIEDUDBV13R1 | 4449 | blueoptima | f       | idle                | 05:16:58.881682 | 05:16:58.88074   | 05:26:50.728973 |                 | COMMIT
 BOIEDUDBV13R1 | 4450 | blueoptima | f       | idle                | 05:17:23.727614 | 05:17:23.726158  | 05:25:55.116657 |                 | COMMIT
 BOIEDUDBV13R1 | 4465 | blueoptima | f       | idle                | 05:22:32.475769 | 05:22:32.470301  | 05:25:03.230671 |                 | COMMIT
 BOIEDUDBV13R1 | 4421 | blueoptima | f       | idle                | 05:25:03.596961 | 05:25:03.596942  | 05:41:51.81487  |                 | COMMIT
 BOIEDUDBV13R1 | 4451 | blueoptima | f       | idle                | 05:25:29.373092 | 05:25:29.364467  | 05:25:52.433709 |                 | COMMIT
 BOIEDUDBV13R1 | 4448 | blueoptima | f       | idle                | 05:25:58.729039 | 05:25:58.724453  | 05:26:50.898318 |                 | COMMIT
 BOIEDUDBV13R1 | 4423 | blueoptima | f       | idle                | 05:26:13.2656   | 05:26:13.263502  | 05:41:51.814528 |                 | COMMIT
 BOIEDUDBV13R1 | 4426 | blueoptima | f       | idle                | 05:26:58.773981 | 05:26:58.765174  | 05:41:51.179333 |                 | COMMIT
 BOIEDUDBV13R1 | 4415 | blueoptima | f       | idle                | 05:29:07.123798 | 05:29:07.115682  | 05:47:36.740939 |                 | COMMIT
 BOIEDUDBV13R1 | 4394 | blueoptima | f       | idle                | 05:42:02.02632  | 05:42:01.994772  | 06:05:54.290575 |                 | COMMIT
 BOIEDUDBV13R1 | 4416 | blueoptima | f       | idle                | 05:45:52.799303 | 05:45:52.793004  | 05:47:36.701474 |                 | COMMIT
 BOIEDUDBV13R1 | 4408 | blueoptima | f       | idle                | 05:48:02.635413 | 05:48:02.630767  | 05:54:49.133404 |                 | COMMIT
 BOIEDUDBV13R1 | 4410 | blueoptima | f       | idle                | 05:49:09.631417 | 05:49:09.624039  | 05:49:47.440347 |                 | COMMIT
 BOIEDUDBV13R1 | 4392 | blueoptima | f       | idle                | 05:49:45.136111 | 05:49:45.124627  | 06:05:54.52666  |                 | COMMIT
 BOIEDUDBV13R1 | 4411 | blueoptima | f       | idle                | 05:49:45.208436 | 05:49:45.207393  | 05:49:46.326729 |                 | COMMIT
 BOIEDUDBV13R1 | 4399 | blueoptima | f       | idle                | 05:50:19.476105 | 05:50:19.465746  | 06:04:53.509647 |                 | COMMIT
 BOIEDUDBV13R1 | 4383 | blueoptima | f       | idle                | 05:54:04.625364 | 05:54:04.56991   | 06:09:43.004602 |                 | COMMIT
 BOIEDUDBV13R1 | 4382 | blueoptima | f       | idle                | 05:58:29.615594 | 05:58:29.608542  | 06:09:43.496538 |                 | COMMIT
 BOIEDUDBV13R1 | 4404 | blueoptima | f       | idle                | 06:00:48.381014 | 06:00:48.379175  | 06:00:50.352202 |                 | COMMIT
 BOIEDUDBV13R1 | 4393 | blueoptima | f       | idle                | 06:01:49.740445 | 06:01:49.733278  | 06:05:54.468595 |                 | COMMIT
 BOIEDUDBV13R1 | 4379 | blueoptima | f       | idle                | 06:02:12.00668  | 06:02:12.004878  | 06:11:37.044413 |                 | COMMIT
 BOIEDUDBV13R1 | 4396 | blueoptima | f       | idle                | 06:02:25.216415 | 06:02:25.202565  | 06:05:10.411017 |                 | COMMIT
 BOIEDUDBV13R1 | 4390 | blueoptima | f       | idle                | 06:03:48.651868 | 06:03:48.647211  | 06:06:05.443    |                 | COMMIT
 BOIEDUDBV13R1 | 4375 | blueoptima | f       | idle                | 06:04:51.760968 | 06:04:51.732155  | 06:11:37.545217 |                 | COMMIT
 BOIEDUDBV13R1 | 4353 | blueoptima | f       | idle                | 06:04:53.302492 | 06:04:53.252345  | 06:25:54.61252  |                 | COMMIT
 BOIEDUDBV13R1 | 4372 | blueoptima | f       | idle                | 06:05:08.158286 | 06:05:08.137553  | 06:11:49.797186 |                 | COMMIT
 BOIEDUDBV13R1 | 4397 | blueoptima | f       | idle                | 06:05:08.578854 | 06:05:08.544941  | 06:05:10.298185 |                 | COMMIT
 BOIEDUDBV13R1 | 4377 | blueoptima | f       | idle                | 06:08:34.443118 | 06:08:34.435299  

Answer 1

It turns out that Hibernate was holding connection and not releasing them to the Pool. Irrespective of the fact that we are using thread local context. But after adding <property name="hibernate.connection.release_mode">after_transaction</property> to the hibernate config. The problem got solved.

PS: I still dont understand why we need to define this explicitly and why the auto release_mode would not release the connection once the session is closed.