コネクションプールの挙動差分によるバグ顕在化

この記事は Java EE Advent Calendar 2016の12/2分の記事です。
明日は@opengl_8080さんです。


Java EEが使われているシステムは、改修を加え続けながら数年〜十年と運用し続けるライフサイクルの長いシステムが多くあります。

アプリケーションを全面刷新することはなくても、ハードウェアやOS、ミドルウェアのEOSLを契機にJava EEサーバのバージョンを上げる、いわゆる『更改』という作業は色々な所で行われていると思います。

更改で厄介なのは、OSやミドルウェアのリリースノートや非互換ガイドに記載されていない『些細なバージョン間差分』です。本来であれば些細なバージョン間差分はアプリケーションの振る舞いに影響を与えないものですが、モノによってはバグを顕在化させ、たまたま動作していたものが、バージョンアップすると動かなくなったり、リソースリークを発生させたりします。

コネクションプールの些細な挙動差分による、バグ顕在化の例を以下にまとめます。

WildFlyバージョン間のコネクションプール挙動差分

データソースからコネクションを取得する良くあるコードを考えます。

DataSource ds = ...;
try (Connection conn = ds.getConnection()) {
    System.out.println(conn);
    // SQLの実行...

WildFlyはバージョンにより、コネクションプールの払い出しポリシーが異なります。

  • FIFO(First In First Out)
    • プールに返されたコネクションから再払い出し
    • 古いコネクションがプールの残るため、一定時間アイドル後の切断設定(idle-timeout-minutes)により切断されやすい
  • FILO(First In Last Out)
    • 前回の払い出しから最も時間の経っているコネクションから再払い出し
    • idle-timeout-minutesの契機で切断されにくい
バージョン コネクションプールの払い出しポリシー
JBoss AS 7.1.1 FIFO
WildFly 8.x FILO
WildFly 9.0.0〜9.0.1 FIFO
WildFly 9.0.2 FILO
WildFly 10.x〜 FILO
参考: Tomcat8.5.x (DBCP) FIFO (lifo=falseの追加によりFILOに変更可能)
参考: Tomcat8.5.x (Tomcat JDBC) FIFO

通常はプールの払い出し順序が変わっても、アプリケーションの振る舞いに影響はありません。払い出し順序はJava EE仕様や実装製品固有の仕様で規定されているものでもないため、特定の払い出し順序を期待すること自体、あまり良くないことです。

しかし、APサーバと連携するDBサーバのリソースリークや、アプリケーション自体の潜在的な問題を露にさせることもあります。

PostgreSQL側のメモリリークが顕在化

PostgreSQLには以下で紹介されているように、create temporary tableとdrop temporary tableを同一セッションで繰り返すと、メモリリークする不具合があります。
Memory leak in PL/pgSQL function which CREATE/SELECT/DROP a temporary table

psコマンドで該当のセッションに対応するプロセスのRSSモニタリングすると徐々に上がっていきます。

# コネクションごとのステータスが書かれている子プロセスのRSSが徐々に上がる
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
postgres  5994  0.0  0.2 338948  4004 ?        Ss   07:21   0:00 postgres: postgres test 127.0.0.1(59780) idle

コネクションプールの最小値と最大値を一般的に推奨される同一値に設定したJBoss AS7を、最新のWIldFly10.x系にバージョンアップすると、このメモリリークが顕在化しやすくなります。

JBoss AS7のプール払い出しポリシーはFIFOのため、古いコネクションがプール中に残りやすく、idle-timeout-minutesに到達して定期的に切断され、PostgreSQL側はセッションの終了と共にメモリが解放されます。

一方、WildFly10.x系ではFILOのため、プール中のコネクションは均等に払い出され、アイドル時間が短くなる傾向になります。idle-timeout-minutesに引っかかるコネクションが減り、結果的にPostgreSQL側でセッションごとの子プロセス終了が発生しにくく、メモリリークが顕在化しやすくなります。

対処

WildFlyには設定によってプールの払い出し順序を変更するオプションがあります。

WildFly10.xおよびJBossEAP7.xの場合
JBoss CLIで以下のように設定すると、プール払い出しポリシーがデフォルトのFILOからFIFOに変更されます。

/subsystem=datasources/data-source=データソース名:write-attribute(name=capacity-decrementer-class,value=org.jboss.jca.core.connectionmanager.pool.capacity.TimedOutFIFODecrementer)

上記のCLIはstandalone-xxx.xmlにcapacityの子要素として反映されます。

<datasource jndi-name="java:jboss/jdbc/testDS" pool-name="testDS" enabled="true">
    <connection-url>jdbc:postgresql://localhost:5432/test</connection-url>
    ...
    <capacity>
        <decrementer class-name="org.jboss.jca.core.connectionmanager.pool.capacity.TimedOutFIFODecrementer"/>
    </capacity>

JBoss EAP 6.4.2 以降の場合
有償版のJBoss EAP 6.4系のデフォルトのプール払い出しポリシーはFILOですが、以下のissueによりFIFOに変更できるオプションが6.4.2より追加されています。
[JBJCA-1260] Allow System Property to override default First In First Out (FIFO) pooling behavior - JBoss Issue Tracker

プール払い出しポリシーをFIFOに変更するためには、Javaシステムプロパティに ironjacamar.filo_pool_behavior=true を設定します。

$JBOSS_HOME/bin/standalone.conf

if [ "x$JAVA_OPTS" = "x" ]; then
   JAVA_OPTS="-Xms1303m -Xmx1303m -XX:MaxPermSize=256m -Djava.net.preferIPv4Stack=true"
   ...
   JAVA_OPTS="$JAVA_OPTS -Dironjacamar.filo_pool_behavior=true"

トランザクション設定のミスが顕在化

プールの払い出し順序の変更は、アプリケーションの潜在的なバグを顕在化させ、処理が正常に動作しない事象を引き起こすこともあります。

以下の例はSpringの誤ったトランザクションの設定例です。本来は同一トランザクションでSELECT ... FOR UPDATEによる悲観ロックの取得と更新を実行したいところです。以下のコードでは、privateメソッドに設定された@Transactionalは意味がなく、lock()メソッドとupdate()メソッドは別々のトランザクション、別々のDBコネクション(DBセッション)で動作します。しかし、プールの挙動がFIFOであるJBoss AS7以前にデプロイして動作させると、並行リクエストがない低負荷な状態ではプールに返した直後のコネクションが再度払い出されるため、擬似的にトランザクションが継続したのと同様に振る舞います。

WildFlyのバージョンを上げると、続けて実行されたDataSource.getConnection()が同一のコネクションを返さなくなる為、ロックを取得した状態のコネクションが再取得されません。既に別コネクションで悲観ロックが取得されているため、UPDATE文はロック待ちとなり、タイムアウトまで一時的にハングアップしたように見えます。

@Service
public class SampleService {
    public void doSomething() {
        lock();
        update();
    }

    @Transactional
    private void lock() {
        // 悲観ロックの取得
        // Connection conn = dataSource.getConnection();
        // SELECT ... FOR UPDATE
    }

    @Transactional
    private void update() {
        // ロックしたレコードの更新
        // Connection conn = dataSource.getConnection();
        // UPDATE ... SET ...
    }
}
対処

これは単純にアプリケーションのミスであるため、アプリケーションを改修します。

@Service
public class SampleService {
    @Transactional
    public void doSomething() {
        lock();
        update();
    }

    private void lock() {...}
    private void update() { ... }
}

まとめ

バージョンアップに伴う些細な差分がバグを顕在化させる例を紹介しました。

このような一定の仕様範囲の些細な実装差分は、ドキュメントに記載されていることも少なく、突然遭遇します。少しでもこのような問題を避けるためには、以下のようなことに注意します。

  • ドキュメントやAPI仕様に書いていない振る舞いには期待しない
    • 例えばjava.sql.DataSourceインタフェースのAPI仕様には払い出し順序に関する言及はありません
  • APサーバの内部クラスに依存させない
    • 可能な限りjavax.xxxパッケージのJava EEの範囲でコードを書く
    • org.jbossなどの実装依存のクラスを利用する際は、互換性に強く期待しない

上記を守っていても、問題を必ず避けられるわけではありません。
普段から対象製品のログレベルの詳細化方法やソースコードの入手、jdbによるデバッグに慣れておくことで、問題に遭遇しても、すぐに原因を特定できるような準備が大切です。