読者です 読者をやめる 読者になる 読者になる

かんがるーさんの日記

最近自分が興味をもったものを調べた時の手順等を書いています。今は Spring Boot をいじっています。

Spring Boot 1.3.x の Web アプリを 1.4.x へバージョンアップする ( その22 )( application.properties に記述する `spring.datasource.tomcat.~` の設定を見直す )

概要

記事一覧はこちらです。

Spring Boot 1.3.x の Web アプリを 1.4.x へバージョンアップする ( その21 )( Log4jdbc Spring Boot Starter を入れてみる ) の続きです。

  • 今回の手順で確認できるのは以下の内容です。
    • Tomcat JDBC Connection Pool の設定項目である spring.datasource.tomcat.~ について、現在 url, username, password, driverClassName しか設定していないので、他に設定すべき項目を確認して設定します。

参照したサイト・書籍

  1. The Tomcat JDBC Connection Pool
    https://tomcat.apache.org/tomcat-8.5-doc/jdbc-pool.html

  2. Tomcat JDBC Connection Poolの存在を忘れてました
    http://qiita.com/uzresk/items/d9e1b46014809094b10d

  3. Tomcat JDBC Connection Pool configuration for production and development
    http://www.codingpedia.org/ama/tomcat-jdbc-connection-pool-configuration-for-production-and-development/

  4. Commons DBCPを超えるTomcat JDBC Poolとは
    http://www.atmarkit.co.jp/ait/articles/1111/07/news212.html

目次

  1. jconsole で Tomcat JDBC Connection Pool の状況を確認する
  2. initialSize, maxActive, maxIdle, minIdle
  3. testOnBorrow, validationQuery, validationQueryTimeout
  4. removeAbandoned, removeAbandonedTimeout
  5. ここまでの設定が反映されているか jconsole で確認する
  6. SlowQueryReport を使用してスロークエリーをログに出力する
  7. 次回は。。。

手順

jconsole で Tomcat JDBC Connection Pool の状況を確認する

今の設定での Tomcat JDBC Connection Pool の他の設定項目の値を確認するために jconsole で MBean の値を見ようとしたのですが、以外に時間がかかりました。結論としては、

  • application.properties に設定する spring.datasource.jmx-enabled はデフォルト値が false なので true にする必要があります。またこの設定は spring.datasource.tomcat.jmx-enabled という名前にしてはいけません。IntelliJ IDEA で補完表示されるのですが設定しても全く意味がありません。
  • Log4jdbc Spring Boot Starter の AutoConfiguration が有効な場合、Tomcat JDBC Connection Pool の MBean インターフェースが登録されず、jconsole に表示されません。

まず Spring Boot Reference Guide の Appendix A. Common application properties を見ると spring.datasource.jmx-enabled=false と記述されています。デフォルト値が false なので true にします。

src/main/resources/application.properties に設定を追加します。spring.datasource.~ の設定は spring.datasource.tomcat.~ に変更していたので、最初 spring.datasource.tomcat.jmx-enabled=true と書きました。IntelliJ IDEA でも以下のように補完表示されます。

f:id:ksby:20170415211303p:plain

しかし、この設定だけ書いた状態では jconsole に Tomcat JDBC Connection Pool らしき情報が表示されません。

コマンドプロンプトを起動後、jconsole コマンドを実行します ( jconsole は C:\Java\jdk1.8.0_121\bin の下にあります )。

f:id:ksby:20170415220116p:plain

ローカル・プロセス一覧から ksbysample-webapp-lending を選択します。

f:id:ksby:20170415220257p:plain

メイン画面が表示されたら「MBeans」タブをクリックし MBean 一覧を表示しますが、画面左側のツリーに Tomcat JDBC Connection Pool らしき情報が表示されません。

f:id:ksby:20170415220444p:plain

MBean インターフェイスを登録している場所を探したら org.springframework.boot.autoconfigure.jdbc.DataSourceAutoConfiguration の中の TomcatDataSourceJmxConfiguration#dataSourceMBean でした。以下のようにブレークポイントを設定して IntelliJ IDEA から debug 実行したところ、ブレークポイントで停止しませんでした。。。

f:id:ksby:20170415210257p:plain

f:id:ksby:20170415211916p:plain

TomcatDataSourceJmxConfiguration クラスに付いているアノテーションを見ると @ConditionalOnProperty(prefix = "spring.datasource", name = "jmx-enabled") と書かれていました。ここで jmx-enabled は spring.datasource.jmx-enabled=true と記述しないといけないことに気づきます。

src/main/resources/application.properties に記述する設定を spring.datasource.jmx-enabled=true に変更したのですが、やはり jconsole に表示されません。今度は debug 実行すると上で設定した TomcatDataSourceJmxConfiguration#dataSourceMBean のブレークポイントで止まるのですが、if (dataSource instanceof DataSourceProxy) の条件を満たしていないのか if 文の中の処理が実行されません。

再度 debug 実行して dataSource がどうなっているのか見てみたところ、DataSourceProxy クラスのインスタンスではなく log4jdbc が提供する DataSourceSpy クラスのインスタンスになっていました。if 文の中の処理が実行されないはずです。

f:id:ksby:20170415222433p:plain

Log4jdbc Spring Boot Starter を無効にするために src/main/resources/application.properties に spring.autoconfigure.exclude=com.integralblue.log4jdbc.spring.Log4jdbcAutoConfiguration を書いて debug 実行したところ、今度は TomcatDataSourceJmxConfiguration#dataSourceMBean の if 文の中の処理が実行されました。

f:id:ksby:20170415223106p:plain

jconsole にも org.apache.tomcat.jdbc.pool.jmx という名前で Tomcat JDBC Connection Pool の情報が表示されました。これで現在の設定値が確認できます。

f:id:ksby:20170416003124p:plain f:id:ksby:20170416003213p:plain

デフォルトの設定が書かれているクラスがどれか確認してみたところ org.apache.tomcat.jdbc.pool.PoolProperties でした。これを探すのに IntelliJ IDEA 2017.1 から新しくなった Find in Path を使いましたが、以前のツリー表示と違い1画面内でヒットしたソースが確認できてレスポンスもよく、使い勝手が非常に良くなっています。

f:id:ksby:20170415230024p:plain

initialSize, maxActive, maxIdle, minIdle

DB とのコネクション数を設定します。以下の方針で設定します。

  • initialSize, minIdle のデフォルト値は 10 ですが、product プロファイル以外では 1 にします。product プロファイルではデフォルト値の 10 にします。
  • maxActive, maxIdle はデフォルト値の 100 のままにします。
  • initialSize, maxActive, maxIdle, minIdle は application.properties, application-product.properties に明記することにします。

■application.properties

spring.datasource.tomcat.initialSize=1
spring.datasource.tomcat.maxActive=100
spring.datasource.tomcat.maxIdle=100
spring.datasource.tomcat.minIdle=1

■application-product.properties

spring.datasource.tomcat.initialSize=10
spring.datasource.tomcat.maxActive=100
spring.datasource.tomcat.maxIdle=100
spring.datasource.tomcat.minIdle=10

testOnBorrow, validationQuery, validationQueryTimeout

プールからコネクションを取得する時に有効性が検証されるようにします。この設定は application.properties にのみ設定します。

■application.properties

spring.datasource.tomcat.testOnBorrow=true
spring.datasource.tomcat.validationQuery=select 1
spring.datasource.tomcat.validationQueryTimeout=5

removeAbandoned, removeAbandonedTimeout

クローズ漏れのコネクションが自動検知されるようにします。

  • application.properties にのみ設定します。
  • removeAbandonedTimeout のデフォルト値は 60秒ですが、30秒にします。

■application.properties

spring.datasource.tomcat.removeAbandoned=true
spring.datasource.tomcat.removeAbandonedTimeout=30

ここまでの設定が反映されているか jconsole で確認する

application.properties に spring.autoconfigure.exclude=com.integralblue.log4jdbc.spring.Log4jdbcAutoConfiguration を追加してから develop プロファイルで Tomcat を起動した後、jconsole で確認します。

全ての設定が反映されていることが確認できます。

f:id:ksby:20170416012752p:plain f:id:ksby:20170416012855p:plain

SlowQueryReport を使用してスロークエリーをログに出力する

Tomcat JDBC Connection Pool にはスロークエリーを検知する仕組みがあるようなので試してみます。スロークエリーを検知したら専用のログファイルに出力させてみます。

  1. src/main/resources の下の application.properties を リンク先のその1の内容 に変更します。

  2. src/main/resources の下の application-product.properties を リンク先のその1の内容 に変更します。

  3. src/main/resources の下の logback-spring.xmlリンク先の内容 に変更します。

  4. src/main/resources の下の logback-product.xmlリンク先の内容 に変更します。

  5. clean タスク → Rebuild Project → build タスクを実行して ksbysample-webapp-lending-1.4.5-RELEASE.jar を作成します。

    f:id:ksby:20170418233200p:plain

  6. C:\project-springboot\ksbysample-webapp-lending\build\libs\ksbysample-webapp-lending-1.4.5-RELEASE.jar を C:\webapps\ksbysample-webapp-lending\lib の下へコピーします。

  7. C:\webapps\ksbysample-webapp-lending\bat\webapp_startup.bat の中の set WEBAPP_JAR=ksbysample-webapp-lending-1.4.5-RELEASE.jar に変更します。

  8. webapp_startup.bat を実行します。

    f:id:ksby:20170419000837p:plain

    slow-query.log が作成されます。

    f:id:ksby:20170419001119p:plain

  9. ログインして検索対象図書館登録画面から図書館を登録すると、slow-query.log に以下のように出力されました。

    f:id:ksby:20170419002654p:plain

    • SQL の末尾に time=1 ms; のように実行時間が出力されます。
    • ログは WARN レベルで出力されます。
    • SQL のパラメータの部分は “?” のまま出力されます。
  10. Ctrl+C を押して webapp_startup.bat を停止します。

  11. スロークエリーに出力される条件は 5秒に変更しておきます。src/main/resources の下の application.properties を リンク先のその2の内容 に変更します。

次回は。。。

application.properties の最終形、application-product.properties の最終形を記載します。

次回は、

  • ログイン画面で何も入力せずに「ログイン」ボタンをクリックすると “500 Internal Server Error” になることに気付いたので、修正します。
  • Spring Security 関連で修正した方がよい箇所があれば見直します。
  • その後で jar ファイルを作成して動作確認して終わりに向かう予定です。

ソースコード

application.properties

■その1

spring.datasource.tomcat.jdbc-interceptors=SlowQueryReport(threshold=0)
  • spring.datasource.tomcat.jdbc-interceptors=SlowQueryReport(threshold=0) を追加します。まずは全てのクエリーをログに出力したいので、スロークエリーの基準は 0 ミリ秒 ( threshold=0 ) にします。

■その2

spring.datasource.tomcat.jdbc-interceptors=SlowQueryReport(threshold=5000)

■最終形

doma.dialect=org.seasar.doma.jdbc.dialect.PostgresDialect

spring.datasource.tomcat.url=jdbc:postgresql://localhost/ksbylending
spring.datasource.tomcat.username=ksbylending_user
spring.datasource.tomcat.password=xxxxxxxx
spring.datasource.tomcat.driverClassName=org.postgresql.Driver
spring.datasource.tomcat.initialSize=1
spring.datasource.tomcat.maxActive=100
spring.datasource.tomcat.maxIdle=100
spring.datasource.tomcat.minIdle=1
spring.datasource.tomcat.testOnBorrow=true
spring.datasource.tomcat.validationQuery=select 1
spring.datasource.tomcat.validationQueryTimeout=5
spring.datasource.tomcat.removeAbandoned=true
spring.datasource.tomcat.removeAbandonedTimeout=30
spring.datasource.tomcat.jdbc-interceptors=SlowQueryReport(threshold=5000)
# spring.datasource.jmx-enabled は spring.datasource.tomcat.jmx-enabled と書かないこと。
# spring.datasource.tomcat.jmx-enabled だと機能しない。
spring.datasource.jmx-enabled=true

spring.session.store-type=redis

spring.freemarker.cache=true
spring.freemarker.charset=UTF-8
spring.freemarker.enabled=false
spring.freemarker.prefer-file-system-access=false

application-product.properties

■その1

server.tomcat.basedir=C:/webapps/ksbysample-webapp-lending
logging.file=${server.tomcat.basedir}/logs/ksbysample-webapp-lending.log
slowquery.logging.file=${server.tomcat.basedir}/logs/slow-query.log
  • slowquery.logging.file=${server.tomcat.basedir}/logs/slow-query.log を追加します。

■最終形

server.tomcat.basedir=C:/webapps/ksbysample-webapp-lending
logging.file=${server.tomcat.basedir}/logs/ksbysample-webapp-lending.log
slowquery.logging.file=${server.tomcat.basedir}/logs/slow-query.log

spring.autoconfigure.exclude=com.integralblue.log4jdbc.spring.Log4jdbcAutoConfiguration
spring.datasource.tomcat.initialSize=10
spring.datasource.tomcat.maxActive=100
spring.datasource.tomcat.maxIdle=100
spring.datasource.tomcat.minIdle=10

spring.mail.host=localhost
spring.mail.port=25

spring.rabbitmq.host=localhost
spring.rabbitmq.port=5672

spring.redis.sentinel.master=mymaster
spring.redis.sentinel.nodes=localhost:6381,localhost:6382,localhost:6383

logback-spring.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>

    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${CONSOLE_LOG_PATTERN}</pattern>
            <charset>UTF-8</charset>
        </encoder>
    </appender>

    <if condition='"${spring.profiles.active}" == "product"'>
        <then>
            <property name="LOG_FILE" value="${LOG_FILE}"/>
            <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
                <encoder>
                    <pattern>${FILE_LOG_PATTERN}</pattern>
                </encoder>
                <file>${LOG_FILE}</file>
                <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
                    <fileNamePattern>${LOG_FILE}.%d{yyyy-MM-dd}</fileNamePattern>
                    <maxHistory>30</maxHistory>
                </rollingPolicy>
            </appender>
        </then>
    </if>

    <!-- SlowQueryReport用ログファイル -->
    <if condition='"${spring.profiles.active}" == "product" &amp;&amp; "${slowquery.logging.file}" != ""'>
        <then>
            <springProperty scope="context" name="slowQueryLogFile" source="slowquery.logging.file"/>
            <appender name="SLOWQUERY_LOG_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
                <encoder>
                    <pattern>${FILE_LOG_PATTERN}</pattern>
                </encoder>
                <file>${slowQueryLogFile}</file>
                <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
                    <fileNamePattern>${slowQueryLogFile}.%d{yyyy-MM-dd}</fileNamePattern>
                    <maxHistory>30</maxHistory>
                </rollingPolicy>
            </appender>
        </then>
    </if>

    <if condition='"${spring.profiles.active}" == "develop"'>
        <then>
            <include resource="logback-develop.xml"/>
        </then>
    </if>
    <if condition='"${spring.profiles.active}" == "unittest"'>
        <then>
            <include resource="logback-unittest.xml"/>
        </then>
    </if>
    <if condition='"${spring.profiles.active}" == "product"'>
        <then>
            <include resource="logback-product.xml"/>
        </then>
    </if>
</configuration>
  • <!-- SlowQueryReport用ログファイル --><if condition=...> ... </if> を追加します。
  • <if condition='...'> の中で AND 条件を記述する場合には &amp;&amp; と書きます。

logback-product.xml

<?xml version="1.0" encoding="UTF-8"?>
<included>
    <root level="INFO">
        <appender-ref ref="FILE"/>
    </root>

    <!-- Doma 2 -->
    <logger name="org.seasar.doma" level="ERROR"/>

    <!-- Tomcat JDBC Connection Pool SlowQueryReport interceptor -->
    <if condition='"${slowquery.logging.file}" != ""'>
        <then>
            <logger name="org.apache.tomcat.jdbc.pool.interceptor.SlowQueryReport" level="INFO">
                <appender-ref ref="SLOWQUERY_LOG_FILE"/>
            </logger>
        </then>
    </if>
</included>
  • <!-- Tomcat JDBC Connection Pool SlowQueryReport interceptor --><if condition=...> ... </if> を追加します。

履歴

2017/04/20
初版発行。