概要
spring-boot-starter-data-cassandraを2.1.8.RELEASEから2.5.5へアップデートした際にタイムアウトの発生が確認されました。(依存によりspring-data-cassandraが2.2.8.RELEASEから3.2.5へアップデートされます)
原因箇所の特定を行ったところ、PreparedStatementの発行に時間を要していることが分かりました。
原因
遭遇したケースとしては、原因となるものが2点存在します。
- spring-data-cassandraのPreparedStatementに関するバグ(Version 3.2 ~ 3.4)
- spring-data-cassandraのPreparedStatementに関する仕様変更(Version 3.2 ~)
ドライバ側で指定するタイムアウト設定はPreparedStatementの発行にかかる時間も含んでいるため、PreparedStatementにかかる時間が伸びたことにより、タイムアウト発生に繋がったようです。
spring-data-cassandraのバグ
こちらのissueで紹介されているバグが存在していました。
端的に説明すると、Prepared Statementを毎回新しく発行してしまうようです。
PreparedStatementを使用する際に、DriverではSimpleStatementを利用する形でPreparedStatementが発行されます。
これは、キャッシュされ使いまわされるものですが、全てのSimpleStatementをキャッシュに載せようとしてメモリを食いつぶしているようです。
上記の事象が発生する理由としては、version 3.2 ~ 3.4の実装ではSimpleStatementに実際の数値がバインドされた状態となっております。
通常であればキャッシュから使用されるはずにSimpleStatementでも、バインドされた値が違うだけで別のPreparedStatementと認識してメモリに保持しようとしているようです。
この不具合はspring-data-cassandra 3.4.0でFixされています。
バグ発生の確認方法
- Cassandraのメトリクスで確認
Cassandraサーバー側のメトリクスとしてorg.apache.cassandra.metrics.CQLにEvictedPreparedStatementsが存在する。
このメトリクスはキャッシュから追い出されたPreparedStatementの数を表しています。
PreparedStatementが大量に発行されると、頻繁にキャッシュから追い出されることになるため、GrafanaなどでEvictedPreparedStatementsを表示させることで検知することができます。 - Cassandraのログで確認
PreparedStatementが大量に発行されていると、Cassandraサーバー上のdebug.logに以下のようなログが大量に発生する。
そのため、ログの確認でもこのバグが起こっている可能性があると確認することができる。
DEBUG [Native-Transport-Requests-2] 2024-08-27 18:07:22,572 SystemKeyspace.java:1555 - stored prepared statement for logged keyspace 'keyspace名': 'クエリ内容''
発生するバージョン
spring-data-cassandra 3.2.0
spring-boot-starter-data-cassandra 2.5.0 (spring-data-cassandra 3.2.1に依存)
Fixされたバージョン
spring-data-cassandra 3.4.0
spring-boot-starter-data-cassandra 2.7.0 (spring-data-cassandra 3.4.0に依存)
spring-data-cassandraの仕様変更
こちらのcommitでspring-data-cassandra 3.2.0におけるPreparedStatementのデフォルト設定に変更がありました。
PreparedStatementがデフォルトで有効になるように修正されています。
そのため、アップデートを行うことで今までPreparedStatementを利用していなかったクエリもPreparedStatementが利用されるようになりました。
この仕様変更単体でもタイムアウトに繋がってしまうということがあり得ますが、先述している不具合と合わさることでより顕著にタイムアウトが発生するといった形になります。
仕様変更については不具合ではないので、修正などは行われておりません。
発生するバージョン
spring-data-cassandra 3.2.0
spring-boot-starter-data-cassandra 2.5.0 (spring-data-cassandra 3.2.1に依存)
Fixされたバージョン
なし
対処方法
それぞれの症状に対しての対応方法を挙げます。
- 3.4.0以上にバージョンアップする
- PreparedStatementを無効化する
spring-data-cassandra 3.4.0以上にバージョンアップする
不具合の方については3.4.0でFIXされているため、バージョンアップすることで解消することができます。
PreparedStatementを無効化する
仕様変更についてはPreparedStatementの無効化を明示的に行う必要があります。
PreparedStatementが不要な箇所(spring-data-cassandra 3.2以前で使用する設定をしていなかった箇所)については、以下のようにCassandraAdminTemplateのsetUsePreparedStatementsをfalseに設定します。
import org.springframework.data.cassandra.core.CassandraAdminTemplate;
# 中略
@Override
@Primary
@Bean(name = "cassandraTemplate")
public CassandraAdminTemplate cassandraTemplate(){
CassandraAdminTemplate cassandraAdminTemplate = new CassandraAdminTemplate(Objects.requireNonNull(cassandraSession().getObject()), cassandraConverter());
cassandraAdminTemplate.setUsePreparedStatements(false);
return cassandraAdminTemplate;
}
まとめ
今回、spring-data-cassandraの特定のバージョンに含まれる不具合 / 仕様変更によるタイムアウト発生の原因及び対応作について記述しました。
遭遇した際の原因の特定及び対応が大変だったので、同様の事象に遭遇した方がいましたら参考にしていただければと思います。