last_query_profiling
NAME
last_query_profiling: Last query's profiling info, aggregated by query's statesTYPE
ViewDESCRIPTION
last_query_profiling presents with pretty profiling info for last executed query.
Based on the INFORMATION_SCHEMA.PROFILING table, this view aggregates data by query state, and presents with more easy to comprehend details, such as the total runtime for the various states and the time ration per state of the total query runtime.
To populate this view, one must enable profiling. This is done by:
mysql> SET PROFILING := 1;
This code is based on queries presented on How to convert MySQL’s SHOW PROFILES into a real profile and in the book High Performance MySQL, 3nd Edition, By Baron Schwartz et al., published by O'REILLY
STRUCTURE
mysql> DESC common_schema.last_query_profiling; +-------------------------+----------------+------+-----+---------+-------+ | Field | Type | Null | Key | Default | Extra | +-------------------------+----------------+------+-----+---------+-------+ | QUERY_ID | int(20) | NO | | 0 | | | STATE | varchar(30) | NO | | | | | state_calls | bigint(21) | NO | | 0 | | | state_sum_duration | decimal(31,6) | YES | | NULL | | | state_duration_per_call | decimal(35,10) | YES | | NULL | | | state_duration_pct | decimal(37,2) | YES | | NULL | | | state_seqs | longblob | YES | | NULL | | +-------------------------+----------------+------+-----+---------+-------+
SYNOPSIS
Structure of this view is identical to that of the query_profiling view.
EXAMPLES
Profile a query over a complex view:
From the above we can see that "Copying to tmp table", "Opening tables" and "Sending data" are the major states impacting the query runtime.mysql> SET PROFILING := 1; mysql> SELECT COUNT(*) FROM sakila.nicer_but_slower_film_list INTO @dummy; mysql> SELECT * FROM last_query_profiling; +----------+----------------------+-------------+--------------------+-------------------------+--------------------+------------+ | QUERY_ID | STATE | state_calls | state_sum_duration | state_duration_per_call | state_duration_pct | state_seqs | +----------+----------------------+-------------+--------------------+-------------------------+--------------------+------------+ | 41 | checking permissions | 5 | 0.000320 | 0.0000640000 | 0.33 | 5,6,7,8,9 | | 41 | cleaning up | 1 | 0.000007 | 0.0000070000 | 0.01 | 31 | | 41 | closing tables | 1 | 0.000016 | 0.0000160000 | 0.02 | 29 | | 41 | Copying to tmp table | 1 | 0.042363 | 0.0423630000 | 44.34 | 15 | | 41 | Creating tmp table | 1 | 0.000123 | 0.0001230000 | 0.13 | 13 | | 41 | end | 1 | 0.000004 | 0.0000040000 | 0.00 | 23 | | 41 | executing | 2 | 0.000014 | 0.0000070000 | 0.01 | 14,22 | | 41 | freeing items | 2 | 0.000216 | 0.0001080000 | 0.23 | 25,27 | | 41 | init | 1 | 0.000012 | 0.0000120000 | 0.01 | 20 | | 41 | logging slow query | 1 | 0.000004 | 0.0000040000 | 0.00 | 30 | | 41 | Opening tables | 1 | 0.028909 | 0.0289090000 | 30.26 | 2 | | 41 | optimizing | 2 | 0.000026 | 0.0000130000 | 0.03 | 10,21 | | 41 | preparing | 1 | 0.000018 | 0.0000180000 | 0.02 | 12 | | 41 | query end | 1 | 0.000004 | 0.0000040000 | 0.00 | 24 | | 41 | removing tmp table | 3 | 0.000130 | 0.0000433333 | 0.14 | 18,26,28 | | 41 | Sending data | 2 | 0.016823 | 0.0084115000 | 17.61 | 17,19 | | 41 | Sorting result | 1 | 0.006302 | 0.0063020000 | 6.60 | 16 | | 41 | starting | 1 | 0.000163 | 0.0001630000 | 0.17 | 1 | | 41 | statistics | 1 | 0.000048 | 0.0000480000 | 0.05 | 11 | | 41 | System lock | 1 | 0.000017 | 0.0000170000 | 0.02 | 3 | | 41 | Table lock | 1 | 0.000018 | 0.0000180000 | 0.02 | 4 | +----------+----------------------+-------------+--------------------+-------------------------+--------------------+------------+
Similar to the above, simplify results:
mysql> SET PROFILING := 1;
mysql> SELECT COUNT(*) FROM sakila.nicer_but_slower_film_list INTO @dummy;
mysql> SELECT STATE, state_duration_pct, state_calls
FROM last_query_profiling
ORDER BY state_duration_pct DESC;
+----------------------+--------------------+-------------+
| STATE | state_duration_pct | state_calls |
+----------------------+--------------------+-------------+
| Copying to tmp table | 61.42 | 1 |
| Sending data | 25.96 | 2 |
| Sorting result | 9.56 | 1 |
| checking permissions | 0.84 | 5 |
| Opening tables | 0.77 | 1 |
| Creating tmp table | 0.51 | 1 |
| starting | 0.21 | 1 |
| removing tmp table | 0.18 | 3 |
| statistics | 0.18 | 1 |
| freeing items | 0.08 | 2 |
| optimizing | 0.07 | 2 |
| preparing | 0.06 | 1 |
| Table lock | 0.04 | 1 |
| executing | 0.03 | 2 |
| closing tables | 0.02 | 1 |
| init | 0.02 | 1 |
| System lock | 0.02 | 1 |
| cleaning up | 0.01 | 1 |
| end | 0.01 | 1 |
| logging slow query | 0.01 | 1 |
| query end | 0.01 | 1 |
+----------------------+--------------------+-------------+