はじめに
先日、Tomcat 7からTomcat 9へのメジャーバージョンアップを実施しました。
アプリケーションのコード自体はJavaのバージョンアップに伴う修正を行い、テスト環境での動作確認もパスして無事リリース…と思った矢先、トラブルが発生しました。
環境
移行前 : Tomcat 7 (Java 7)
移行後 : Tomcat 9 (Java 11)
DB : PostgreSQL 16
接続プール: Tomcat標準のDataSource (DBCP)トラブル発生-サイトが落ちる
リリース直後のアクセスが少ない時間帯は問題なかったのですが、ユーザーのアクセスが増え始めた頃、突然サイトのレスポンスが悪化し、最終的には接続エラーが多発してサイトがダウンしてしまいました。
アプリケーションログに特にエラーは出ておらず、Tomcatのログにも特別な異常は見当たりませんでした…。
原因は何なのか?と思い調査を開始しました。
調査を進める中で、Tomcatの起動ログに以下のような警告メッセージが出ていることに気付きました。
警告 [main] java.util.ArrayList.forEach Name = datasource Property maxActive is not used in DBCP2, use maxTotal instead. maxTotal default value is 8. You have set value of "100" for "maxActive" property, which is being ignored.
警告 [main] java.util.ArrayList.forEach Name = datasource Property maxWait is not used in DBCP2 , use maxWaitMillis instead. maxWaitMillis default value is PT-0.001S. You have set value of "10000" for "maxWait" property, which is being ignored.もしかして、これが原因か…!?
原因調査-設定は合っているはずなのに?
「DB接続プールが足りていないのか?」と思い、context.xml の設定を確認しました。
しかし、設定ファイルには以下のように十分な接続数を確保する設定が記述されていました。
<!-- Tomcat 7時代の設定 -->
<Resource name="jdbc/MyDB"
auth="Container"
type="javax.sql.DataSource"
...
maxActive="100"
maxWait="10000"
... />maxActive="100" と設定しているので、100本までは接続が作られるはずです。
しかし、データベース側の接続数を確認すると、そこまで接続が増えていないにも関わらず、アプリケーション側では接続が取れていなさそうなのです。
原因- Tomcat 9のデフォルトDBCPは設定項目名が違う
調査を進めると、Tomcat 9のドキュメントにある重要な記述にたどり着きました。
NOTE: The default data source support in Tomcat is based on the DBCP 2 connection pool from the Commons project.
Tomcat 7では標準の接続プールとして Commons DBCP 1.x が使われていましたが、Tomcat 8以降(Tomcat 9含む)では Commons DBCP 2.x が標準になっています。
そして、DBCP 1.x と DBCP 2.x では、設定プロパティ名に互換性がありません。
| 設定項目 | Tomcat 7 (DBCP 1.x) | Tomcat 9 (DBCP 2.x) |
|---|---|---|
| 最大アクティブ接続数 | maxActive | maxTotal |
| 最大待機時間 | maxWait | maxWaitMillis |
つまり、移行時に考慮できていなかった maxActive="100" はTomcat 9(DBCP 2)では未知のプロパティとして無視されていたのです。
その結果、DBCP 2のデフォルト値である maxTotal="8" が適用されてしまい、たった8本の接続が埋まった時点で後続のリクエストが待たされ、サイトがダウンしていたというのが原因でした。
解決策
context.xml の設定項目名を、新しいDBCP 2の仕様に合わせて修正しました。
<!-- Tomcat 9 (DBCP 2) 用の設定 -->
<Resource name="jdbc/MyDB"
auth="Container"
type="javax.sql.DataSource"
...
maxTotal="100"
maxWaitMillis="10000"
... />これにより、設定通り100本まで接続が拡張されるようになり、サイトは安定稼働を取り戻しました。
やったぜ!
さて、この経験を踏まえて、手元で動かせるサンプルを用意しましたので、以下で紹介します。
付録:手元で動かせるサンプル
Tomcat 9とPostgreSQLをDockerで立ち上げ、正しい設定が反映されているか確認できるサンプルを用意しました。
必要なもの
Docker
Docker Compose※今回は、Windows11 + WSL2 環境で動作確認しています。
使い方
- 以下リポジトリをクローンします。
- tomcat9-dbcp-test / katsuobushiFPGA
https://github.com/katsuobushiFPGA/tomcat9-dbcp-test
git clone https://github.com/katsuobushiFPGA/tomcat9-dbcp-test.git- コンテナを起動します。
docker-compose up -d --build- ブラウザで
http://localhost:8080/にアクセスします。
画面に以下のように表示されれば成功です。
- DataSource Class:
org.apache.tomcat.dbcp.dbcp2.BasicDataSource - maxTotal (configured):
100 - maxWaitMillis (configured):
10000 - Connection successful!
もし context.xml を書き換えて maxActive に変更して再起動すると、maxTotal がデフォルト値(8)に戻ってしまう挙動も確認できます。
同時接続テスト
設定値が正しく効いているか、実際に負荷をかけて確認するためのスクリプト test_concurrency.py も用意しました。
このスクリプトは、指定した数の同時リクエストを送信し、サーバー側で2秒間DB接続を保持(スリープ)させることで、接続プールを意図的に埋めるテストを行います。
実行方法
Python環境がない場合でも、Dockerコンテナ内で実行できるようにしてあります。
# Dockerコンテナ内で実行する場合
docker compose exec tester python test_concurrency.py 120ローカルにPython環境がある場合は、直接実行することも可能です。
# ローカルで実行する場合
python3 test_concurrency.py 120結果の確認
成功パターン(設定が正しい場合)
maxTotal="100" で120並列のリクエストを投げても、maxWaitMillis(10秒)以内に空きが出れば全員成功します。
Test finished in 4.xx seconds
Total Requests: 120
Success: 120
Errors: 0失敗パターン(設定ミスを再現)
context.xml を編集して maxTotal を maxActive に書き換え、Tomcatを再起動してからテストします。
デフォルトの maxTotal="8" になるため、大量のリクエスト(例: 100)を投げると待機タイムアウトが発生します。
python3 test_concurrency.py 120...
Thread 15 failed: Content check failed
Thread 22 error: HTTP Error 500: Internal Server Error
...
Success: 45
Errors: 55このようにして、設定ミスによる障害をローカル環境で再現・検証することができます。
参考
Apache Tomcat 9.0 - JNDI Resources HOW-TO
https://tomcat.apache.org/tomcat-9.0-doc/jndi-resources-howto.htmlApache Commons DBCP – Apache Commons DBCP
https://commons.apache.org/proper/commons-dbcp/
おわりに
ミドルウェアのバージョンアップでは、アプリケーションコードの修正だけでなく、設定ファイルや依存するライブラリ(今回はDBCP)の仕様変更にも注意が必要と身に染みて思いました。
特に「設定エラーにならずに、デフォルト値で動いてしまう」ケースは発見が遅れがちなので、負荷テストなどで設定値通りに動作しているか確認することが重要だと痛感しました。
移行時には最も気をつけたい部分ですね。。。
今回の経験が、同様の移行を検討している方々の参考になれば幸いです。