TomcatのDBコネクションが8個までしか増えない謎を追う ～ あるOSSサポートエンジニアの1日

「TomcatのDBコネクションが8個しかできないんだけど、なんで？？」

そんな質問があり、原因を調査しました。意外なオチだったので、そのときの記録をここに残します。

この質問とともに受け取ったcontext.xmlには以下のような定義がありました。

<Resource name="jdbc/MyDB"
          auth="Container"
          type="javax.sql.DataSource"
          driverClassName="com.mysql.jdbc.Driver"
          factry="org.apache.tomcat.jdbc.pool.DataSourceFactory"
          url="jdbc:mysql://dbserver.example.com:3306/db4app"
          username="dbuser"
          password="xxxxxxxxxx"
          initialSize="20"
          maxActive="20" />

Tomcatを起動したら、コネクションプールにコネクションが20個できると思ったのに、8個しかできないとのこと。確かにこの設定であれば、initialSizeとmaxActiveが20なので、起動中に20個のコネクションが生成されて、その後も20個のまま増減しないはずです。

問題を整理する

この質問を受けて、まず疑問に思ったのは「質問者がどのようにコネクション数を確認したのか？」ということです。何をもとに「8個しかできない」と判断したのかは不明確だったので、それについて聞いてみることにしました。

すると、以下のコマンドをDB（MySQL）に発行して、確認しているとのこと。

mysql> show processlist;
+------+--------+---------------------------------+--------+---------+------+-------+------------------+
| Id   | User   | Host                            | db     | Command | Time | State | Info             |
+------+--------+---------------------------------+--------+---------+------+-------+------------------+
| 1142 | root   | localhost                       | NULL   | Query   |    0 | NULL  | show processlist |
| 1614 | dbuser | application.example.co.jp:37110 | db4app | Sleep   |  746 |       | NULL             |
| 1615 | dbuser | application.example.co.jp:37111 | db4app | Sleep   |  746 |       | NULL             |
| 1616 | dbuser | application.example.co.jp:37112 | db4app | Sleep   |  746 |       | NULL             |
| 1617 | dbuser | application.example.co.jp:37113 | db4app | Sleep   |  746 |       | NULL             |
| 1618 | dbuser | application.example.co.jp:37114 | db4app | Sleep   |  746 |       | NULL             |
| 1619 | dbuser | application.example.co.jp:37115 | db4app | Sleep   |  746 |       | NULL             |
| 1620 | dbuser | application.example.co.jp:37116 | db4app | Sleep   |  746 |       | NULL             |
| 1621 | dbuser | application.example.co.jp:37117 | db4app | Sleep   |  746 |       | NULL             |
+------+--------+---------------------------------+--------+---------+------+-------+------------------+
9 rows in set (0.00 sec)

show processlist;の結果にはクライアントからのコネクションの数だけレコードが含まれるので、確認の仕方は間違っていないはずです。initialSizeが20なのに、アプリケーションからのコネクションを表すレコードが8件しかない（※）のは明らかにおかしいです。

※：上記レコードは9件ですが、このうちshow processlist;を実行するコネクションの1レコードを除くと8件になります。

そして、次に思いついた可能性は、「そもそも見ている設定ファイルが違うのでは」ということでした。しかし、そうではないようです。というのも、context.xmlのinitialSizeを1に設定すると上記コマンドは1件のレコードを返し、5に設定すると5件、8に設定すると8件のレコードを返すからです。そして、不思議なことに、9以上に設定しても8件のまま変化しないというのです。

• initialSize = "1"：コネクション数 1
• initialSize = "3"：コネクション数 3
• initialSize = "5"：コネクション数 5
• initialSize = "8"：コネクション数 8
• initialSize = "9"：コネクション数 8
• initialSize ="20"：コネクション数 8

つまり、context.xmlのinitialSizeが効いていることは間違いないのですが、maxActiveではない何かが8件を超えるコネクションの生成を制限しているということになります。

試す

念の為、実際にローカル環境でも試してみることにしました。MySQLにJDBC接続する定義が既にcontext.xmlに記載されているWebアプリが手元にあったので、接続URL（url）などの定義はそのまま残し、それ以外を受け取ったcontext.xmlと同じになるように修正してみました（initialSizeとmaxActiveを20に修正し、残りのminIdleなどの定義は削除）。そして、Tomcatを起動し、確認してみました。が、やはり事象は再現せず、コマンドを実行すると、20件のレコードが返ってきました。

「ということは、Tomcatではなく、MySQLサーバー側でクライアントが扱えるコネクション数を制限をしているのでは？」

MySQLサーバーが制限しているとすれば、MySQLのコマンドライン・クライアントでも同じ問題が発生するはずです。そこで、クライアントを同時に9つ起動して、MySQLサーバーに接続してみるようにお願いしてみました。すると、Tomcatのときとは異なり、コマンドは9件のレコードを返したとの回答が返ってきました。

確かにMySQL側でmax_connectionsなどのパラメーターで制限しているのであれば、Tomcatにはエラーが返り、ログに何らかの情報（Too many connectionsのようなメッセージ）が出力されるはずです。しかし、ログには関連しそうなメッセージが何も出力されていませんでした。

ググる

「TomcatでもMySQLでもない？もしかして、ORマッパーやアプリに特殊な仕組みが？それともファイアウォールが切断している？」

いろいろな可能性に頭をめぐらせてみましたが、8というのがどうもひっかかります。そこで、「"8 connections" "initialSize" "show processlist"」のキーワードでググってみることにしました。すると、同様の現象に遭遇している人の質問がStackOverflowに見つかりました。

• Tomcat 8 - MySQL at most 8 connections seen in MySQL Workbench from each tomcat instace

• initialSize == 1 - at Tomcat startup 1 connections are created
• initialSize == 5 - at Tomcat startup 5 connections are created
• initialSize >= 9 - at Tomcat startup 8 connections are created

「まさにこれだ！」そう思ったのですが、この質問とは全く一致しない条件が1つありました。

それは、StackOverflowの質問者が「Commons DBCP」を使用しているのに対し、我々は「Tomcat JDBC Connection Pool」を使っているということです。TomcatのDBコネクションプールには2種類あり、古いバージョンで使用されていた「Commons DBCP」と新しいバージョンで使用されている「Tomcat JDBC Connection Pool」があります。

最初に載せたcontext.xmlを見ると分かりますが、以下の定義があると、

factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"

「Tomcat JDBC Connection Pool」が使用されるため、残念ながらこのページの回答にある「「Commons DBCP」のmaxTotalが未設定であるためにデフォルトの8で制限されるので、maxTotalを指定しろ」という対策は、今回のケースには適用できないはずです。

とは言え、事象があまりにも似ていて、すぐにはこのStackOverflowのページから離れることができずにいましました。「「Commons DBCP」が使われているなら、つじつまがあうのに...」

謎が解ける

「もしかして、質問者が古いバージョンを使っている？」と一瞬思いましたが、context.xmlとともに受け取っていたTomcatのログから、使用しているバージョンが7.0.92であることは確かなので、その可能性はありません。

2019/08/27 15:44:34 org.apache.catalina.startup.VersionLoggerListener log
情報: Server version:        Apache Tomcat/7.0.92

「Tomcat JDBC Connection Pool」が導入されたのがバージョン7であることは、何度も見た＠ITの記事（以下）で知っていました。

• Tomcat 7の新機能で何ができるようになるのか？（番外編）：Commons DBCPを超えるTomcat JDBC Poolとは (1/2)

他に「Commons DBCP」が使用される可能性はないのでしょうか？

「両者を切り替える定義はこの1行だけだったはず...」

factory="org.apache.tomcat.jdbc.pool.DataSourceFactory"

「そして、受け取ったcontext.xmlにもこの定義があったはず...」

factry="org.apache.tomcat.jdbc.pool.DataSourceFactory"

「ん...んん...ん？...」

つまり、typoによりこの定義が無視され、意図せず「Commons DBCP」が使用されてしまい、未指定のmaxTotalのデフォルト値8が機能することで、コネクションは8件までしか生成されなかった、というわけです。そして、コネクションの最大数の設定は「Commons DBCP」がmaxTotal、「Tomcat JDBC Connection Pool」がmaxActiveで異なるのに対し、コネクションの初期数の設定はinitialSizeで同じなこともこの不思議な挙動を演出していたことになります。

後で考えてみると、JMXクライアント（JConsoleなど）でコネクションプールの属性値を取得してもらった方が、maxTotalになっていることにもっと早く気づいたかもしれません。原因が分かってみれば、そんなことも思ったりしますが...

最後に

実はこのページの最初に書いた設定もfactryとなっていたんですが、気づかれた方はいたでしょうか？よくあることですが、みなさん、typoには気をつけましょう。こういう場合は、正確性の高いサイト（Tomcatの公式ドキュメントとか）からのコピペが確実ですね。