Profiling MySQL/MariaDB queries

  1. mariadb-logo

MariaDB logoIf you ever face an optimization issue in MySQL or MariaDB and want to know how to measure/benchmark the differences in execution between two queries, you should definitely know about the set profiling=1; command.

Here is how it works:

mysql> set profiling=1;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT count(login_user_id)  FROM stats.track_e_online WHERE DATE_ADD(login_date, INTERVAL 60 MINUTE) >= ‘2012-06-11 11:56:20′;
+———————-+
| count(login_user_id) |
+———————-+
|                   65 |
+———————-+
1 row in set (0.00 sec)
mysql> show profile;
+——————————–+———-+
| Status                         | Duration |
+——————————–+———-+
| starting                       | 0.000022 |
| checking query cache for query | 0.000055 |
| checking permissions           | 0.000010 |
| Opening tables                 | 0.000012 |
| System lock                    | 0.000005 |
| Table lock                     | 0.000023 |
| init                           | 0.000027 |
| optimizing                     | 0.000010 |
| statistics                     | 0.000008 |
| preparing                      | 0.000009 |
| executing                      | 0.000004 |
| Sending data                   | 0.001994 |
| end                            | 0.000006 |
| query end                      | 0.000004 |
| freeing items                  | 0.000014 |
| storing result in query cache  | 0.000227 |
| logging slow query             | 0.000004 |
| logging slow query             | 0.000028 |
| cleaning up                    | 0.000003 |
+——————————–+———-+
19 rows in set (0.01 sec)

mysql> SELECT count(login_user_id)  FROM stats.track_e_online WHERE ‘2012-06-11 11:56:20′  <= DATE_ADD(login_date, INTERVAL 60 MINUTE);
+———————-+
| count(login_user_id) |
+———————-+
|                   65 |
+———————-+
1 row in set (0.00 sec)

mysql> show profile;
+——————————–+———-+
| Status                         | Duration |
+——————————–+———-+
| starting                       | 0.000032 |
| checking query cache for query | 0.000083 |
| checking permissions           | 0.000014 |
| Opening tables                 | 0.000011 |
| System lock                    | 0.000005 |
| Table lock                     | 0.000031 |
| init                           | 0.000026 |
| optimizing                     | 0.000009 |
| statistics                     | 0.000008 |
| preparing                      | 0.000009 |
| executing                      | 0.000005 |
| Sending data                   | 0.001989 |
| end                            | 0.000007 |
| query end                      | 0.000003 |
| freeing items                  | 0.000015 |
| storing result in query cache  | 0.000340 |
| logging slow query             | 0.000005 |
| logging slow query             | 0.000030 |
| cleaning up                    | 0.000003 |
+——————————–+———-+
19 rows in set (0.00 sec)
mysql> set profiling=0;
Query OK, 0 rows affected (0.00 sec)

Well, granted, there isn’t much of a difference between those two examples. I believe that’s because these queries have been stored in the query cache already, but you get the idea…

Note that profiling is a session variable, which means it only acts in your session of the MySQL/MariaDB client. You can find more information about profiling in the MySQL documentation pages.

Of course, this also works in the great MariaDB server.

It's only fair to share...Share on FacebookShare on Google+Tweet about this on TwitterShare on LinkedInShare on TumblrEmail this to someone

Leave a Reply

Your email address will not be published. Required fields are marked *