メモ

MySQLのwait_timeout実験

秘伝のバッチが突如悲鳴を上げるということは少なくないと思いますが、自分の知識不足から復旧に時間を要してしまった。

自戒もかねてメモを残す。

やばいクエリによるtimeoutでgone away

“MySQL server has gone away” が発生する原因としては以下の要因が考えられる。

  • クエリのサイズがでかすぎ
  • 接続のアイドルタイムアウト

前者はmax_packet_sizeの値を調整して解決できる。
が、今回の原因は後者のタイムアウトの秒数だった。

接続が開始されてから、最後にデータベースに問い合わせをした時間から、指定した秒数たってしまうと、データベースはクライアントとの接続を勝手に切ってしまう。
接続が切れた状態でクエリを送信すると、「おまえの接続はもう切れてるぜ！」となりgone awayとなる。

この指定した秒数の謎についておいかけていきたいと思います(^O^)／

なぜ原因判明まで時間がかかってしまったのか

そもそも時間がかかりすぎるクエリがよくないのだが、明らかに設定された時間内より早いタイミングで切断されていた。

デフォルトだとおそらく2880秒で設定されている

1
2
3
4
5
6
7
8
9
% mysql -u root

mysql> SHOW VARIABLES LIKE 'wait_timeout';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| wait_timeout  | 28800 |
+---------------+-------+
1 row in set (0.00 sec)

2880秒もたってないのになぜgone awayになるんだよ。。。

マニュアルに書いてあった。。。

以下公式からの引用

Interactive（対話型）で接続したやつはinteractive_timeoutの秒数をwait_timeoutとして設定しちゃうぜ！
ってことみたいです。

interactive_timeoutの秒数

1
2
3
4
5
6
7
8
9
% mysql -u root

mysql> SHOW VARIABLES LIKE 'interactive_timeout';
+---------------------+-------+
| Variable_name       | Value |
+---------------------+-------+
| interactive_timeout | 28800 |
+---------------------+-------+
1 row in set (0.00 sec)

じゃあ対話型じゃない場合はどうなるかっていうと

1
2
3
4
5
6
7
% mysql -u root -e "show variables like 'wait_timeout'"

+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| wait_timeout  | 60    |
+---------------+-------+

my.iniで設定されている数字がやっとでてきた。

アプリケーションから接続する際は非対話モード（Interactiveじゃない）になるので、
60秒が設定されていたため、早いタイミングで落ちていたみたいです。

28800秒で設定されるから他に原因があるのかと思い余計な時間をとられてしまった。。。

実験

前提

  • mysql 5.6
  • php7.1
  • pdo

実験1. wait_timeoutを5秒に設定して、DBに接続してからsleepを6秒いれた後、クエリを実行するとgone awayになるか確認。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
<?php
define('WAIT_TIME', 6);

try {
  $pdo = new PDO('mysql:host=db;dbname=test;charset=utf8','root','pass',
array(PDO::ATTR_EMULATE_PREPARES => false));

  sleep(WAIT_TIME);

  $sql = "SELECT version();";
  $pdo->query($sql);
  
} catch (PDOException $e) {
  exit($e->getMessage());
}

見事gone away!

1
Warning: PDO::query(): MySQL server has gone away in /src/connect.php on line 11

実験2. interactive_timeoutを5秒に設定して、対話接続でクエリ実行後に5秒まち、再度クエリを実行するとgone awayになるか確認。

1
2
3
4
5
6
7
8
9
10
% mysql -u root

mysql> SHOW VARIABLES LIKE 'interactive_timeout';
+---------------------+-------+
| Variable_name       | Value |
+---------------------+-------+
| interactive_timeout |   5   |
+---------------------+-------+
1 row in set (0.00 sec)

5秒待って再度クエリ実行

見事gone away!

1
2
mysql> SHOW VARIABLES LIKE 'interactive_timeout';
ERROR 2013 (HY000): Lost connection to MySQL server during query

テストに使ったコードはこちら

https://github.com/kuniiskywalker/test-mysql-goneaway

まとめ

対話型の場合だけ秒数が別指定が多めにとられてるのは、一旦接続していろいろいじることが前提なので当たり前といえば当たり前。。。