JDBC の socketTimeout では DB のクエリは止まらない

バッチ処理がタイムアウトしたとき、「アプリがエラーを返したのだから DB の負荷も止まったはずだ」と考えていないでしょうか。

実はこれ、JDBC の socketTimeout に頼っている場合は誤りです。

socketTimeout はクライアント側のソケットを放棄するだけで、DB 側のクエリは走り続けます。

私が担当したバッチでは、アプリが 60 秒でエラーを返したあとも、DB は 371 秒スキャンを続けていました。

しかもその間にリトライが走り、まったく同じ全表走査が二重に実行されていました。

本記事では実際に遭遇した事例をもとに、この誤解の中身と対処方法を解説します。

アプリは 60 秒で諦めたが DB は 371 秒走っていた

事の発端は、毎朝決まった時刻に出るスロークエリのアラートでした。

対象は日次で動くバッチ処理です。

アプリケーション側のログを見ると、DB との通信エラーが記録されていました。

このアプリの JDBC 設定は socketTimeout=60000、つまり 60 秒です。

ところが DB 側のスロークエリログには、次の値が記録されていました。

Query_time: 371.172384
Rows_examined: 3346315
Rows_sent: 54

約 6 分 11 秒です。

つまりアプリが 60 秒でエラーを返して処理を終えたあとも、DB は 5 分以上スキャンを続けていたことになります。

334 万行を走査して、返ってきたのはわずか 54 行でした。

そしてその結果は、受け取り手がもういないので捨てられます。

リトライと重なって負荷が倍増する

問題はここからです。

アプリがエラーを返したので、キューのリトライ機構が働いて処理が再実行されます。

このとき最初のクエリはまだ DB 上で走っています。

結果として、同じ全表走査が並行して二重に実行される状態になりました。

これは推測ではなく、スロークエリログから確認できました。

2 本のクエリの Rows_examined がどちらも 3,346,315 で完全に一致していたのです。

まったく同じ範囲を、2 つのセッションが同時にスキャンしていた証拠になります。

つまりタイムアウトで諦めたつもりが、DB にかかる負荷はむしろ増えていたわけです。

リトライ回数が多い設定なら、さらに積み上がっていきます。

socketTimeout と setQueryTimeout の違い

なぜこうなるのか、2 つのタイムアウトの役割を整理します。

socketTimeout は、MySQL Connector/J のドキュメントで「ネットワークソケット操作に対するタイムアウト」と定義されています。

あくまでネットワーク層の設定であり、SQL の実行を制御するものではありません。

クライアントが読み取りを諦めてソケットを閉じても、サーバーはそれを知る由もなく処理を続けます。

一方の Statement.setQueryTimeout() は、まったく別の仕組みで動きます。

Connector/J はクライアント側でタイマーを持ち、時間が来ると別のコネクションを新たに張って KILL QUERY を発行します。

つまり DB に対して明示的に「このクエリを止めろ」と伝えるため、サーバー側のスキャンも実際に停止します。

この違いを押さえておかないと、タイムアウトを設定したつもりで DB は守れていないという状態になります。

どう設定するか

DB 側のクエリまで止めたい場合、socketTimeout に加えてクエリタイムアウトを設定します。

フレームワークごとの代表的な指定方法は次のとおりです。

• MyBatis: defaultStatementTimeout で全体の既定値を指定する
• Spring: @Transactional(timeout = N) でトランザクション単位に指定する
• JPA / Hibernate: jakarta.persistence.query.timeout をプロパティで指定する

設定するときはsocketTimeout をクエリタイムアウトより長くしておくのが基本です。

逆にすると、KILL QUERY が飛ぶ前にソケットが切れてしまい、せっかくの設定が働きません。

さらに確実にしたい場合は、サーバー側にもバックストップを置く方法があります。

MySQL には max_execution_time という設定があり、SELECT の実行時間に上限を設けられます。

アプリ側の設定漏れがあっても、DB 側で歯止めがかかるので安心感があります。

タイムアウト調査は層を分けて確認する

今回の調査で実感したのが、どの層で切れているのかを取り違えやすいということです。

このシステムには、タイムアウトの設定が複数の層に存在していました。

観測された 60 秒という値は、HTTP クライアントのどちらでもなく JDBC 層のものでした。

もし HTTP 層だと思い込んで rest.read.timeout を調整していたら、いつまでも解決しなかったはずです。

タイムアウトを調査するときは、HTTP / JDBC / トランザクション / DB の各層を分けて洗い出すことをおすすめします。

観測された時間と一致する設定値を探すと、当たりを付けやすくなります。

まとめ

• socketTimeout はソケットを放棄するだけで、DB 側のクエリは走り続ける
• アプリが諦めた後もスキャンが続き、リトライと重なると負荷が倍増する
• DB 側を止めたいなら setQueryTimeout 系を使う。こちらは KILL QUERY を発行する
• socketTimeout はクエリタイムアウトより長く設定する
• タイムアウト調査は HTTP / JDBC / トランザクション / DB の層を分けて確認する

「DB との通信エラー」というログを見ると、つい DB 側の問題だと考えてしまいがちです。

しかしその実体が socketTimeout による切断で、裏では DB が延々とスキャンを続けているというケースは珍しくありません。

スロークエリログの Query_time とアプリのタイムアウト値を突き合わせてみると、思わぬ発見があるかもしれません。

saratoga

フリーランスエンジニア

XYouTube

仕事にも趣味にも IT を駆使するフリーランスエンジニア。技術的な TIPS や日々の生活の中で深堀りしてみたくなったことを備忘録として残していきます。