Profiling MySQL/MariaDB queries

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.


Related Posts

Dokeos and MySQL strict SQL mode

We’ve had reports about Dokeos creating problems when used with MySQL in strict...

Database schema for Chamilo 1.9.4

A lot of people have been asking for a database schema of Chamilo...

Quick Contact Form