質問をすることでしか得られない、回答やアドバイスがある。

15分調べてもわからないことは、質問しよう!

ただいまの
回答率

87.50%

同時アクセス数が増えるとコネクションが切断されてしまう。

受付中

回答 2

投稿 編集

  • 評価
  • クリップ 6
  • VIEW 27K+

score 6

同時アクセス数が増えるとコネクションが切断されてしまう。

Spring MVCで作成しているWEBシステムで、
同時アクセスができていることの確認はできているのですが、
同時アクセス数が増えると、コネクションが切断されてしまいます。

そこで、コネクションプールの設定を行う為に
データソースマッピング設定に以下の設定を記載しましたが、
設定が反映されませんでした。

        <bean id="dataSource" class="org.apache.tomcat.jdbc.pool.DataSource">
        <property name="driverClassName" value="org.postgresql.Driver"/>
        <property name="url" value="jdbc:postgresql://xxxxxxxxxxxxxx"/>
        <property name="username" value="xxxx" />
        <property name="password" value="xxxx" />
        <property name="validationQuery" value="SELECT 1" />
        <property name="testOnBorrow" value="true" />
        <property name="testWhileIdle" value="true" />
        <property name="timeBetweenEvictionRunsMillis" value="60000" />
        <property name="initialSize" value="100" />
        <property name="maxActive" value="100" />
        <property name="maxIdle" value="100" />
        <property name="minIdle" value="10" />


以下にpom.xmlを抜粋します

        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-core</artifactId>
            <version>${spring.version}</version>
        </dependency>

        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-web</artifactId>
            <version>${spring.version}</version>
        </dependency>

        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-webmvc</artifactId>
            <version>${spring.version}</version>
        </dependency>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-jdbc</artifactId>
            <version>4.3.8.RELEASE</version>
        </dependency>
        <dependency>
            <groupId>org.postgresql</groupId>
            <artifactId>postgresql</artifactId>
            <version>9.4-1200-jdbc41</version>
        </dependency>
        <dependency>
            <groupId>org.springframework</groupId>
            <artifactId>spring-jdbc</artifactId>
            <version>4.3.8.RELEASE</version>
        </dependency>
        <dependency>
            <groupId>org.apache.tomcat</groupId>
            <artifactId>tomcat-jdbc</artifactId>
            <version>8.5.23</version>
        </dependency>

コネクション接続時に発生したエラーメッセージ

[ERROR] DBException!
000.0.0.0jp.co.xxx.exception.DBException: java.sql.SQLException: PooledConnection has already been closed.
jp.co.xxxx.exception.DBException: jp.co.xxxx.exception.DBException: java.sql.SQLException: PooledConnection has already been closed.

何かアドバイスをいただけるとうれしいです。
よろしくお願い致します。

追記

ご質問ありがとうございます。
返答が遅くなり、申し訳ございません。

A)PostgreSQL側で、max_connectionsの設定は? 
⇒"100"になっております。

B)PostgreSQL側で、全てのSQLをログ出力できるようにして、validationQuery" value="SELECT 1 " が発行されているかどうか 
⇒確認しましたところ、validationQuery" value="SELECT 1 "の発行はされておりました。

C) OS側のtcp timeoutが短すぎることはないか?
⇒他アプリケーション動作時は、問題なく動作するため、
tcp timeoutの設定は問題ないと思っております。

また、今回の同時アクセス検証につきましては、
10秒間に100アクセスが可能かの検証を行っており
現状、100アクセス中の数件のコネクションが切断されてしまう状態です。

追記(使用データソース変更(2017/11/16))

データソースを
org.apache.commons.dbcp.BasicDataSourceに変更したところ、
性能が多少改善致しましたので追記致します。
(以前、[dbcp2]を試した時は、性能の改善が見られなかったのですが…)

【以下、データソースマッピング設定】

    <bean id="dataSource" class="org.apache.commons.dbcp.BasicDataSource">
        <property name="driverClassName" value="org.postgresql.Driver"/>
        <property name="url" value="jdbc:postgresql://xxxxxxxxxxxxxx" />
        <property name="username" value="xxxxx"/>
        <property name="password" value="xxxxx"/>
        <property name="initialSize" value="300"/>
        <property name="testOnBorrow" value="true"/>
        <property name="maxActive" value="300"/>
        <property name="maxIdle" value="300" />
    </bean>

上記データソースに変更後、
10秒間に100アクセスは、問題なく動作するようになりました。
ご協力ありがとうございます。

しかし、
・負荷を上げると、以前と同エラーが発生してしまう。
(※5秒間に400アクセスの検証で稀にエラーが発生)
 
・10秒間に100アクセスの検証をループして実施すると、
エラーが発生してしまう。
(※10秒間に100アクセスを2分間ループさせると、
1%未満の確立でエラーが発生)

・不具合原因の特定ができていない。

という状況の為、引き続き調査を行っていきたいと思っております。

皆様お忙しいとは思いますが、
引き続きお力添えいただければ幸いです。

  • 気になる質問をクリップする

    クリップした質問は、後からいつでもマイページで確認できます。

    またクリップした質問に回答があった際、通知やメールを受け取ることができます。

    クリップを取り消します

  • 良い質問の評価を上げる

    以下のような質問は評価を上げましょう

    • 質問内容が明確
    • 自分も答えを知りたい
    • 質問者以外のユーザにも役立つ

    評価が高い質問は、TOPページの「注目」タブのフィードに表示されやすくなります。

    質問の評価を上げたことを取り消します

  • 評価を下げられる数の上限に達しました

    評価を下げることができません

    • 1日5回まで評価を下げられます
    • 1日に1ユーザに対して2回まで評価を下げられます

    質問の評価を下げる

    teratailでは下記のような質問を「具体的に困っていることがない質問」、「サイトポリシーに違反する質問」と定義し、推奨していません。

    • プログラミングに関係のない質問
    • やってほしいことだけを記載した丸投げの質問
    • 問題・課題が含まれていない質問
    • 意図的に内容が抹消された質問
    • 過去に投稿した質問と同じ内容の質問
    • 広告と受け取られるような投稿

    評価が下がると、TOPページの「アクティブ」「注目」タブのフィードに表示されにくくなります。

    質問の評価を下げたことを取り消します

    この機能は開放されていません

    評価を下げる条件を満たしてません

    評価を下げる理由を選択してください

    詳細な説明はこちら

    上記に当てはまらず、質問内容が明確になっていない質問には「情報の追加・修正依頼」機能からコメントをしてください。

    質問の評価を下げる機能の利用条件

    この機能を利用するためには、以下の事項を行う必要があります。

質問への追記・修正、ベストアンサー選択の依頼

  • kuniku

    2017/11/10 17:13 編集

    A)PostgreSQL側で、max_connections の設定は?

    B)PostgreSQL側で、全てのSQLをログ出力できるようにして、validationQuery" value="SELECT 1 " が発行されているかどうか

    C) OS側のtcp timeoutが短すぎることはないか?

    キャンセル

回答 2

+3

validationQueryの SELECT 1 が発行されていることから
Spring側でgetConnectionしたときに、そのDBとのコネクションは正常と判断されていますね

その正常の後に、コネクションが切断されている可能性があります。

Spring側(tomcat dbcp)の

 initialSize=100
 maxActive=100
 maxIdle=100



PostgreSQLでの

 max_connections =100(デフォルト値)


で、アプリ側とDB側の値が同値になっています。

ここからは推測も含みますが、

PostgreSQLのドキュメント(バージョン9.4想定)
https://www.postgresql.jp/document/9.4/html/runtime-config-connection.html

PostgreSQLのスーパユーザによる接続のために予約されている接続"開口部(スロット)"の数
superuser_reserved_connections =3(デフォルト)
何時の時点にあっても、有効な接続数は、少なくともmax_connectionsから
superuser_reserved_connectionsを差し引いた数であって

なので、PostgreSQLのmax_connections=100がPostgreSQLのスーパユーザの接続数を含むため、
100-3=97 が外側(アプリケーションなど)からの最大接続可能数になるのではないかと推測。

Spring側を97以下にするか、PostgreSQL側を103以上にする必要があるのでは?
また、運用でのSQL実行やDBの正常確認もあること考慮すると、10くらいは余裕をもっておく方が良いかと思います。

投稿

編集

  • 回答の評価を上げる

    以下のような回答は評価を上げましょう

    • 正しい回答
    • わかりやすい回答
    • ためになる回答

    評価が高い回答ほどページの上位に表示されます。

  • 回答の評価を下げる

    下記のような回答は推奨されていません。

    • 間違っている回答
    • 質問の回答になっていない投稿
    • スパムや攻撃的な表現を用いた投稿

    評価を下げる際はその理由を明確に伝え、適切な回答に修正してもらいましょう。

  • 2017/11/15 16:10

    pring側(tomcat dbcp)とPostgreSQLの設定の最大コネクション数に
    余裕を持たせた状態で検証を実施いたしましたが、性能に差は出ませんでした。

    また、検証時(SQL発行時)にPostgreSQL側の
    ログの確認、sessionをモニタリングを行いましたが、
    特に異常は見られませんでした。

    キャンセル

  • 2017/11/16 10:57

    ・例外 「java.sql.SQLException: PooledConnection has already been closed.」が発生するのは、同じ箇所(特定のSQLや特定のロジック処理)で発生するのでしょうか?

    ・負荷相当の試験をされている時間は、どれくらいの時間やり続けて、どれくらいの割合で例外が発生するのでしょうか?

    ・何らかのSQLが異様に長く、それがqueryTimeout を起こしたり、DB側とのネットワークが切断されて、そのコネクションがコネクションプールに回収され、validationQueryやtestWhileIdle で例外が発生するのかな?(ネットワーク上のFWで接続状態が一定時間を超えると切断されることはあるのですが、getconnectionされるときにvalidationQueryでコネクションの正常かを判定して接続し直し、そのときコネクションが無効でも例外は発生しないので、そこではないと思っています)

    キャンセル

  • 2017/11/16 19:09

    データソース変更前(org.apache.tomcat.jdbc.pool.DataSource)の状況で、
    答えさせていただきます。

    ・例外 「java.sql.SQLException: PooledConnection has already been closed.」が発生するのは、
     同じ箇所(特定のSQLや特定のロジック処理)で発生するのでしょうか?
     ⇒同じ箇所で発生しているようです。

    ・負荷相当の試験をされている時間は、どれくらいの時間やり続けて、
     どれくらいの割合で例外が発生するのでしょうか?
     ⇒10秒間に100アクセスで1%前後のエラーが発生しております。


    ・何らかのSQLが異様に長く、それがqueryTimeout を起こしたり、
     DB側とのネットワークが切断されて、そのコネクションがコネクションプールに回収され、
     validationQueryやtestWhileIdle で例外が発生するのかな?
     (ネットワーク上のFWで接続状態が一定時間を超えると切断されることはあるのですが、
     getconnectionされるときにvalidationQueryでコネクションの正常かを判定して接続し直し、
     そのときコネクションが無効でも例外は発生しないので、そこではないと思っています)
     ⇒検証での実行SQLを精査しましたが、
      実行SQLには問題がなさそうでした。

    キャンセル

0

https://github.com/apache/tomcat を "PooledConnection has already been closed" で検索する限り、org.apache.tomcat.jdbc.pool.DisposableConnectionFacade  の以下の個所しかありませんでした。

try {
            return super.invoke(proxy, method, args);
        } catch (NullPointerException e) {
            if (getNext() == null) {
                if (compare(TOSTRING_VAL, method)) {
                    return "DisposableConnectionFacade[null]";
                }
                throw new SQLException(
                        "PooledConnection has already been closed.");
            }

            throw e;
        } finally {
            if (compare(CLOSE_VAL, method)) {
                setNext(null);
            }
        }


で、super.invoke は、org.apache.tomcat.jdbc.pool.JdbcInterceptor のここ。

@Override
    public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
        if (getNext()!=null) return getNext().invoke(proxy,method,args);
        else throw new NullPointerException();
    }


Connectionにインターセプタをかまして、closeが呼ばれたらコネクションをクローズせずにプールに戻すといったことをしているのだと思います。で、getNext()では次のインターセプタを取得しているのだと思います。それがnullだったと。ここで、以下の個所に注目しました。

        } finally {
            if (compare(CLOSE_VAL, method)) {
                setNext(null);
            }
        }


closeがよばれたら、次のインターセプタにnullを設定しています。
つまり、close()が既に呼び出されているとこのようなことが起こるのでは?ということです。
実際のデータベース接続の数とかは関係ないように見えます。

同時接続でおかしくなるとのことなので、Connectionをクラス変数にいれていて、別スレッドでcloseしているとかそういったバグがあるのではないかと思います。

投稿

  • 回答の評価を上げる

    以下のような回答は評価を上げましょう

    • 正しい回答
    • わかりやすい回答
    • ためになる回答

    評価が高い回答ほどページの上位に表示されます。

  • 回答の評価を下げる

    下記のような回答は推奨されていません。

    • 間違っている回答
    • 質問の回答になっていない投稿
    • スパムや攻撃的な表現を用いた投稿

    評価を下げる際はその理由を明確に伝え、適切な回答に修正してもらいましょう。

  • 2017/11/16 14:00

    なるほどです。
    connectionをThreadlocal 等に保持して、ServletFilterの最後にclose するようなシステムや、httpリクエストからThread生成などして、別処理を同時に実行(例えばログ出力)などあるかもしれないですね。

    キャンセル

  • 2017/11/16 18:11 編集

    さすがにトリッキーなことはしないと思っているんですが、Connectionをメンバー変数に持っているクラスが、

    1. 保持しているConnectionがnullだったら、getConnection()して保持
    2. 保持しているConnectionを使う
    3. Connectionをクローズして、保持内容をnullに初期化

    などをやっていて、インスタンスがシングルトンだった、とかなら起こりえると思います。
    ただ、それならNullPointerExceptionとかも出てもいいと思うんですけどね。

    キャンセル

  • 2017/11/16 19:00

    ご回答ありがとうございます。

    データベース接続の設定がおかしいとばかり
    考えておりましたが…
    一度調査してみます。ありがとうございます。

    キャンセル

15分調べてもわからないことは、teratailで質問しよう!

  • ただいまの回答率 87.50%
  • 質問をまとめることで、思考を整理して素早く解決
  • テンプレート機能で、簡単に質問をまとめられる

関連した質問

同じタグがついた質問を見る