mita2 database life

主にMySQLに関するメモです

MySQLのスロークエリログにはエラーになったクエリが含まれる?

以前、エラーになったクエリがスロークエリログに落ちるかどうか試しました。

mita2db.hateblo.jp

このときは文法エラーも含め、エラー時もスロークエリログに記録されてましたが、MySQL 8.0.29, MySQL 5.7.38 で文法エラーは除外するよう挙動が変更されたようです。 改めて、挙動を確認してみます。

MySQL 8.0.29, Statements that cannot be parsed (due, for example, to syntax errors) are no longer written to the slow query log.

実行時間でフィルターされないようlong_query_time=0 を設定して試します。

log_slow_extra=ON
long_query_time=0
slow_query_log=on
slow_query_log_file=/var/log/mysqld-slow.log

文法エラー

mysql>  INSERT INTO t1 HOGEHOGE;
ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'HOGEHOGE' at line 1

出力されませんでした。リリースノートに書かれている通りですね。

制約違反

mysql>  INSERT INTO t.t1 VALUES(1);
ERROR 1062 (23000): Duplicate entry '1' for key 't1.PRIMARY'

出力されました。 ちゃんと、Errno が出るようになってる!以前、試したときは出力されてなかったです(どのバージョンで直ったんだろ)。

# Time: 2022-05-04T08:10:47.083268Z
# User@Host: root[root] @ localhost []  Id:    14
# Query_time: 0.000293  Lock_time: 0.000002 Rows_sent: 0  Rows_examined: 0 Thread_id: 14 Errno: 1062 Killed: 0 Bytes_received: 0 Bytes_sent: 53 Read_first: 0 Read_last: 0 Read_key: 0 Read_next: 0 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 0 Sort_merge_passes: 0 Sort_range_count: 0 Sort_rows: 0 Sort_scan_count: 0 Created_tmp_disk_tables: 0 Created_tmp_tables: 0 Start: 2022-05-04T08:10:47.082975Z End: 2022-05-04T08:10:47.083268Z
SET timestamp=1651651847;
INSERT INTO t.t1 VALUES(1);

ロックタイムアウト

出力されました。こちらも、Errno が正しく出力されるようになってます。

# Time: 2022-05-04T08:22:02.224408Z
# User@Host: root[root] @ localhost []  Id:    19
# Query_time: 50.333232  Lock_time: 50.331265 Rows_sent: 0  Rows_examined: 0 Thread_id: 19 Errno: 1205 Killed: 0 Bytes_received: 0 Bytes_sent: 67 Read_first: 0 Read_last: 0 Read_key: 1 Read_next: 0 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 0 Sort_merge_passes: 0 Sort_range_count: 0 Sort_rows: 0 Sort_scan_count: 0 Created_tmp_disk_tables: 0 Created_tmp_tables: 0 Start: 2022-05-04T08:21:11.891176Z End: 2022-05-04T08:22:02.224408Z
SET timestamp=1651652471;
UPDATE t.t1 SET pk = 100 WHERE pk = 1;

中断

mysql> SELECT SLEEP(10);
^C^C -- query aborted
+-----------+
| SLEEP(10) |
+-----------+
|         1 |
+-----------+
1 row in set (1.21 sec)

出力されました。Errno0 です。

# Time: 2022-05-04T08:13:53.342742Z
# User@Host: root[root] @ localhost []  Id:    15
# Query_time: 1.211280  Lock_time: 0.000000 Rows_sent: 1  Rows_examined: 1 Thread_id: 15 Errno: 0 Killed: 0 Bytes_received: 0 Bytes_sent: 57 Read_first: 0 Read_last: 0 Read_key: 0 Read_next: 0 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 0 Sort_merge_passes: 0 Sort_range_count: 0 Sort_rows: 0 Sort_scan_count: 0 Created_tmp_disk_tables: 0 Created_tmp_tables: 0 Start: 2022-05-04T08:13:52.131462Z End: 2022-05-04T08:13:53.342742Z
SET timestamp=1651652032;
SELECT SLEEP(10);