Mysql Profiler

Nearly unnoticed from most people, there's now a profiler built into every mysql database beginning with release 5.0.37. It profiles the steps of the SQL engine and can help to solve performance issues. Usage is very simple:

set profiling=1;

After that statement MySQL will start to maintain profiling information in a table in the information_schema schema, called information_schema.profiling. For the examples I will use a table called testo1:

CREATE TABLE testo1 (
id int(11) NOT NULL auto_increment,
name1 varchar(20) NOT NULL,
PRIMARY KEY (id));

and a view called v1:

create view v1 as select * from testo1

Now lets try some select statements:

select * from testo1;
select * from v1;

And see what we get:

mysql> show profiles;
+----------+------------+----------------------+
| Query_ID | Duration | Query |
+----------+------------+----------------------+
| 1 | 0.00964100 | select * from testo1 |
| 2 | 0.00099800 | select * from v1 |
+----------+------------+----------------------+
2 rows in set (0,00 sec)

Thats OK, but we want a closer look into each query:

mysql> show profile for query 1;
+--------------------+------------+
| Status | Duration |
+--------------------+------------+
| (initialization) | 0.00003200 |
| Opening tables | 0.00001000 |
| System lock | 0.00001300 |
| Table lock | 0.00000800 |
| init | 0.00001400 |
| optimizing | 0.00000400 |
| statistics | 0.00001300 |
| preparing | 0.00000800 |
| executing | 0.00000400 |
| Sending data | 0.00069000 |
| end | 0.00000700 |
| query end | 0.00876200 |
| freeing items | 0.00006500 |
| closing tables | 0.00000700 |
| logging slow query | 0.00000400 |
+--------------------+------------+
15 rows in set (0,00 sec)

And for the second query:

mysql> show profile for query 2;
+----------------------+------------+
| Status | Duration |
+----------------------+------------+
| (initialization) | 0.00004500 |
| Opening tables | 0.00016400 |
| System lock | 0.00000800 |
| Table lock | 0.00001100 |
| init | 0.00000800 |
| checking permissions | 0.00002000 |
| optimizing | 0.00000700 |
| statistics | 0.00001400 |
| preparing | 0.00001200 |
| executing | 0.00000500 |
| Sending data | 0.00009000 |
| end | 0.00000600 |
| query end | 0.00058000 |
| freeing items | 0.00001700 |
| closing tables | 0.00000600 |
| logging slow query | 0.00000500 |
+----------------------+------------+
16 rows in set (0,00 sec)

If we once again select from the table testo1 with:

select * from testo1;

we get the following profiles:

mysql> show profiles;
+----------+------------+----------------------+
| Query_ID | Duration | Query |
+----------+------------+----------------------+
| 1 | 0.00964100 | select * from testo1 |
| 2 | 0.00099800 | select * from v1 |
| 3 | 0.00071200 | select * from testo1 |
+----------+------------+----------------------+
3 rows in set (0,00 sec)

The first select needed 9.6msec, the second one only 0.7 because of the query cache. We used two identical statements so the query cache could be used.
This should be enough to wet your appetite. If you would like have a closer look:
MySQL dev center article on profiling
MySQL manual entry for "show profiles"