通常のクエリーログ、遅いクエリーログの保存設定

通常のクエリーログ、遅いクエリーログをファイルに保存する方法を確認します。遅いクエリーログについては、対象となる処理時間の設定方法なども取り上げます。

※注意
ここでは、動作確認のため SET文 で設定してますが、サーバーの再起動で設定が失われます。
設定を失いたくない場合は 設定ファイル で設定します。

まず確認

log_output|ログの出力先

値が FILE になっていることを確認します。

mysql> SHOW GLOBAL VARIABLES LIKE 'log_output';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_output    | FILE  |
+---------------+-------+
1 row in set (0.01 sec)

参考
https://dev.mysql.com/doc/refman/5.6/ja/server-system-variables.html#sysvar_log_output

datadir|データディレクトリ

ログの出力ディレクトリを確認します。

mysql> SHOW GLOBAL VARIABLES LIKE 'datadir';
+---------------+-----------------+
| Variable_name | Value           |
+---------------+-----------------+
| datadir       | /var/lib/mysql/ |
+---------------+-----------------+
1 row in set (0.01 sec)

参考
https://dev.mysql.com/doc/refman/5.6/ja/server-system-variables.html#sysvar_datadir

通常のクエリーログの設定

general_log|ONにする

通常のクエリーログを有効にするには、general_log をONにします。

mysql> SET GLOBAL general_log = ON;
Query OK, 0 rows affected (0.00 sec)

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

参考
https://dev.mysql.com/doc/refman/5.6/ja/server-system-variables.html#sysvar_general_log

general_log_file|出力ファイル名

ログの出力先となるファイル名を確認します。

mysql> SHOW GLOBAL VARIABLES LIKE 'general_log_file';
+------------------+------------------------+
| Variable_name    | Value                  |
+------------------+------------------------+
| general_log_file | /var/lib/mysql/api.log |
+------------------+------------------------+
1 row in set (0.00 sec)

動作確認

以下のように、通常クエリのログが /var/lib/mysql/api.log に保存されるようになりました。

# cat /var/lib/mysql/api.log 
/usr/sbin/mysqld, Version: 5.7.19 (MySQL Community Server (GPL)). started with:
Tcp port: 3306  Unix socket: /var/lib/mysql/mysql.sock
Time                 Id Command    Argument
2017-08-08T03:12:19.798915Z         5 Query     SHOW GLOBAL VARIABLES LIKE 'general_log'
2017-08-08T03:13:14.194874Z         5 Query     SHOW GLOBAL VARIABLES LIKE 'general_log_file'
2017-08-08T03:14:15.092823Z         5 Query     SELECT * FROM users

遅いクエリーログの設定

slow_query_log|ONにする

遅いクエリーログを有効にするには、slow_query_log をONにします。

mysql> SET GLOBAL slow_query_log = ON;
Query OK, 0 rows affected (0.01 sec)

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

参考
https://dev.mysql.com/doc/refman/5.6/ja/server-system-variables.html#sysvar_slow_query_log

slow_query_log_file|出力ファイル名

ログの出力先となるファイル名を確認します。

mysql> SHOW GLOBAL VARIABLES LIKE 'slow_query_log_file';
+---------------------+-----------------------------+
| Variable_name       | Value                       |
+---------------------+-----------------------------+
| slow_query_log_file | /var/lib/mysql/api-slow.log |
+---------------------+-----------------------------+
1 row in set (0.00 sec)

動作確認

前準備

検証用テーブルを生成します。

CREATE TABLE `tests` (
  `column` text NOT NULL
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;

10レコード挿入します。

INSERT INTO `tests`
(`column`)
VALUES
('xxx'),
('xxx'),
('xxx'),
('xxx'),
('xxx'),
('xxx'),
('xxx'),
('xxx'),
('xxx'),
('xxx');

単純結合を7回することで1000万レコードになります。
(10 × 10 × 10 × 10 × 10 × 10 × 10 = 10,000,000)

mysql> SELECT COUNT(*) FROM `tests` t1, `tests` t2, `tests` t3, `tests` t4, `tests` t5, `tests` t6, `tests` t7;
+----------+
| COUNT(*) |
+----------+
| 10000000 |
+----------+
1 row in set (0.92 sec)

遅いクエリ実行

1000万レコード挿入します。重い処理です。

mysql> INSERT INTO `tests`
    -> (`column`)
    -> SELECT `t1`.`column` FROM `tests` t1, `tests` t2, `tests` t3, `tests` t4, `tests` t5, `tests` t6, `tests` t7;
Query OK, 10000000 rows affected (45.95 sec)
Records: 10000000  Duplicates: 0  Warnings: 0

46秒ほどかかりました。

スロークエリログの確認

スロークエリログを確認してみます。

# cat /var/lib/mysql/api-slow.log 
/usr/sbin/mysqld, Version: 5.7.19 (MySQL Community Server (GPL)). started with:
Tcp port: 3306  Unix socket: /var/lib/mysql/mysql.sock
Time                 Id Command    Argument
# Time: 2017-08-08T04:03:21.936415Z
# User@Host: root[root] @ localhost []  Id:     5
# Query_time: 45.958685  Lock_time: 0.000137 Rows_sent: 0  Rows_examined: 10000230
SET timestamp=1502165001;
INSERT INTO `tests`
(`column`)
SELECT `t1`.`column` FROM `tests` t1, `tests` t2, `tests` t3, `tests` t4, `tests` t5, `tests` t6, `tests` t7;

long_query_time

long_query_time で設定された 秒数 より処理時間が長いとスロークエリログの対象になります。

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

3秒に変更してみます。

mysql> SET GLOBAL long_query_time = 3;
Query OK, 0 rows affected (0.00 sec)

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

参考
https://dev.mysql.com/doc/refman/5.6/ja/server-system-variables.html#sysvar_long_query_time

log_queries_not_using_indexes

log_queries_not_using_indexesON にすると「インデックスの効かないクエリ」がスロークエリログに記録されます。

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

参考
https://dev.mysql.com/doc/refman/5.6/ja/server-system-variables.html#sysvar_log_queries_not_using_indexes

参考