Skip to content

Instantly share code, notes, and snippets.

@hironomiu
Last active March 2, 2020 14:58
Show Gist options
  • Save hironomiu/8418671 to your computer and use it in GitHub Desktop.
Save hironomiu/8418671 to your computer and use it in GitHub Desktop.
パフォーマンスチューニング

パフォーマンスチューニング

スロークエリ

設定確認

# mysql
mysql> show global variables like '%slow_query%';
+---------------------+-------------------------------+
| Variable_name       | Value                         |
+---------------------+-------------------------------+
| slow_query_log      | ON                            |
| slow_query_log_file | /var/lib/mysql/mysql-slow.log |
+---------------------+-------------------------------+
2 rows in set (0.00 sec)

mysql> show global variables like '%long_query_time%';
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
1 row in set (0.00 sec)

mysql> show global variables like '%log_output%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_output    | FILE  |
+---------------+-------+
1 row in set (0.00 sec)

設定

rootにて実行

long_query_timeを1から0.1に変更

vi /etc/my.cnf

long_query_time = 0.1

再起動

service mysql restart

スローログ確認

2台ターミナルは開くこと

1台目 root

cd /var/lib/mysql
tail -f mysql-slow.log

2台目 アプリケーションユーザ

グローバルIPを利用する場合は各自のIPを設定すること

curl http://localhost/exercise/part4

1台目

tailにてスローログが出力されていること

# Time: 150610 18:06:37
# User@Host: techtrain[techtrain] @ localhost []  Id:    89
# Query_time: 6.028402  Lock_time: 0.000047 Rows_sent: 0  Rows_examined: 1754073
SET timestamp=1433927197;
select * from  message where title = 'チューニングバトル' order by created_at desc limit 10;

explain

確認

上記で出力されたSQLにて確認する

explain時に末尾を「;」から「\G」に変えること

テーブルが1つ


mysql> explain select * from  message where title = 'チューニングバトル' order by created_at desc limit 10\G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: message
         type: ALL
possible_keys: NULL
          key: NULL
      key_len: NULL
          ref: NULL
         rows: 1522365
        Extra: Using where; Using filesort
1 row in set (0.00 sec)

テーブルが2つの場合の表示


mysql> explain select u.name ,m.message from message m inner join user u on u.id = m.user_id where m.id = 100\G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: m
         type: const
possible_keys: PRIMARY
          key: PRIMARY
      key_len: 4
          ref: const
         rows: 1
        Extra: NULL
*************************** 2. row ***************************
           id: 1
  select_type: SIMPLE
        table: u
         type: const
possible_keys: PRIMARY
          key: PRIMARY
      key_len: 4
          ref: const
         rows: 1
        Extra: NULL
2 rows in set (0.01 sec)

更新系SQLの実行計画

MySQL5.6から実装


mysql> explain insert into user values (null,'A','A','A','A','A',now(),now())\G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: NULL
         type: NULL
possible_keys: NULL
          key: NULL
      key_len: NULL
          ref: NULL
         rows: NULL
        Extra: No tables used
1 row in set (0.00 sec)

288 Tips1

messageにINDEXを追加


mysql> alter table message add index user_id(user_id);
Query OK, 0 rows affected (12.52 sec)
Records: 0  Duplicates: 0  Warnings: 0

mysql> select count(*) from message force index (primary);
+----------+
| count(*) |
+----------+
|  1754069 |
+----------+
1 row in set (6.04 sec)

mysql> select count(*) from message force index (user_id);
+----------+
| count(*) |
+----------+
|  1754069 |
+----------+
1 row in set (0.53 sec)

Tips3

最新バージョンはunionは不要の例


mysql> explain select id from message where user_id = 10 or id = 10\G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: message
         type: index_merge
possible_keys: PRIMARY,user_id
          key: user_id,PRIMARY
      key_len: 5,4
          ref: NULL
         rows: 12
        Extra: Using union(user_id,PRIMARY); Using where
1 row in set (0.01 sec)

union例


mysql> explain select id from message where user_id = 10 union select id from message where id = 10\G
*************************** 1. row ***************************
           id: 1
  select_type: PRIMARY
        table: message
         type: ref
possible_keys: user_id
          key: user_id
      key_len: 5
          ref: const
         rows: 11
        Extra: Using index
*************************** 2. row ***************************
           id: 2
  select_type: UNION
        table: message
         type: const
possible_keys: PRIMARY
          key: PRIMARY
      key_len: 4
          ref: const
         rows: 1
        Extra: Using index
*************************** 3. row ***************************
           id: NULL
  select_type: UNION RESULT
        table: <union1,2>
         type: ALL
possible_keys: NULL
          key: NULL
      key_len: NULL
          ref: NULL
         rows: NULL
        Extra: Using temporary
3 rows in set (0.00 sec)

295 クエリキャッシュ

確認


mysql> select count(*) from message;
+----------+
| count(*) |
+----------+
|  1754069 |
+----------+
1 row in set (0.37 sec)

mysql> select count(*) from message;
+----------+
| count(*) |
+----------+
|  1754069 |
+----------+
1 row in set (0.35 sec)

mysql> select count(*) from message;
+----------+
| count(*) |
+----------+
|  1754069 |
+----------+
1 row in set (0.38 sec)

rootにて行うこと

[mysqld]の段落に追記すること

# vi /etc/my.cnf

query_cache_type = ON

# service mysql restart

確認

2回目以降0.00 secであること


mysql> select count(*) from message;
+----------+
| count(*) |
+----------+
|  1754069 |
+----------+
1 row in set (0.46 sec)

mysql> select count(*) from message;
+----------+
| count(*) |
+----------+
|  1754069 |
+----------+
1 row in set (0.00 sec)

mysql> select count(*) from message;
+----------+
| count(*) |
+----------+
|  1754069 |
+----------+
1 row in set (0.00 sec)

296

2回目でQcache_hitsがインクリメントされていること


mysql> show status like 'Qcache%';
+-------------------------+---------+
| Variable_name           | Value   |
+-------------------------+---------+
| Qcache_free_blocks      | 1       |
| Qcache_free_memory      | 1029832 |
| Qcache_hits             | 4       |
| Qcache_inserts          | 1       |
| Qcache_lowmem_prunes    | 0       |
| Qcache_not_cached       | 4       |
| Qcache_queries_in_cache | 1       |
| Qcache_total_blocks     | 4       |
+-------------------------+---------+
8 rows in set (0.00 sec)

mysql> select count(*) from message;
+----------+
| count(*) |
+----------+
|  1754069 |
+----------+
1 row in set (0.00 sec)

mysql> show status like 'Qcache%';
+-------------------------+---------+
| Variable_name           | Value   |
+-------------------------+---------+
| Qcache_free_blocks      | 1       |
| Qcache_free_memory      | 1029832 |
| Qcache_hits             | 5       |
| Qcache_inserts          | 1       |
| Qcache_lowmem_prunes    | 0       |
| Qcache_not_cached       | 4       |
| Qcache_queries_in_cache | 1       |
| Qcache_total_blocks     | 4       |
+-------------------------+---------+
8 rows in set (0.00 sec)

297

2台のターミナルで実施

1台目 アプリケーションユーザで実行

$ siege -c 10 http://localhost/exercise/part4

2台目(root、アプリケーションユーザどちらでも可)

processlistに着目

mysql> show processlist;
+-----+----------+-----------+-----------+---------+------+---------------------+----------------------------------------------------------------------------------------------------+
| Id  | User     | Host      | db        | Command | Time | State               | Info                                                                                               |
+-----+----------+-----------+-----------+---------+------+---------------------+----------------------------------------------------------------------------------------------------+
|   1 | root     | localhost | groupwork | Sleep   | 3934 |                     | NULL                                                                                               |
|   2 | root     | localhost | groupwork | Query   |    0 | init                | show processlist                                                                                   |
| 387 | demouser | localhost | groupwork | Execute |    0 | Creating sort index | select title,message,created_at from message where user_id = '79679' order by created_at limit 100 |
+-----+----------+-----------+-----------+---------+------+---------------------+----------------------------------------------------------------------------------------------------+
3 rows in set (0.00 sec)

310 バルクインサート

非バルク

mysql> use test
mysql> create table test (id int,col1 varchar(10),primary key (id));
Query OK, 0 rows affected (0.05 sec)

mysql> insert into test values(1,'abc');
Query OK, 1 row affected (0.00 sec)

mysql> select * from test;
+----+------+
| id | col1 |
+----+------+
|  1 | abc  |
+----+------+
1 row in set (0.00 sec)

バルクインサート

mysql> insert into test values(2,'bbb'),(3,'ccc'),(4,'ddd');
Query OK, 3 rows affected (0.00 sec)
Records: 3  Duplicates: 0  Warnings: 0

mysql> select * from test;
+----+------+
| id | col1 |
+----+------+
|  1 | abc  |
|  2 | bbb  |
|  3 | ccc  |
|  4 | ddd  |
+----+------+
4 rows in set (0.00 sec)

323

2台のターミナルで実施

1台目

LATEST DETECTED DEADLOCKが無いこと

mysql> show engine innodb status\G
mysql> use test

mysql> start transaction;
Query OK, 0 rows affected (0.00 sec)

mysql> insert into test values(5,'eee');
Query OK, 1 row affected (0.01 sec)

2台目

mysql> use test

mysql> start transaction;
Query OK, 0 rows affected (0.00 sec)

mysql> insert into test values(6,'fff');
Query OK, 1 row affected (0.00 sec)

1台目

mysql> update test set col1 = 'zzz' where id = 6;
Query OK, 0 rows affected (27.83 sec)
Rows matched: 0  Changed: 0  Warnings: 0

2台目

mysql> update test set col1 = 'yyy' where id = 5;
ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction

LATEST DETECTED DEADLOCKが表示されること

mysql> show engine innodb status\G

中略

------------------------
LATEST DETECTED DEADLOCK
------------------------
2014-01-14 22:51:00 7f5aa9bcd700
*** (1) TRANSACTION:
TRANSACTION 99676, ACTIVE 88 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 376, 2 row lock(s), undo log entries 1
MySQL thread id 47819, OS thread handle 0x7f5aa9b4b700, query id 334756 localhost root updating
update test set col1 = 'zzz' where id = 6
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 8 page no 3 n bits 80 index `PRIMARY` of table `test`.`test` trx id 99676 lock_mode X locks rec but not gap waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 4; hex 80000006; asc     ;;
 1: len 6; hex 00000001855d; asc      ];;
 2: len 7; hex 9a000001870110; asc        ;;
 3: len 3; hex 666666; asc fff;;

*** (2) TRANSACTION:
TRANSACTION 99677, ACTIVE 53 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 376, 2 row lock(s), undo log entries 1
MySQL thread id 2, OS thread handle 0x7f5aa9bcd700, query id 334757 localhost root updating
update test set col1 = 'yyy' where id = 5
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 8 page no 3 n bits 80 index `PRIMARY` of table `test`.`test` trx id 99677 lock_mode X locks rec but not gap
Record lock, heap no 7 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 4; hex 80000006; asc     ;;
 1: len 6; hex 00000001855d; asc      ];;
 2: len 7; hex 9a000001870110; asc        ;;
 3: len 3; hex 666666; asc fff;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 8 page no 3 n bits 80 index `PRIMARY` of table `test`.`test` trx id 99677 lock_mode X locks rec but not gap waiting
Record lock, heap no 6 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 4; hex 80000005; asc     ;;
 1: len 6; hex 00000001855c; asc      \;;
 2: len 7; hex 99000001860110; asc        ;;
 3: len 3; hex 656565; asc eee;;

*** WE ROLL BACK TRANSACTION (2)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment