やったこと
SHOW PROFILE を使ってみます。
確認環境
$ mysql --version
mysql Ver 14.14 Distrib 5.6.25, for Linux (x86_64) using EditLine wrapper
調査
プロファイリング対象のクエリを発行
mysql> show variables like "%profiling%"
-> ;
+------------------------+-------+
| Variable_name | Value |
+------------------------+-------+
| have_profiling | YES |
| profiling | OFF |
| profiling_history_size | 15 |
+------------------------+-------+
3 rows in set (0.00 sec)
mysql> SELECT COUNT(*), created_at FROM bulk_test_org
-> GROUP BY created_at
-> ORDER BY COUNT(*) DESC
-> LIMIT 10;
+----------+---------------------+
| COUNT(*) | created_at |
+----------+---------------------+
| 8388608 | 2020-11-03 07:36:31 |
| 4194304 | 2020-11-03 07:34:32 |
| 2097152 | 2020-11-03 07:34:19 |
| 1048576 | 2020-11-03 07:34:12 |
| 524288 | 2020-11-03 07:34:07 |
| 262144 | 2020-11-03 07:34:03 |
| 131072 | 2020-11-03 07:34:01 |
| 65536 | 2020-11-03 07:34:00 |
| 32768 | 2020-11-03 07:33:59 |
| 16384 | 2020-11-03 07:33:58 |
+----------+---------------------+
10 rows in set (20.51 sec)
結果確認
mysql> SHOW PROFILES;
+----------+-------------+-------------------------------------------------------------------------------------------------------+
| Query_ID | Duration | Query |
+----------+-------------+-------------------------------------------------------------------------------------------------------+
| 1 | 0.00901450 | select count(*), created_at from bulk_test group by created_at order by count(*) desc limit 3 |
| 2 | 0.00022100 | select * from bulk_test limit 3 |
| 3 | 0.00224100 | select * from bulk_test_org limit 3 |
| 4 | 0.00024325 | select * from bulk_test_org limit 3 |
| 5 | 0.00000075 | SELECT COUNT(*), created_at FROM bulk_test
GROUP BY created_at
ORDER BY COUNT(*) DESC
LIMIT 10 |
| 6 | 20.49806075 | SELECT COUNT(*), created_at FROM bulk_test_org
GROUP BY created_at
ORDER BY COUNT(*) DESC
LIMIT 10 |
+----------+-------------+-------------------------------------------------------------------------------------------------------+
6 rows in set, 1 warning (0.00 sec)
mysql> SHOW PROFILE;
+----------------------+-----------+
| Status | Duration |
+----------------------+-----------+
| starting | 0.000060 |
| checking permissions | 0.000008 |
| Opening tables | 0.000018 |
| init | 0.000020 |
| System lock | 0.000009 |
| optimizing | 0.000006 |
| statistics | 0.000014 |
| preparing | 0.000011 |
| Creating tmp table | 0.000030 |
| Sorting result | 0.000005 |
| executing | 0.000003 |
| Sending data | 20.480386 |
| Creating sort index | 0.009607 |
| end | 0.000435 |
| removing tmp table | 0.000028 |
| end | 0.000234 |
| query end | 0.000015 |
| closing tables | 0.001094 |
| freeing items | 0.002723 |
| logging slow query | 0.000010 |
| cleaning up | 0.003346 |
+----------------------+-----------+
21 rows in set, 1 warning (0.01 sec)