Spring Data JPAのMySQL接続周りについて

概要

SpringDataJPAを使用していた際に疑問となった、DB接続周りについて調査した。

環境

Java 8
SpringBoot 1.5.7.RELEASE

コネクションの調査

DBに接続するアプリケーションを起動すると、コネクションが10本自動で張られていた。
アプリケーションを立ち上げる際にDBが落ちていると起動が失敗するのでなるほどなあという感じ。
（一番上のコネクションは確認用に接続しているもの）

コネクションが10本自動で張られるのは、使用されているDBコネクションプーリングの初期値initialSizeによるのではと思います。

tomokaneさんよりコメントいただきました。
今回のケースだと、spring.datasource.tomcat.initial-sizeの値を変えると起動時のコネクション数が変わりました。

mysql> show processlist;
+-----+------+------------------+---------+---------+------+----------+------------------+
| Id  | User | Host             | db      | Command | Time | State    | Info             |
+-----+------+------------------+---------+---------+------+----------+------------------+
|   3 | user | localhost        | test_db | Query   |    0 | starting | show processlist |
| 108 | user | 172.19.0.1:45338 | test_db | Sleep   |   22 |          | NULL             |
| 109 | user | 172.19.0.1:45340 | test_db | Sleep   |   22 |          | NULL             |
| 110 | user | 172.19.0.1:45342 | test_db | Sleep   |   22 |          | NULL             |
| 111 | user | 172.19.0.1:45344 | test_db | Sleep   |   22 |          | NULL             |
| 112 | user | 172.19.0.1:45346 | test_db | Sleep   |   21 |          | NULL             |
| 113 | user | 172.19.0.1:45348 | test_db | Sleep   |   21 |          | NULL             |
| 114 | user | 172.19.0.1:45350 | test_db | Sleep   |   21 |          | NULL             |
| 115 | user | 172.19.0.1:45352 | test_db | Sleep   |   21 |          | NULL             |
| 116 | user | 172.19.0.1:45354 | test_db | Sleep   |   21 |          | NULL             |
| 117 | user | 172.19.0.1:45356 | test_db | Sleep   |   21 |          | NULL             |
+-----+--------+------------------+----------------+---------+------+----------+------------------+

また同時に10を超えるアクセスを立ち上げたアプリケーション経由でしたところ、コネクションが増えたり全て使われている様子はなかった。
どのようにコントロールされているかまでは未調査。

トランザクションの調査

トランザクションをするためには、トランザクションの範囲にしたいメソッドに対して「@Transactional」アノテーションを付与する。

@Transactional
public void methodName() {
    // SELECT文その１
    doSelect1();
  
    // 10秒スリープ
    try{
        Thread.sleep(10000);
    } catch(Exception e) {
    }
  
    // SELECT文その2
    doSelect2();
}

確認のため、上記のようなメソッドを作成した。
スリープの間にSELECT文その2の対象となるレコードを挿入してもSELECT結果には含まれていなかった。

タイムアウトについて

application.propertiesにて値を設定できる。

// 20秒
spring.transaction.default-timeout=20 

個別の設定はアノテーションで行う。

// 10秒
@Transactional(timeout = 10)

DB側でもタイムアウトが設定しており、MySQLだと以下のようになっていた。
innodb_lock_wait_timeoutがその値で、初期値が50秒となる。

mysql> show global variables like '%wait%';
+---------------------------------------------------+----------+
| Variable_name                                     | Value    |
+---------------------------------------------------+----------+
| innodb_lock_wait_timeout                          | 50       |
| innodb_spin_wait_delay                            | 6        |
| lock_wait_timeout                                 | 31536000 |
| performance_schema_events_waits_history_long_size | 10000    |
| performance_schema_events_waits_history_size      | 10       |
| wait_timeout                                      | 28800    |
+---------------------------------------------------+----------+

挙動を確認するため、行ロックをかけたレコードに対してJpaRepositoryのsaveメソッドを実行した。
行ロックは下記の用にあらかじめmysqlサーバに入って行っておく。

mysql> start transaction;                                                                                                                                                                                 Query OK, 0 rows affected (0.01 sec)
 
mysql> update test_db column1 = 'hoge' WHERE column2 = '0';                                                                                                               Query OK, 0 rows affected (0.00 sec)
Rows matched: 2  Changed: 0  Warnings: 0

この行ロックに引っかかるようsaveメソッドを実行したところ、設定値の時間後に上記exceptionが投げられるのを確認した。
（ちなみにログを見る限り、saveメソッドの内部ではSELECT→UPDATEが行われている様子）

org.springframework.dao.CannotAcquireLockException: could not execute statement; SQL [n/a]; nested exception is org.hibernate.exception.LockAcquisitionException: could not execute statement