mage by NicoElNino / Shutterstock
Capturing your SQL Statements with MySQL
The previous article Capturing running SQL statements is an important component of application performance analysis when using a relational database (RDBMS). To support the analysis of any SQL statement with MySQL it is also important to gather additional meta information for adequate context. This includes the table structures used, statistics about the table data and structure, and the timing of steps in the preparation and execution of the SQL statement. Information is also collected at different times, before, during, and after the SQL statement execution.
Additional statement information gathering
In MySQL, the following supporting information assists in the validation, assessment, and tuning of your application SQL statements. This information can be collected using default MySQL tools.
- Rows returned (after execution)
- Execution time (after execution)
- Query Execution Plan (QEP) (before execution)
- Table structure (before execution)
- Index cardinality (before execution)
- Query execution cost (before execution)
- Query optimizer evaluation (before execution)
- Status values (before, during, and after execution)
- Query profiling (after execution)
- Processlist (during execution)
Unless otherwise stated the mysql command-line client is used for the following example output.
NOTE: The SQL examples shown here are compatible with both MySQL 5.7 and MySQL 8.0. Due to the end-of-life (EOL) of MySQL 5.7 community edition, all example output and documentation references use the current MySQL 8.0 version. Some output shown in this article may differ from the output produced when using MySQL 5.7.
1\. Rows returned
Rows returned with MySQL client
With the mysql client, you can execute an SQL query, and the number of rows returned is included in a status statement after the query results. This however has to be parsed with all content that is captured.
mysql> SELECT ...
10 rows in set ...
Rows returned via slow query log
The slow query log provides the rows returned via the `Rows_sent` value for each SQL statement that is logged.
# Query_time: 0.473775 Lock_time: 0.000751 Rows_sent: 10 Rows_examined: 152960
The article Capturing running SQL statements describes in detail how to configure, use, and review the MySQL slow query log.
Rows returned via performance/sys schema
You can obtain information on the rows_sent from the PERFORMANCE_SCHEMA and sys schemas, however, these are generally aggregated results. The following example shows an exec_count=1 and thus an accurate rows_sent response.
mysql> SELECT * FROM sys.x$statement_analysis WHERE query LIKE '%airport%'\G
query: SELECT `a` . `country_code` , `c` . `name` , COUNT ( * ) AS `cnt` FROM `airport` `a` INNER JOIN `country` `c` USING ( `country_code` ) GROUP BY `country_code` , NAME ORDER BY ? DESC LIMIT ?
db: airport
full_scan: *
exec_count: 1
err_count: 0
warn_count: 0
total_latency: 477392952000
max_latency: 477392952000
avg_latency: 477392952000
lock_latency: 221000000
rows_sent: 10
rows_sent_avg: 10
rows_examined: 152960
rows_examined_avg: 152960
rows_affected: 0
rows_affected_avg: 0
tmp_tables: 1
tmp_disk_tables: 0
rows_sorted: 10
sort_merge_passes: 0
digest: 616aa31e4f99b22a194c91ae9f1cfbfb95d6957621b55393b4a01603d8e1fd47
first_seen: 2024-01-18 19:23:42.595635
2\. Query execution time
Execution time via MySQL client
Similar to how the mysql client provides the number of rows returned, the total execution time is presented to a granularity of 10 milliseconds.
mysql> SELECT ...
10 rows in set (0.28 sec)
Execution time via profiling
When using profiling you can obtain a high-precision total execution time of an SQL statement.
mysql > SET @@profiling=1;
mysql > SELECT ...
mysql > SET @@profiling=0;
mysql > SHOW PROFILES;
mysql > SELECT SUM(DURATION) FROM INFORMATION_SCHEMA.PROFILING WHERE query_id=1;
NOTE: If you run additional SELECT statements, the query_idvalue may need to be modified to match the query you wish to determine the execution time.
mysql > SHOW PROFILES;
+----------+------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Query_ID | Duration | Query |
+----------+------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------+
|
| 1| 0.23497150 | SELECT a.country_code, c.name, COUNT(*) AS cnt
FROM airport a
INNER JOIN country c USING (country_code)
GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10 |
+----------+------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------+
mysql> SELECT SUM(DURATION) FROM INFORMATION_SCHEMA.PROFILING WHERE query_id=9;
+----------------+
| SUM(DURATION) |
+----------------+
| 0.2349715 |
+----------------+
The use of profiling is described in greater detail in a later section.
Execution time via slow query log
When queries are written to the slow query log you can get a high-precision execution time of the SQL statement with the Query_time value.
# Query_time: 0.473775 Lock_time: 0.000751 Rows_sent: 10 Rows_examined: 152960
3\. Query Execution Plan (QEP)
The EXPLAIN statement produces the QEP containing valuable information about how MySQL will execute the SQL statement. The QEP shows in order the individual steps to execute the query and provides additional information including indexes evaluated, partitions considered, the type of joins used, row estimates, and additional information found in the Extracolumn.
mysql> EXPLAIN SELECT ...
+----+-------------+-------+------------+--------+---------------+---------+---------+------------------------+-------+----------+---------------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-------+------------+--------+---------------+---------+---------+------------------------+-------+----------+---------------------------------+
| 1 | SIMPLE | a | NULL | ALL | country_code | NULL | NULL | NULL | 86733 | 100.00 | Using temporary; Using filesort |
| 1 | SIMPLE | c | NULL | eq_ref | PRIMARY | PRIMARY | 8 | airport.a.country_code | 1 | 100.00 | NULL |
+----+-------------+-------+------------+--------+---------------+---------+---------+------------------------+-------+----------+---------------------------------+
2 rows in set, 1 warning (0.04 sec)
The EXPLAIN statement will always produce 1 warning, which is the statement re-written for internal execution. Should there be more than 1 warning these should be reviewed before continuing.
> SHOW WARNINGS;
Note (Code 1003): /* select#1 */ select `airport`.`a`.`country_code` AS `country_code`,`airport`.`c`.`name` AS `name`,count(0) AS `cnt` from `airport`.`airport` `a` join `airport`.`country` `c` where (`airport`.`c`.`country_code` = `airport`.`a`.`country_code`) group by `airport`.`a`.`country_code` order by count(0) desc limit 10
There is also the newer JSON format over the traditional table layout (FORMAT=TRADITIONAL) that also produces additional cost_infodata.
mysql> EXPLAIN FORMAT=JSON SELECT ...
{
"query_block": {
"select_id": 1,
"cost_info": {
"query_cost": "105264.60"
},
"ordering_operation": {
"using_filesort": true,
"grouping_operation": {
"using_temporary_table": true,
"using_filesort": false,
"nested_loop": [\
{\
"table": {\
"table_name": "a",\
"access_type": "ALL",\
"possible_keys": [\
"country_code"\
],\
"rows_examined_per_scan": 86733,\
"rows_produced_per_join": 86733,\
"filtered": "100.00",\
"cost_info": {\
"read_cost": "1185.00",\
"eval_cost": "8673.30",\
"prefix_cost": "9858.30",\
"data_read_per_join": "256M"\
},\
"used_columns": [\
"airport_id",\
"name",\
"country_code"\
]\
}\
},\
{\
"table": {\
"table_name": "c",\
"access_type": "eq_ref",\
"possible_keys": [\
"PRIMARY"\
],\
"key": "PRIMARY",\
"used_key_parts": [\
"country_code"\
],\
"key_length": "8",\
"ref": [\
"airport.a.country_code"\
],\
"rows_examined_per_scan": 1,\
"rows_produced_per_join": 86733,\
"filtered": "100.00",\
"cost_info": {\
"read_cost": "86733.00",\
"eval_cost": "8673.30",\
"prefix_cost": "105264.60",\
"data_read_per_join": "160M"\
},\
"used_columns": [\
"country_code",\
"name"\
]\
}\
}\
]
}
}
}
}
For more information see the MySQL 8.0 Reference Manual.
See a later example of the EXPLAIN ANALYZE option which also demonstrates the FORMAT=TREE layout.
4\. Table structure
Table structure via the mysql client (1)
For each table in an SQL statement, it is important to gather information regarding the columns and constraints of the table. You can use the SHOW CREATE TABLE syntax.
mysql> SHOW CREATE TABLE airport\G
*************************** 1. row ***************************
Table: airport
Create Table: CREATE TABLE `airport` (
`airport_id` int unsigned NOT NULL,
`ident` varchar(7) NOT NULL,
`type` varchar(20) NOT NULL,
`name` varchar(100) NOT NULL,
`latitude` float NOT NULL,
`longitude` float NOT NULL,
`elevation_ft` smallint DEFAULT NULL,
`continent_code` char(2) NOT NULL,
`country_code` char(2) NOT NULL,
`region_code` char(7) NOT NULL,
`municipality` varchar(60) NOT NULL,
`scheduled_service` tinyint(1) NOT NULL,
`gps_code` char(4) DEFAULT NULL,
`iata_code` char(3) DEFAULT NULL,
`local_code` varchar(7) DEFAULT NULL,
`home_url` varchar(128) DEFAULT NULL,
`wikipedia_url` varchar(128) DEFAULT NULL,
`keywords` varchar(300) DEFAULT NULL,
PRIMARY KEY (`airport_id`),
KEY `name` (`name`),
KEY `country_code` (`country_code`),
KEY `region_code` (`region_code`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci
1 row in set (0.03 sec)
NOTE: The benefit of using this syntax is you can re-create the table with the output.
For more information see the MySQL 8.0 Reference Manual.
Table structure via the mysql client (2)
You can also describe a table with the DESCSQL statement. The disadvantage is you cannot recreate the table with this output, and you cannot correctly determine the index columns and positions.
mysql> DESC airport;
+-------------------+--------------+------+-----+---------+-------+
| Field | Type | Null | Key | Default | Extra |
+-------------------+--------------+------+-----+---------+-------+
| airport_id | int unsigned | NO | PRI | NULL | |
| ident | varchar(7) | NO | | NULL | |
| type | varchar(20) | NO | | NULL | |
| name | varchar(100) | NO | MUL | NULL | |
| latitude | float | NO | | NULL | |
| longitude | float | NO | | NULL | |
| elevation_ft | smallint | YES | | NULL | |
| continent_code | char(2) | NO | | NULL | |
| country_code | char(2) | NO | MUL | NULL | |
| region_code | char(7) | NO | MUL | NULL | |
| municipality | varchar(60) | NO | | NULL | |
| scheduled_service | tinyint(1) | NO | | NULL | |
| gps_code | char(4) | YES | | NULL | |
| iata_code | char(3) | YES | | NULL | |
| local_code | varchar(7) | YES | | NULL | |
| home_url | varchar(128) | YES | | NULL | |
| wikipedia_url | varchar(128) | YES | | NULL | |
| keywords | varchar(300) | YES | | NULL | |
+-------------------+--------------+------+-----+---------+-------+
18 rows in set (0.00 sec)
For more information see the MySQL 8.0 Reference Manual.
Table structure via the mysqldump client
You may find it beneficial to retrieve the definition of all tables from a given schema, or you can obtain the table definition for a single table.
$ mysqldump --no-data --compact --set-gtid-purged=OFF \
-h${INSTANCE_ENDPOINT} -u${USER} -p${DBA_PASSWD} \
${DB_NAME} airport
This will produce an identical output to the SHOW CREATE TABLE statement. You can ignore additional comment lines with the table structure.
/*!40101 SET @saved_cs_client = @@character_set_client */;
/*!50503 SET character_set_client = utf8mb4 */;
CREATE TABLE `airport` (
`airport_id` int unsigned NOT NULL,
`ident` varchar(7) NOT NULL,
`type` varchar(20) NOT NULL,
`name` varchar(100) NOT NULL,
`latitude` float NOT NULL,
`longitude` float NOT NULL,
`elevation_ft` smallint DEFAULT NULL,
`continent_code` char(2) NOT NULL,
`country_code` char(2) NOT NULL,
`region_code` char(7) NOT NULL,
`municipality` varchar(60) NOT NULL,
`scheduled_service` tinyint(1) NOT NULL,
`gps_code` char(4) DEFAULT NULL,
`iata_code` char(3) DEFAULT NULL,
`local_code` varchar(7) DEFAULT NULL,
`home_url` varchar(128) DEFAULT NULL,
`wikipedia_url` varchar(128) DEFAULT NULL,
`keywords` varchar(300) DEFAULT NULL,
PRIMARY KEY (`airport_id`),
KEY `name` (`name`),
KEY `country_code` (`country_code`),
KEY `region_code` (`region_code`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci;
/*!40101 SET character_set_client = @saved_cs_client */;
For more information see the MySQL 8.0 Reference Manual.
Table structure via Information Schema
You can also reproduce the DESC-like syntax using the INFORMATION_SCHEMA tables. This is not a complete example as it does not serve a practical purpose when other options exist. The full SQL statement would need to add support for different data type formats, nullability, character sets, collations, and all constraints.
> SELECT column_name, data_type, character_maximum_length, numeric_precision,
numeric_scale, datetime_precision, is_nullable, column_default
FROM information_schema.columns
WHERE table_schema = 'airport'
AND table_name = 'airport'
ORDER BY ordinal_position;
+-------------------+-----------+--------------------------+-------------------+---------------+--------------------+-------------+----------------+
| COLUMN_NAME | DATA_TYPE | CHARACTER_MAXIMUM_LENGTH | NUMERIC_PRECISION | NUMERIC_SCALE | DATETIME_PRECISION | IS_NULLABLE | COLUMN_DEFAULT |
+-------------------+-----------+--------------------------+-------------------+---------------+--------------------+-------------+----------------+
| airport_id | int | NULL | 10 | 0 | NULL | NO | NULL |
| ident | varchar | 7 | NULL | NULL | NULL | NO | NULL |
| type | varchar | 20 | NULL | NULL | NULL | NO | NULL |
| name | varchar | 100 | NULL | NULL | NULL | NO | NULL |
| latitude | float | NULL | 12 | NULL | NULL | NO | NULL |
| longitude | float | NULL | 12 | NULL | NULL | NO | NULL |
| elevation_ft | smallint | NULL | 5 | 0 | NULL | YES | NULL |
| continent_code | char | 2 | NULL | NULL | NULL | NO | NULL |
| country_code | char | 2 | NULL | NULL | NULL | NO | NULL |
| region_code | char | 7 | NULL | NULL | NULL | NO | NULL |
| municipality | varchar | 60 | NULL | NULL | NULL | NO | NULL |
| scheduled_service | tinyint | NULL | 3 | 0 | NULL | NO | NULL |
| gps_code | char | 4 | NULL | NULL | NULL | YES | NULL |
| iata_code | char | 3 | NULL | NULL | NULL | YES | NULL |
| local_code | varchar | 7 | NULL | NULL | NULL | YES | NULL |
| home_url | varchar | 128 | NULL | NULL | NULL | YES | NULL |
| wikipedia_url | varchar | 128 | NULL | NULL | NULL | YES | NULL |
| keywords | varchar | 300 | NULL | NULL | NULL | YES | NULL |
+-------------------+-----------+--------------------------+-------------------+---------------+--------------------+-------------+----------------+
5\. Index cardinality
The table structure will provide information about the indexes defined for the table, however, the QEP is influenced by statistics on indexed columns. One technique to get an approximation is to look at the cardinality of each column of an index using the SHOW INDEXESstatement.
> SHOW INDEXES FROM airport;
+---------+------------+--------------+--------------+--------------+-----------+-------------+----------+--------+------+------------+---------+---------------+---------+------------+
| Table | Non_unique | Key_name | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment | Visible | Expression |
+---------+------------+--------------+--------------+--------------+-----------+-------------+----------+--------+------+------------+---------+---------------+---------+------------+
| airport | 0 | PRIMARY | 1 | airport_id | A | 86733 | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 1 | name | 1 | name | A | 70534 | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 1 | country_code | 1 | country_code | A | 214 | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 1 | region_code | 1 | region_code | A | 3334 | NULL | NULL | | BTREE | | | YES | NULL |
+---------+------------+--------------+--------------+--------------+-----------+-------------+----------+--------+------+------------+---------+---------------+---------+------------+
4 rows in set (0.01 sec)
NOTE: The higher the number in the cardinality column, the better this is for a SELECT statement that is looking to match specific rows.
You can also use the EXTENDED keyword to gain additional information however this is not practical for an end user.
> SHOW EXTENDED INDEXES FROM airport;
+---------+------------+--------------+--------------+-------------------+-----------+-------------+----------+--------+------+------------+---------+---------------+---------+------------+
| Table | Non_unique | Key_name | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment | Visible | Expression |
+---------+------------+--------------+--------------+-------------------+-----------+-------------+----------+--------+------+------------+---------+---------------+---------+------------+
| airport | 0 | PRIMARY | 1 | airport_id | A | 86733 | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 2 | DB_TRX_ID | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 3 | DB_ROLL_PTR | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 4 | ident | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 5 | type | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 6 | name | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 7 | latitude | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 8 | longitude | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 9 | elevation_ft | A | NULL | NULL | NULL | YES | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 10 | continent_code | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 11 | country_code | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 12 | region_code | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 13 | municipality | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 14 | scheduled_service | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 15 | gps_code | A | NULL | NULL | NULL | YES | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 16 | iata_code | A | NULL | NULL | NULL | YES | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 17 | local_code | A | NULL | NULL | NULL | YES | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 18 | home_url | A | NULL | NULL | NULL | YES | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 19 | wikipedia_url | A | NULL | NULL | NULL | YES | BTREE | | | YES | NULL |
| airport | 0 | PRIMARY | 20 | keywords | A | NULL | NULL | NULL | YES | BTREE | | | YES | NULL |
| airport | 1 | name | 1 | name | A | 70534 | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 1 | name | 2 | airport_id | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 1 | country_code | 1 | country_code | A | 214 | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 1 | country_code | 2 | airport_id | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 1 | region_code | 1 | region_code | A | 3334 | NULL | NULL | | BTREE | | | YES | NULL |
| airport | 1 | region_code | 2 | airport_id | A | NULL | NULL | NULL | | BTREE | | | YES | NULL |
+---------+------------+--------------+--------------+-------------------+-----------+-------------+----------+--------+------+------------+---------+---------------+---------+------------+
26 rows in set (0.00 sec)
For more information see the MySQL 8.0 Reference Manual.
6\. Query execution cost
The EXPLAIN ANALYZEcommand can provide detailed cost information for each step of query execution. This can be very valuable to identify the individual steps that are expensive with resources including execution time and rows processed.
mysql > EXPLAIN ANALYZE SELECT ...
-> Limit: 10 row(s) (actual time=350.043..350.045 rows=10 loops=1)
-> Sort: cnt DESC, limit input to 10 row(s) per chunk (actual time=350.043..350.043 rows=10 loops=1)
-> Table scan on <temporary> (actual time=0.003..0.049 rows=245 loops=1)
-> Aggregate using temporary table (actual time=349.935..349.994 rows=245 loops=1)
-> Nested loop inner join (cost=112.60 rows=248) (actual time=0.083..257.689 rows=76475 loops=1)
-> Table scan on c (cost=25.80 rows=248) (actual time=0.051..0.225 rows=248 loops=1)
-> Index lookup on a using country_code (country_code=c.country_code) (cost=0.25 rows=1) (actual time=0.043..0.993 rows=308 loops=248)
For more information see the MySQL 8.0 Reference Manual.
7\. Query optimizer evaluation
Before an SQL query is executed in MySQL it is first parsed. The parsed query is then checked to ensure applicable privileges to the tables and columns are present for the executing user. When query caching is enabled, the query is checked for an existing match and the results are returned for a valid match. The query optimizer then determines the ideal path to perform the query using a variety of evaluations and assessing the table storage engine capabilities. The optimizer trace enables you to gather detailed information about the steps the optimizer evaluated, and the statistics used to make a cost-based decision.
NOTE: This information is highly technical and should only be collected for specialized evaluation by highly skilled resources.
> SET SESSION optimizer_trace="enabled=on";
> SELECT ...
> SELECT TRACE FROM INFORMATION_SCHEMA.OPTIMIZER_TRACE;
{
"steps": [\
{\
"join_preparation": {\
...\
},\
{\
"join_optimization": {\
"select#": 1,\
"steps": [\
...\
},\
{\
"rows_estimation": [\
{\
"table": "`airport` `a`",\
"table_scan": {\
"rows": 86733,\
"cost": 296.25\
}\
},\
{\
"table": "`country` `c`",\
"table_scan": {\
"rows": 248,\
"cost": 1\
}\
}\
]\
},\
...\
},\
{\
"join_execution": {\
"select#": 1,\
"steps": [\
{\
"temp_table_aggregate": {\
"select#": 1,\
"steps": [\
{\
"creating_tmp_table": {\
"tmp_table_info": {\
"in_plan_at_position": 2,\
"columns": 3,\
"row_length": 218,\
"key_length": 210,\
"unique_constraint": false,\
"makes_grouped_rows": true,\
"cannot_insert_duplicates": false,\
"location": "TempTable"\
}\
}\
}\
]\
}\
},\
{\
"sorting_table": "<temporary>",\
"filesort_information": [\
{\
"direction": "desc",\
"expression": "`cnt`"\
}\
],\
"filesort_priority_queue_optimization": {\
"limit": 10,\
"chosen": true\
},\
"filesort_execution": [\
],\
"filesort_summary": {\
"memory_available": 262144,\
"key_size": 8,\
"row_size": 226,\
"max_rows_per_buffer": 11,\
"num_rows_estimate": 18446744073709551615,\
"num_rows_found": 245,\
"num_initial_chunks_spilled_to_disk": 0,\
"peak_memory_used": 2574,\
"sort_algorithm": "std::sort",\
"unpacked_addon_fields": "using_priority_queue",\
"sort_mode": "<fixed_sort_key, additional_fields>"\
}\
}\
]\
}\
}\
]\
}\
```\
NOTE: The above JSON output is truncated as it is several pages long. You can find a full version [here](https://gist.github.com/ronaldbradford/14f3e253342da7c7ce64756976b690f7).\
For more information see the [MySQL 8.0 Reference Manual](https://dev.mysql.com/doc/refman/8.0/en/information-schema-optimizer-trace-table.html).\
8\. MySQL Status Values\
MySQL internally has over 300 metrics that can be reviewed at a GLOBAL or SESSION granularity. Using the correct status variable can validate internal action taken during the query at various execution stages including index usage, where qualification, sorting, and grouping of data. In the following simple example where an internal temporary table was used, knowing that it was written to disk is important to see if this can be tuned via various means to reduce execution time.
NOTE: This information is highly technical and should only be collected for specialized evaluation by highly skilled resources knowing which metric to use and which to discard. The act of collecting information also impacts some metrics.\
mysql> SHOW SESSION STATUS LIKE 'Created_tmp%tables';\
+-------------------------+-------+\
| Variable_name | Value |\
+-------------------------+-------+\
| Created_tmp_disk_tables | 0 |\
| Created_tmp_tables | 4 |\
+-------------------------+-------+\
mysql> SELECT ...\
mysql> SHOW SESSION STATUS LIKE 'Created_tmp%tables';\
+-------------------------+-------+\
| Variable_name | Value |\
+-------------------------+-------+\
| Created_tmp_disk_tables | 1 |\
| Created_tmp_tables | 5 |\
+-------------------------+-------+\
```\
For more information see the [MySQL 8.0 Reference Manual](https://dev.mysql.com/doc/refman/8.0/en/show-status.html).\
9\. Query profiling\
When profiling is enabled for a query you can review each internal step and you can align this with the MySQL source code. In the following output, you can see the majority of the execution time was a single step e.g. line 14 was 0.234060 seconds. Most queries will follow a similar distribution of time, however, more complex queries will show additional steps.
NOTE: This information is highly technical and should only be collected for specialized evaluation by highly skilled resources. No additional details of this analysis are described here.\
mysql > SET @@profiling=1;\
mysql > SELECT ...\
mysql > SET @@profiling=0;\
mysql > SHOW PROFILES;\
mysql> SELECT * FROM INFORMATION_SCHEMA.PROFILING WHERE query_id=1;\
```\
```\
+----------+-----+--------------------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+--------------------------------+----------------------+-------------+\
| QUERY_ID | SEQ | STATE | DURATION | CPU_USER | CPU_SYSTEM | CONTEXT_VOLUNTARY | CONTEXT_INVOLUNTARY | BLOCK_OPS_IN | BLOCK_OPS_OUT | MESSAGES_SENT | MESSAGES_RECEIVED | PAGE_FAULTS_MAJOR | PAGE_FAULTS_MINOR | SWAPS | SOURCE_FUNCTION | SOURCE_FILE | SOURCE_LINE |\
+----------+-----+--------------------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+--------------------------------+----------------------+-------------+\
| 9 | 2 | starting | 0.000125 | 0.000130 | 0.000021 | 1 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | NULL | NULL | NULL |\
| 9 | 3 | Executing hook on transaction | 0.000010 | 0.000009 | 0.000002 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | launch_hook_trans_begin | rpl_handler.cc | 1376 |\
| 9 | 4 | starting | 0.000011 | 0.000010 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | launch_hook_trans_begin | rpl_handler.cc | 1378 |\
| 9 | 5 | checking permissions | 0.000005 | 0.000004 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | check_access | sql_authorization.cc | 2303 |\
| 9 | 6 | checking permissions | 0.000005 | 0.000004 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | check_access | sql_authorization.cc | 2303 |\
| 9 | 7 | Opening tables | 0.000180 | 0.000156 | 0.000025 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 1 | 0 | open_tables | sql_base.cc | 5803 |\
| 9 | 8 | init | 0.000008 | 0.000006 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | execute | sql_select.cc | 570 |\
| 9 | 9 | System lock | 0.000009 | 0.000007 | 0.000001 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_lock_tables | lock.cc | 331 |\
| 9 | 10 | optimizing | 0.000012 | 0.000011 | 0.000002 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | optimize | sql_optimizer.cc | 344 |\
| 9 | 11 | statistics | 0.000027 | 0.000023 | 0.000003 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | optimize | sql_optimizer.cc | 663 |\
| 9 | 12 | preparing | 0.000017 | 0.000014 | 0.000003 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | optimize | sql_optimizer.cc | 747 |\
| 9 | 13 | Creating tmp table | 0.000047 | 0.000041 | 0.000006 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | create_intermediate_table | sql_executor.cc | 195 |\
| 9 | 14 | executing | 0.234060 | 0.202675 | 0.000000 | 65 | 3 | 0 | 0 | 0 | 0 | 0 | 1222 | 0 | ExecuteIteratorQuery | sql_union.cc | 1130 |\
| 9 | 15 | end | 0.000022 | 0.000020 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | execute | sql_select.cc | 603 |\
| 9 | 16 | query end | 0.000009 | 0.000009 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | mysql_execute_command_internal | sql_parse.cc | 6372 |\
| 9 | 17 | waiting for handler commit | 0.000231 | 0.000231 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | ha_commit_trans | handler.cc | 1707 |\
| 9 | 18 | closing tables | 0.000018 | 0.000021 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 1 | 0 | mysql_execute_command_internal | sql_parse.cc | 6450 |\
| 9 | 19 | freeing items | 0.000018 | 0.000015 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | finish_dispatch_sql_command | sql_parse.cc | 6971 |\
| 9 | 20 | logging slow query | 0.000150 | 0.000150 | 0.000000 | 0 | 0 | 0 | 8 | 0 | 0 | 0 | 4 | 0 | log_slow_do | log.cc | 1784 |\
| 9 | 21 | cleaning up | 0.000010 | 0.000010 | 0.000000 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | finish_dispatch_command | sql_parse.cc | 3409 |\
+----------+-----+--------------------------------+----------+----------+------------+-------------------+---------------------+--------------+---------------+---------------+-------------------+-------------------+-------------------+-------+--------------------------------+----------------------+-------------+\
20 rows in set, 1 warning (0.00 sec)\
```\
For more information see the [MySQL 8.0 Reference Manual](https://dev.mysql.com/doc/refman/8.0/en/performance-schema-query-profiling.html).\
10\. Processlist\
During the execution of a SQL statement, the processlistcan be valuable to see the Stateand Timeof a longer-running query. This can also show the impact of the statement on other concurrent statements, for example locking. See Capturing running SQL statements for detailed information on how to gather the processlistprocesslist via various methods.\
Warning about the precision of values\
Many of the analysis tools described here will produce varying results under different situations. Some values should remain precise during every execution, for example, the number of rows returned or the table structure.
Some output should remain nearly consistent during repeat executions, for example, the QEP may include the same number of steps, but, one column may contain different values. A QEP may change depending on different constant values used in the SQL statement, a different version of MySQL, or changes in MySQL configuration.
Other values will rarely be identical, for example, the high-precision query execution time, query cost, or individual steps of profiling should be averaged, and an appropriate percentile value used to identify similar executions.\
Conclusion\
There are multiple native methods using MySQL client tools to collect supporting information when executing SQL statements. This information is critical when analyzing and optimizing SQL statements.
This article follows Capturing running SQL statements which details the different techniques for capturing complete SQL statements that can be used.\
Appendix\
Example data used\
For this article, the airport dataset used is available at https://github.com/ronaldbradford/data/tree/main/mysql-data/airport\
Example SQL used\
For each method of collection, the following example SQL statement was used.\
SELECT a.country_code, c.name, COUNT(*) AS cnt\
FROM airport a\
INNER JOIN country c USING (country_code)\
GROUP BY country_code, name ORDER BY 3 DESC LIMIT 10;\
```\
### This SQL statement will return a set of results like:\
```\
+--------------+----------------+-------+\
| country_code | name | cnt |\
+--------------+----------------+-------+\
| US | United States | 30581 |\
| BR | Brazil | 6849 |\
| JP | Japan | 3430 |\
| CA | Canada | 3075 |\
| AU | Australia | 2576 |\
| MX | Mexico | 2288 |\
| RU | Russia | 1556 |\
| KR | South Korea | 1400 |\
| GB | United Kingdom | 1398 |\
| DE | Germany | 1042 |\
+--------------+----------------+-------+\
10 rows in set (0.47 sec)\
```\
NOTE: The actual counts of airports and the ordering of countries may vary depending on when you retrieved the dataset.\
A note about backquotes (\`)\
In many examples, you will see the addition of the backquote character (`) around object names. This is an artifact of the capability to support the use of reserved words, and these must be enclosed in backquotes. The tools however do not provide this additional syntax when required but for all table and column objects making readability more complex.\