MySQL (MariaDB) のスローログを出す設定をする

インデックスつかってる?やばない?みたいなクエリを調べたいので、スローログで出せた気がするなあ、ってメモ。

スローログに関する設定の確認

> show variables like '%slow%';
+---------------------+--------------------------------------------------------------------------------------------------------------+
| Variable_name       | Value                                                                                                        |
+---------------------+--------------------------------------------------------------------------------------------------------------+
| log_slow_filter     | admin,filesort,filesort_on_disk,full_join,full_scan,query_cache,query_cache_miss,tmp_table,tmp_table_on_disk |
| log_slow_queries    | OFF                                                                                                          |
| log_slow_rate_limit | 1                                                                                                            |
| log_slow_verbosity  |                                                                                                              |
| slow_launch_time    | 2                                                                                                            |
| slow_query_log      | OFF                                                                                                          |
| slow_query_log_file | 522d4fac608d-slow.log                                                                                        |
+---------------------+--------------------------------------------------------------------------------------------------------------+
7 rows in set (0.00 sec)
> show variables like '%long%';
+---------------------------------------------------+-----------+
| Variable_name                                     | Value     |
+---------------------------------------------------+-----------+
| deadlock_search_depth_long                        | 15        |
| deadlock_timeout_long                             | 50000000  |
| long_query_time                                   | 10.000000 |
| max_long_data_size                                | 1048576   |
| performance_schema_events_waits_history_long_size | 10000     |
+---------------------------------------------------+-----------+
5 rows in set (0.00 sec)
> show variables like '%log_queries%';
+-------------------------------+-------+
| Variable_name                 | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | OFF    |
+-------------------------------+-------+
1 row in set (0.00 sec)
> show variables like '%output%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_output    | FILE  |
+---------------+-------+
1 row in set (0.00 sec)

log_slow_queries と slow_query_log がいてオッ?と思ったが slow_query_log を使うのが正しいらしい。

profiling - Mysql: What is the difference between "slow_query_log" vs "log_slow_queries" - Stack Overflow

 

その他の設定値はフィーリングで大丈夫(ダメ)
このあたりで説明は補完できる。

MySQL :: MySQL 5.7 Reference Manual :: 5.1.7 Server System Variables

スローログの設定と動作確認

set global slow_query_log = ON;
set global long_query_time = 1;
set global log_queries_not_using_indexes = ON;
set global log_output = 'TABLE';

log_output を TABLE にすると mysql.slow_log テーブルに出る FILE にするとファイルに出る。

まずは TABLE にした場合

> use hoge;
> select * from users where nanika_id = 1;

> use mysql;
> show tables;
+---------------------------+
| Tables_in_mysql           |
+---------------------------+
| columns_priv              |
| db                        |
| event                     |
| func                      |
| general_log               |
| help_category             |
| help_keyword              |
| help_relation             |
| help_topic                |
| host                      |
| ndb_binlog_index          |
| plugin                    |
| proc                      |
| procs_priv                |
| proxies_priv              |
| servers                   |
| slow_log                  |
| tables_priv               |
| time_zone                 |
| time_zone_leap_second     |
| time_zone_name            |
| time_zone_transition      |
| time_zone_transition_type |
| user                      |
+---------------------------+
24 rows in set (0.00 sec)

> select * from slow_log;
+----------------------------+---------------------------+-----------------+-----------------+-----------+---------------+------+----------------+-----------+-----------+-----------------------------------------+
| start_time                 | user_host                 | query_time      | lock_time       | rows_sent | rows_examined | db   | last_insert_id | insert_id | server_id | sql_text                                |
+----------------------------+---------------------------+-----------------+-----------------+-----------+---------------+------+----------------+-----------+-----------+-----------------------------------------+
| 2018-07-19 05:08:05.999111 | root[root] @ localhost [] | 00:00:00.003893 | 00:00:00.002550 |         0 |             0 | hoge |              0 |         0 |         0 | select * from users where nanika_id = 1 |
+----------------------------+---------------------------+-----------------+-----------------+-----------+---------------+------+----------------+-----------+-----------+-----------------------------------------+
1 row in set (0.00 sec)

> use hoge;
> explain select * from users where nanika_id = 1;
+------+-------------+-------+------+---------------+------+---------+------+------+-------------+
| id   | select_type | table | type | possible_keys | key  | key_len | ref  | rows | Extra       |
+------+-------------+-------+------+---------------+------+---------+------+------+-------------+
|    1 | SIMPLE      | users | ALL  | NULL          | NULL | NULL    | NULL |    1 | Using where |
+------+-------------+-------+------+---------------+------+---------+------+------+-------------+
1 row in set (0.00 sec)

次に FILE の場合。

$ pwd

/var/lib/mysql


$ tail 522d4fac608d-slow.log

# Time: 180719  5:33:26
# User@Host: root[root] @ localhost []
# Thread_id: 3  Schema: hoge  QC_hit: No
# Query_time: 0.000337  Lock_time: 0.000141  Rows_sent: 0  Rows_examined: 0
SET timestamp=1531978406;
select * from users where nanika_id = 1;

slow_query_log_file で指定した場所に出る /var/log/mysql/... みたいな指定をする必要がありそう。

インデックスを使用していないクエリも出してくれる、便利。

そのほか

set global しただけだと mysql サーバーを終了したときに設定が消えてしまうので、必要に応じて my.cnf に記載。

[mysqld]
slow_query_log=ON
long_query_time=1
log_queries_not_using_indexes=ON
log_output=FILE
slow_query_log_file=hogehoge-slow.log
$ echo 'show variables like "%slow%";' | mysql

Variable_name	Value
log_slow_filter	admin,filesort,filesort_on_disk,full_join,full_scan,query_cache,query_cache_miss,tmp_table,tmp_table_on_disk
log_slow_queries	ON
log_slow_rate_limit	1
log_slow_verbosity
slow_launch_time	2
slow_query_log	ON
slow_query_log_file	hogehoge-slow.log

大丈夫そう。

前後の記事

Next:
Prev: