Welcome to OStack Knowledge Sharing Community for programmer and developer-Open, Learning and Share
Welcome To Ask or Share your Answers For Others

Categories

0 votes
410 views
in Technique[技术] by (71.8m points)

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

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  

与恶龙缠斗过久,自身亦成为恶龙;凝视深渊过久,深渊将回以凝视…
Welcome To Ask or Share your Answers For Others

1 Answer

0 votes
by (71.8m points)

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.


与恶龙缠斗过久,自身亦成为恶龙;凝视深渊过久,深渊将回以凝视…
Welcome to OStack Knowledge Sharing Community for programmer and developer-Open, Learning and Share
Click Here to Ask a Question

...