Home > Best practices, Development, English, Optimization, Techie > Profiling MySQL/MariaDB queries

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.

Advertisements
  1. No comments yet.
  1. No trackbacks yet.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

%d bloggers like this: